[Linux-cachefs] PROBLEM: ASSERT(object->dentry) fails in cachefiles_delete_object()

[Manuel Schölling]

Hi David,

I'm afraid the patch didn't quite fix it:
I get a BUG() in cachefiles_mark_object_active():

      KERNEL: /usr/lib/debug/lib/modules/3.14.15/vmlinux
    DUMPFILE: /var/crash/201409181627/vmcore.201409181627
        CPUS: 24
        DATE: Thu Sep 18 16:26:01 2014
      UPTIME: 03:29:24
LOAD AVERAGE: 0.19, 0.12, 0.14
       TASKS: 458
    NODENAME: animate-x3
     RELEASE: 3.14.15
     VERSION: #1 SMP Thu Sep 18 10:27:48 CEST 2014
     MACHINE: x86_64  (3466 Mhz)
      MEMORY: 48 GB
       PANIC: "kernel BUG at fs/cachefiles/namei.c:200!"
         PID: 25889
     COMMAND: "kworker/u49:1"
        TASK: ffff880624e793f0  [THREAD_INFO: ffff88046cd52000]
         CPU: 2
       STATE: TASK_RUNNING (PANIC)

which is this line:

static int cachefiles_mark_object_active(struct cachefiles_cache *cache,
					 struct cachefiles_object *object)
{
	[...]
	
wait_for_old_object:
	if (fscache_object_is_live(&object->fscache)) {
		printk(KERN_ERR "\n");
		printk(KERN_ERR "CacheFiles: Error:"
		       " Unexpected object collision\n");
		cachefiles_printk_object(object, xobject);
		BUG(); // <===================------------ here
	}

	[...]
}

However, I made a mistake: I didn't compile the patched kernel with
debugging info. I rebuild the patched kernel now including the debugging
info, but the new info doesn't seem to fit the kdump data of the patched
kernel without debugging info. So I cannot give you detailed data about
the variables.

As soon as the kernel crashes again, I will send it to you.


Thank you very much for all your effortsa and have a nice weekend!

Manuel

On Do, 2014-09-18 at 11:20 +0100, David Howells wrote:
> Manuel Schölling <manuel.schoelling at gmx.de> wrote:
> 
> > [1. text/plain; object_fscache_cookie.txt]
> > ...
> >   flags = 23
> 
> That would be 0x17, or:
> 
> 	FSCACHE_COOKIE_LOOKING_UP
> 	FSCACHE_COOKIE_NO_DATA_YET
> 	FSCACHE_COOKIE_UNAVAILABLE
> 	FSCACHE_COOKIE_RELINQUISHED
> 
> so fscache_relinquish_cookie() was called and the cookie thinks it was still
> in the process of being looked up.
> 
> > [2. text/plain; object_fscache_parent_cookie.txt]   
> > ...
> >   flags = 32
> 
> That would be 0x20, or:
> 
> 	FSCACHE_COOKIE_ENABLED
> 
> so that appears to be live.
> 
> > [3. text/plain; object_fscache_parent.txt]
> > ...
> >   state = 0xffffffffa02b07c0 <fscache_osm_WAIT_FOR_CMD>,
> > ...
> >   lookup_jif = 4298902188, 
> >   oob_event_mask = 96, 
> >   event_mask = 109, 
> >   events = 16, 
> >   flags = 56, 
> 
> The flags are 0x38, or:
> 
> 	FSCACHE_OBJECT_IS_LIVE
> 	FSCACHE_OBJECT_IS_LOOKED_UP
> 	FSCACHE_OBJECT_IS_AVAILABLE
> 
> so the parent object looks okay.
> 
> So it does just look like I've failed to take account of the fact that I can
> get to the DROP_OBJECT state without actually looking up the object - and thus
> I might not see object->dentry having been set yet.
> 
> David