Skip to contentSkip to conversation

kdevtmpfs oops since yesterdays vfs merge

DISCUSSION Dave Jones 2 participants 11 messages Jul 24, 2011 – Jul 25, 2011 Driver core

lore
Share & tools
lore
#3 lore raw
Quoted 11 lines · Dave Jones
Quoted 8 lines · Al Viro
Quoted 4 lines · Dave Jones

I see an oops in handle_create when I try to boot current tree..

full trace:
https://s3.amazonaws.com/twitpic/photos/large/355006460.jpg?AWSAccessKeyId=AKIAJF3XCCKACR3QDMOA&Expires=1311550232&Signature=IIO%2Bya1uEDJzSXTD0DXh2%2BdZpoU%3D

Where in handle_create() is that? At least dump objdump -d of your devtmpfs.o someplace readable...

http://codemonkey.org.uk/devtmpfs.s

Smells like req->dev somehow managing to be NULL at that point, but that doesn't make any sense - we get to devtmpfs_create_node() only from one place, it sets req.dev to the argument it got from callers and that caller would have oopsed itself before getting to that call with dev == NULL...

Could you stick a BUG_ON(!dev) in the beginning of handle_create() to see if that's what somehow manages to happen?

author
#4 lore raw
Quoted 13 lines · Al Viro
Quoted 11 lines · Dave Jones
Quoted 8 lines · Al Viro
Quoted 4 lines · Dave Jones

I see an oops in handle_create when I try to boot current tree..

full trace:
https://s3.amazonaws.com/twitpic/photos/large/355006460.jpg?AWSAccessKeyId=AKIAJF3XCCKACR3QDMOA&Expires=1311550232&Signature=IIO%2Bya1uEDJzSXTD0DXh2%2BdZpoU%3D

Where in handle_create() is that? At least dump objdump -d of your devtmpfs.o someplace readable...

http://codemonkey.org.uk/devtmpfs.s

Quoted 7 lines

Smells like req->dev somehow managing to be NULL at that point, but that doesn't make any sense - we get to devtmpfs_create_node() only from one place, it sets req.dev to the argument it got from callers and that caller would have oopsed itself before getting to that call with dev == NULL...

Could you stick a BUG_ON(!dev) in the beginning of handle_create() to see if that's what somehow manages to happen?

So I built a kernel with this, and then couldn't reproduce it. Made a clean kernel again, and still nothing.. After a number of reboots, it finally triggered again, with that BUG_ON(). fwiw 'nodename' is pointing at garbage when that happens too.

Either it only triggers occasionally, or it's dependent on how quickly I type my luks password in.

Dave

author
#5 lore raw
Quoted 22 lines · Dave Jones
Quoted 13 lines · Al Viro
Quoted 11 lines · Dave Jones
Quoted 8 lines · Al Viro
Quoted 4 lines · Dave Jones

I see an oops in handle_create when I try to boot current tree..

full trace:
https://s3.amazonaws.com/twitpic/photos/large/355006460.jpg?AWSAccessKeyId=AKIAJF3XCCKACR3QDMOA&Expires=1311550232&Signature=IIO%2Bya1uEDJzSXTD0DXh2%2BdZpoU%3D

Where in handle_create() is that? At least dump objdump -d of your devtmpfs.o someplace readable...

http://codemonkey.org.uk/devtmpfs.s

Quoted 7 lines

Smells like req->dev somehow managing to be NULL at that point, but that doesn't make any sense - we get to devtmpfs_create_node() only from one place, it sets req.dev to the argument it got from callers and that caller would have oopsed itself before getting to that call with dev == NULL...

Could you stick a BUG_ON(!dev) in the beginning of handle_create() to see if that's what somehow manages to happen?

Quoted 7 lines

So I built a kernel with this, and then couldn't reproduce it. Made a clean kernel again, and still nothing.. After a number of reboots, it finally triggered again, with that BUG_ON(). fwiw 'nodename' is pointing at garbage when that happens too.

Either it only triggers occasionally, or it's dependent on how quickly I type my luks password in.

one more datapoint. On a succesful boot, I see ..

[    7.760774] dracut: luksOpen /dev/sda2 luks-b5a1fb36-5672-4191-a260-e3f389eb0bb6
[   14.787158] nodename: dm-0
[   15.082391] nodename: dm-0

when it triggers the bug_on(), it's that second nodename that is garbage.

Dave

#6 lore raw
Quoted 6 lines · Dave Jones
[    7.760774] dracut: luksOpen /dev/sda2 luks-b5a1fb36-5672-4191-a260-e3f389eb0bb6
[   14.787158] nodename: dm-0
[   15.082391] nodename: dm-0

when it triggers the bug_on(), it's that second nodename that is garbage.

Interesting... The next experiment would be to stick BUG_ON(!req.dev) into devtmpfs_create_node() right after the assigment to that field.

We couldn't be hit by the lack of barriers here, could we? Store to req.dev happens before spin_unlock(&req_lock), so by the time when that request is seen by loop in devtmpfsd() and passed to handle() it should be seen - we have grabbed req_lock, found a pointer to req, dropped req_lock and called handle(). Should've been enough...

Might be interesting to print &req from devtmpfs_create_node(), both on entry and on exit, and print req right before the call of handle()...

Incidentally, that disassembly shows one really ugly thing - offset of ->devt in struct device is 0x3c0. IOW, each of those suckers eats a kilobyte... ;-/

author
#7 lore raw
Quoted 4 lines · Al Viro
Quoted 1 line

when it triggers the bug_on(), it's that second nodename that is garbage.

Interesting... The next experiment would be to stick BUG_ON(!req.dev) into devtmpfs_create_node() right after the assigment to that field.

couldn't get that to trigger.

Quoted 8 lines

We couldn't be hit by the lack of barriers here, could we? Store to req.dev happens before spin_unlock(&req_lock), so by the time when that request is seen by loop in devtmpfsd() and passed to handle() it should be seen - we have grabbed req_lock, found a pointer to req, dropped req_lock and called handle(). Should've been enough...

Might be interesting to print &req from devtmpfs_create_node(), both on entry and on exit, and print req right before the call of handle()...

Here's latest..

https://s3.amazonaws.com/twitpic/photos/full/355219312.jpg?AWSAccessKeyId=AKIAJF3XCCKACR3QDMOA&Expires=1311570683&Signature=xr3tusulMiV2bIsxux9YNrawUDA%3D

apologies for crappy picture, but it's legible at fullsize..

interesting thing here is that the req that causes the oops, I couldn't find any call to create_handle for that address, so where devtmpfsd got it is a mystery. The address is curious too, in that it's way off from all the reqs created around that time.

I'll add some more printk's to see if I can figure where that's being created.

Dave

#8 lore raw
Quoted 8 lines · Dave Jones
Quoted 4 lines · Al Viro
Quoted 1 line

when it triggers the bug_on(), it's that second nodename that is garbage.

Interesting... The next experiment would be to stick BUG_ON(!req.dev) into devtmpfs_create_node() right after the assigment to that field.

couldn't get that to trigger.

Interesting...

Quoted 11 lines
Quoted 8 lines

We couldn't be hit by the lack of barriers here, could we? Store to req.dev happens before spin_unlock(&req_lock), so by the time when that request is seen by loop in devtmpfsd() and passed to handle() it should be seen - we have grabbed req_lock, found a pointer to req, dropped req_lock and called handle(). Should've been enough...

Might be interesting to print &req from devtmpfs_create_node(), both on entry and on exit, and print req right before the call of handle()...

Here's latest..

Quoted 8 lines

https://s3.amazonaws.com/twitpic/photos/full/355219312.jpg?AWSAccessKeyId=AKIAJF3XCCKACR3QDMOA&Expires=1311570683&Signature=xr3tusulMiV2bIsxux9YNrawUDA%3D

apologies for crappy picture, but it's legible at fullsize..

interesting thing here is that the req that causes the oops, I couldn't find any call to create_handle for that address, so where devtmpfsd got it is a mystery. The address is curious too, in that it's way off from all the reqs created around that time.

Arrgh... OK, I see what's going on.

                                req->err = handle(req->name, req->mode, req->dev);
                                complete(&req->done);
                                req = req->next;

is letting the request creator to continue; if it leaves the scope, guess what is left in *req? That's right, garbage... Including req->next. All right, try this and let's see if it fixes the problem:

drivers/base/devtmpfs.c +2 -1
index 3644dd4..49b6cba 100644
@@ -406,9 +406,10 @@ static int devtmpfsd(void *p)
 			requests = NULL;
 			spin_unlock(&req_lock);
 			while (req) {
+				struct req *next = req->next;
 				req->err = handle(req->name, req->mode, req->dev);
 				complete(&req->done);
-				req = req->next;
+				req = next;
 			}
 			spin_lock(&req_lock);
 		}
author
#9 lore raw
Quoted 8 lines · Al Viro

Arrgh... OK, I see what's going on.

                                req->err = handle(req->name, req->mode, req->dev);
                                complete(&req->done);
                                req = req->next;

is letting the request creator to continue; if it leaves the scope, guess what is left in *req? That's right, garbage... Including req->next. All right, try this and let's see if it fixes the problem:

Yep, that solves the problem.

Dave

#10 lore raw
Quoted 4 lines · Dave Jones
Quoted 2 lines · Al Viro

Arrgh... OK, I see what's going on.

Quoted 8 lines
Quoted 6 lines
                                req->err = handle(req->name, req->mode, req->dev);
                                complete(&req->done);
                                req = req->next;

is letting the request creator to continue; if it leaves the scope, guess what is left in *req? That's right, garbage... Including req->next. All right, try this and let's see if it fixes the problem:

Yep, that solves the problem.

OK, to Linus it goes tomorrow morning... I'm about to fall asleep right now and queue needs a bit of reordering ;-/