Bug 830862 - Kernel panic at reboot (possibly NFS related).
Summary: Kernel panic at reboot (possibly NFS related).
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 17
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: nfs-maint
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 829413 831194 839515 848740 (view as bug list)
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-06-11 14:24 UTC by Tom Horsley
Modified: 2020-04-15 14:04 UTC (History)
18 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2012-12-18 01:55:51 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
Here is the list of mounted filesystems before the reboot. (5.32 KB, text/plain)
2012-06-11 14:26 UTC, Tom Horsley
no flags Details
screen photo (843.65 KB, image/jpeg)
2012-06-11 19:46 UTC, Tom Horsley
no flags Details
screen photo 2 (823.51 KB, image/jpeg)
2012-06-11 19:47 UTC, Tom Horsley
no flags Details
screen photo 3 (876.40 KB, image/jpeg)
2012-06-11 19:48 UTC, Tom Horsley
no flags Details
screen photo 4 (698.71 KB, image/jpeg)
2012-06-11 19:48 UTC, Tom Horsley
no flags Details
screen photo 5 (933.71 KB, image/jpeg)
2012-06-11 19:51 UTC, Tom Horsley
no flags Details
screen photo 6 (854.66 KB, image/jpeg)
2012-06-11 19:51 UTC, Tom Horsley
no flags Details
screen photo 7 (790.88 KB, image/jpeg)
2012-06-11 19:52 UTC, Tom Horsley
no flags Details
screen photo 8 (885.07 KB, image/jpeg)
2012-06-11 19:52 UTC, Tom Horsley
no flags Details
New crash looks like the old crash (632.23 KB, image/png)
2012-06-18 12:16 UTC, Tom Horsley
no flags Details
hard-code init_net in lockd_up/down (574 bytes, patch)
2012-06-18 20:35 UTC, J. Bruce Fields
no flags Details | Diff
spec file patch (1.98 KB, patch)
2012-07-06 17:19 UTC, Stefan Ring
no flags Details | Diff
screen photo of traceback (540.49 KB, image/png)
2012-07-06 17:20 UTC, Stefan Ring
no flags Details
screen photo of traceback (bottom) (166.26 KB, image/png)
2012-07-06 17:21 UTC, Stefan Ring
no flags Details

Description Tom Horsley 2012-06-11 14:24:08 UTC
Description of problem:
When I am running kernel-3.4.0-1.fc17.x86_64 my system panics and freezes
at reboot time. Power cycle is required to get the system back. One time
this system freeze left the tail end of a kernel backtrace on my screen
(but unfortunately I didn't take a picture). Subsequent attempts to reproduce
it and get something I could record have failed to capture the backtrace,
but have been 100% successful at panicing the system every time.

The reason I suggest NFS is because there were routines with names containing
nfs_ on the screen in that first panic.

Version-Release number of selected component (if applicable):
kernel-3.4.0-1.fc17.x86_64


How reproducible:
100%

Steps to Reproduce:
1.type reboot
2.
3.
  
Actual results:
kernel panic scrolls past too fast to see then system is frozen.

Expected results:
System reboots.

Additional info:

Comment 1 Tom Horsley 2012-06-11 14:26:07 UTC
Created attachment 590949 [details]
Here is the list of mounted filesystems before the reboot.

Note that many of these systems I'm talking to are very old and have no idea
that such a thing as NFS version 4 exists, so I have to put a proto=udp on
many of the mount lines.

Comment 2 Tom Horsley 2012-06-11 14:35:40 UTC
There is no panic with the same NFS mounts when I'm running
kernel-3.3.7-1.fc17.x86_64.

Now I'm about to try typing reboot back in 3.4.0 after manually un-mounting
every NFS filesystem.

Comment 3 Tom Horsley 2012-06-11 14:42:59 UTC
Maybe this isn't NFS related after all. I still got the kernel panic at
reboot with no NFS mounts active when I rebooted.

Anyone know if there is some way to make the reboot process stop clearing the
screen? The kernel panic almost always flashes past immediately prior to the
reboot clearing the screen.

Comment 4 Tom Horsley 2012-06-11 16:28:35 UTC
Here's the smolt page for the machine in case there is something
hardware related involved:

http://www.smolts.org/client/show/?uuid=pub_407b67eb-24bb-4ef0-9092-ad2429ae1eb4

Comment 5 J. Bruce Fields 2012-06-11 17:10:51 UTC
Based on Comment 3, I'm assuming this isn't nfs-related.  Let's try checking the "Reset Assignee to default for component" box and see if that gets us anywhere....

Comment 6 Josh Boyer 2012-06-11 18:31:40 UTC
(In reply to comment #5)
> Based on Comment 3, I'm assuming this isn't nfs-related.  Let's try checking
> the "Reset Assignee to default for component" box and see if that gets us
> anywhere....

Reassinging it back based strictly on comments is fair play I guess.

Tom, please add 'pause_on_oops=30' and remove 'rhgb quiet' to the boot.  That should cause the oops to pause on the screen and hopefully you get get the backtrace.  I'm guessing this is at the tail end, so it isn't already stored in /var/log/messages because syslog has been shutdown?

Comment 7 Tom Horsley 2012-06-11 19:46:48 UTC
Created attachment 591007 [details]
screen photo

I'm attaching a bunch of marginally readable photos of my screen. I did
remember correctly - there are a bunch of nfs_ routines in the backtrace.
I gotta remember that pause_on_oops parameter.

Comment 8 Tom Horsley 2012-06-11 19:47:39 UTC
Created attachment 591008 [details]
screen photo 2

Comment 9 Tom Horsley 2012-06-11 19:48:13 UTC
Created attachment 591009 [details]
screen photo 3

Comment 10 Tom Horsley 2012-06-11 19:48:43 UTC
Created attachment 591010 [details]
screen photo 4

Comment 11 Tom Horsley 2012-06-11 19:51:04 UTC
Created attachment 591011 [details]
screen photo 5

Comment 12 Tom Horsley 2012-06-11 19:51:36 UTC
Created attachment 591012 [details]
screen photo 6

Comment 13 Tom Horsley 2012-06-11 19:52:13 UTC
Created attachment 591013 [details]
screen photo 7

Comment 14 Tom Horsley 2012-06-11 19:52:45 UTC
Created attachment 591014 [details]
screen photo 8

Comment 15 Tom Horsley 2012-06-11 19:58:13 UTC
Also, when rebooting many times to try and figure out what camera settings
produced something, I found that if I reboot soon after logging in, it
doesn't panic. I have to do some random amount of work before the panic
will happen (run editor, run firefox, etc). Seems like I need it to be
up at least 5 or ten minutes before it panics on reboot.

Comment 16 Josh Boyer 2012-06-11 20:04:13 UTC
Hand transcribed:

lockd_down+0x90/0x140 [lockd]
nlmclnt_done+0x13/0x20 [lockd]
nfs_destroy_server+0x24/0x30 [nfs]
nfs_free_server+0xce/0x190 [nfs]
nfs_kill_super+0x34/0x40 [nfs]
deactivate_locked_super+0x57/0x90
deactivate_super+0x4e/0x70
mntput_no_expire+0xcc/0x120
mntput+0x26/0x40
release_mounts+0x77/0x90
put_mnt_ns+0x70/0x90
free_nsproxy+0x1f/0xb0
switch_task_namespaces=0x50/0x60
exit_task_namespaces+0x10/0x20
do_exit+0x456/0xa0
do_group_exit+0x3f/0xa0
sys_exit_group+0x17/0x20
system_call_fastpath+0x16/0x1b

Tom, were all of those with or without NFS mounted?

Comment 17 Tom Horsley 2012-06-11 22:13:05 UTC
I had NFS mounts active on all of these. I only tried the experiment of
unmounting everything once and still got the system freeze, but didn't
see anything of the walkback that time. I think I'm probably also doing
an NFS export of a couple of partitions as well, and I didn't try it with
exports disabled.

Comment 18 Josh Boyer 2012-06-12 00:58:27 UTC
OK, thanks.  Reassigning, this time with data.

Comment 19 Tom Horsley 2012-06-12 11:53:29 UTC
Just to throw more fuel on the NFS fire, I tried another experiment this morning.
I deleted all the nfs mounts in /etc/fstab. I checked /etc/exports and found
that I wasn't exporting any filesystems (so it is empty), and I found the
only enabled service with "nfs" in the name was nfs-lock.service, so I
disabled it.

I then rebooted, power cycled through the same old panic, then after I got
the system back up, used it for a while to get it up long enough to panic.

I then typed reboot, and it rebooted just fine with no oops and no getting
frozen.

Comment 20 Jeff Layton 2012-06-12 12:37:39 UTC
It certainly does seem to be NLM related...

(gdb) list *(lockd_down+0x90)
0x3eb0 is in lockd_down (fs/lockd/svc.c:386).
381	lockd_down(void)
382	{
383		mutex_lock(&nlmsvc_mutex);
384		if (nlmsvc_users) {
385			if (--nlmsvc_users) {
386				lockd_down_net(current->nsproxy->net_ns);
387				goto out;
388			}
389		} else {
390			printk(KERN_ERR "lockd_down: no users! task=%p\n",

It's not clear what caused the oops from the screenshots however. Usually there's a message prior to the backtrace that says something like NULL pointer dereference, but maybe that scrolled off the screen. Knowing that would help us determine where the bug actually is. Maybe nsproxy is a NULL pointer?

Comment 21 Jeff Layton 2012-06-12 12:51:50 UTC
Yeah, this is being called from process exit context. I think that code is setting current->nsproxy to NULL and then proceeding to tear down all of the namespaces. Unfortunately, we require current->nsproxy to not be NULL in order to do that.

I think we'll need to pull in Stanislav Kinsbursky to look at this since he did most of this work upstream...

Comment 22 Tom Horsley 2012-06-12 12:56:45 UTC
The "screen photo 2" attachment above has the last [OK] message leftover
from the initial boot right at the top, so everything the oops printed
when I rebooted should be on that photo (I don't see anything that looks
like a reason).

Comment 23 Jeff Layton 2012-06-12 13:06:41 UTC
Ok, got a quick response from Stanislav:

---------------------[snip]----------------------
Jeff, this is known issue.
Search for my patch set "NFS: callback shutdown panic fix".
The problem is caused by isolated mount namespace on shutdown. Init 
switches nsproxy to zero and tries to umount NFS, which in turn leads to 
NULL pointer dereference on SUNRPC service shutdown 
(current->nsproxy->net_ns).
---------------------[snip]----------------------

So I guess we just need to wait for those to make their way into the stable kernels.

Comment 24 Josh Boyer 2012-06-12 13:12:24 UTC
*** Bug 831194 has been marked as a duplicate of this bug. ***

Comment 25 Josh Boyer 2012-06-12 13:18:43 UTC
(In reply to comment #23)
> Ok, got a quick response from Stanislav:
> 
> ---------------------[snip]----------------------
> Jeff, this is known issue.
> Search for my patch set "NFS: callback shutdown panic fix".
> The problem is caused by isolated mount namespace on shutdown. Init 
> switches nsproxy to zero and tries to umount NFS, which in turn leads to 
> NULL pointer dereference on SUNRPC service shutdown 
> (current->nsproxy->net_ns).
> ---------------------[snip]----------------------
> 
> So I guess we just need to wait for those to make their way into the stable
> kernels.

These two commits?

commit 9793f7c88937e7ac07305ab1af1a519225836823
Author: Stanislav Kinsbursky <skinsbursky>
Date:   Wed May 2 16:08:38 2012 +0400

    SUNRPC: new svc_bind() routine introduced

commit 786185b5f8abefa6a8a16695bb4a59c164d5a071
Author: Stanislav Kinsbursky <skinsbursky>
Date:   Fri May 4 12:49:41 2012 +0400

    SUNRPC: move per-net operations from svc_destroy()
    

Neither one of them are CC'd to stable...

Comment 26 Josh Boyer 2012-06-12 14:05:47 UTC
*** Bug 829413 has been marked as a duplicate of this bug. ***

Comment 27 Josh Boyer 2012-06-13 16:30:15 UTC
When this finishes building, could you please test:

http://koji.fedoraproject.org/koji/taskinfo?taskID=4159507

it has the above two commits added to it.

Comment 28 J. Bruce Fields 2012-06-13 16:41:58 UTC
Actually, those two commits are really just preparation; the version Stanislav posted to the mailing list also had another patch ("hard-code init_net for NFS callback transports") folded into one of them.

I have these queued up to submit to stable soon, in the for-3.4 branch of
git://linux-nfs.org/~bfields/linux-topics.

Comment 29 Josh Boyer 2012-06-13 16:47:16 UTC
(In reply to comment #28)
> Actually, those two commits are really just preparation; the version
> Stanislav posted to the mailing list also had another patch ("hard-code
> init_net for NFS callback transports") folded into one of them.

Yeah.  I pulled them off the list instead out of git directly.  It was pretty clear he did something additional when he said they were backported from 3.5.  The scratch build above contains the list patches.

> I have these queued up to submit to stable soon, in the for-3.4 branch of
> git://linux-nfs.org/~bfields/linux-topics.

Great!

Comment 30 J. Bruce Fields 2012-06-13 17:25:24 UTC
(In reply to comment #29)
> Yeah.  I pulled them off the list instead out of git directly.  It was
> pretty clear he did something additional when he said they were backported
> from 3.5.  The scratch build above contains the list patches.

OK, good, that's the right thing to test then, thanks.

Comment 31 Tom Horsley 2012-06-13 19:46:57 UTC
I installed kernel-3.4.2-4.fc17.x86_64 from the build in comment #27, and
it sure seems to fix my problems. I ran for a while, referenced NFS filesystems
and let the system settle in, then did a reboot, and it rebooted with no
problems. Looks fixed to me.

Comment 32 Josh Boyer 2012-06-13 20:01:52 UTC
OK.  I committed the patches to Fedora git.  They'll be in the next official build.

Comment 33 Tom Horsley 2012-06-14 13:30:29 UTC
DOH! I rebooted this morning after running kernel-3.4.2-4.fc17.x86_64 all night
and the kernel panic at reboot was back again. Maybe it is more random now?

Comment 34 H.J. Lu 2012-06-14 13:45:19 UTC
There are other NFS problems in 3.4 kernel:

https://lkml.org/lkml/2012/6/5/64

I don't know if they are related to this one.

Comment 35 Tom Horsley 2012-06-14 13:57:24 UTC
The walkback I got this morning looked just like the one transcribed above,
but the RIP seems to be at lockd_down+0x25/0x10 (I think, the 0x10 is
very fuzzy :-).

Comment 36 Fedora Update System 2012-06-15 06:24:15 UTC
kernel-3.4.2-4.fc17 has been submitted as an update for Fedora 17.
https://admin.fedoraproject.org/updates/kernel-3.4.2-4.fc17

Comment 37 Fedora Update System 2012-06-15 06:24:18 UTC
kernel-3.4.2-1.fc16 has been submitted as an update for Fedora 16.
https://admin.fedoraproject.org/updates/kernel-3.4.2-1.fc16

Comment 38 Fedora Update System 2012-06-15 23:48:57 UTC
Package kernel-3.4.2-4.fc17:
* should fix your issue,
* was pushed to the Fedora 17 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing kernel-3.4.2-4.fc17'
as soon as you are able to, then reboot.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2012-9501/kernel-3.4.2-4.fc17
then log in and leave karma (feedback).

Comment 39 Rolf Fokkens 2012-06-17 13:27:36 UTC
Have the same problem here, installed the new kernel and see if it helps.

Comment 40 Fedora Update System 2012-06-17 22:22:34 UTC
kernel-3.4.2-4.fc17 has been pushed to the Fedora 17 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 41 Tom Horsley 2012-06-18 12:16:18 UTC
Created attachment 592622 [details]
New crash looks like the old crash

I'm getting better at taking readable pictures of the screen, but it looks like
kernel-3.4.2-4.fc17.x86_64 is still prone to these crashes, though may be
a little more random than it used to be (I have rebooted a couple of times
without this happening).

Comment 42 Tom Horsley 2012-06-18 12:18:49 UTC
I guess I should re-open this (I'm not sure what ASSIGNED means, but that's
the only option bugzilla gives me other than CLOSED :-).

Comment 43 J. Bruce Fields 2012-06-18 20:35:13 UTC
Created attachment 592735 [details]
hard-code init_net in lockd_up/down

Actually, Stanislav's patches were meant for nfs callback up/down, but I wonder if lockd needs the same treament.

Maybe something like the attached?  (Totally untested.)

Comment 44 Fedora Update System 2012-06-20 00:26:23 UTC
kernel-3.4.2-1.fc16 has been pushed to the Fedora 16 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 45 Tom Horsley 2012-06-20 00:41:37 UTC
Is there some driverless bulldozer pushing these changes to the stable repos and closing this bug? F16 had no NFS problems, but if 3.4.2 doesn't work any better on f16 than it does on f17, then f16 will indeed soon have problems.

Comment 46 J. Bruce Fields 2012-06-20 13:32:29 UTC
Note the previous attachment had an obvious typo (inet_net should have been init_net on both lines).  With that fixed, I've submitted to stable:

http://mid.gmane.org/<20120620132738.GA30742>

(In reply to comment #45)
> Is there some driverless bulldozer pushing these changes to the stable repos
> and closing this bug? F16 had no NFS problems, but if 3.4.2 doesn't work any
> better on f16 than it does on f17, then f16 will indeed soon have problems.

So hopefully the fix will eventually make its way in one way or another.

In the mean time any testing to confirm that patch would be helpful.

Looks like this bug got closed again? I'm not sure what the correct procedure is.  Probably a new bug needs to be opened and the patch attached.

Comment 47 Josh Boyer 2012-06-20 14:50:59 UTC
We'll just reopen this.

Comment 48 Philippe Troin 2012-06-24 19:07:19 UTC
Still seeing the problem with kernel-devel-3.4.3-1.fc17.x86_64.

Comment 49 J. Bruce Fields 2012-06-25 11:56:36 UTC
That's expected.

I'll submit to stable today if I can get a reproducer working.  If somebody wants to speed the process then testing of what I intend to submit would be helpful.  It's in the for-3.4-take-3 branch at git://linux-nfs.org/~bfields/linux-topics.git.  Should backport easily to Fedora.

Comment 50 Stefan Ring 2012-07-03 22:20:22 UTC
Same problem here. Contrary to what is stated here and what I believed until just now, the machine will reboot/shutdown, it just takes its sweet time (it was something like 5-10 minutes).

I will test your git branch tomorrow. Unfortunately, it takes a while to do so, because it doesn't happen right away, but only if the machine has had a few hours of activity.

Comment 51 Stefan Ring 2012-07-04 16:22:36 UTC
I have rebooted a few times with the patches from for-3.4-take-3 applied (on top of 3.4.3-1, though). So far, without adverse effects. I will let you know in a few days how it goes.

Comment 52 Stefan Ring 2012-07-04 20:17:25 UTC
If you're interested in the setup I'm running to trigger this: I have an OpenIndiana (151a-4) machine as a KVM guest which starts at system boot and has a fixed IP. It serves as an iSCSI target (via COMSTAR) as well as the NFS server. After the OpenIndiana guest is booted up, I mount an XFS filesystem that lives on the iSCSI target, and I also mount an NFS share.

Before shutting down the real machine, I unmount both of them, then I shut down the OpenIndiana guest. Only then do I shut down the physical machine.

Comment 53 Stefan Ring 2012-07-06 17:19:38 UTC
Created attachment 596671 [details]
spec file patch

Comment 54 Stefan Ring 2012-07-06 17:20:41 UTC
Created attachment 596672 [details]
screen photo of traceback

Comment 55 Stefan Ring 2012-07-06 17:21:09 UTC
Created attachment 596673 [details]
screen photo of traceback (bottom)

Comment 56 Stefan Ring 2012-07-06 17:21:29 UTC
Bad news:

Something similar, but slightly different happened now, during reboot. I could not scroll up any further than this, but the "Fixing recursive fault" at the bottom may be enough information to infer the cause for the traceback. As before, the system stayed in this condition for a few minutes, then proceeded with the reboot.

The exact version of the source tree I was running was based on this version (see attached patch, which is rather obvious though; the four applied patches are exactly the ones from the mentioned for-3.4-take-3 branch): http://pkgs.fedoraproject.org/gitweb/?p=kernel.git;a=commit;h=50263f813155c14a2cfe6e263eab5325afe0015f

Comment 57 Stefan Ring 2012-07-06 17:52:55 UTC
Hand transcription again:

? __schedule+0x3c7/0x7b0
nsm_create+0x8b/0xb0 [lockd]
nsm_mon_unmon+0x64/0x100 [lockd]
nsm_unmonitor+0x68/0xc0 [lockd]
nlm_destroy_host_locked+0x6b/0xc0 [lockd]
nlmclnt_release_host+0x88/0xc0 [lockd]
nlmclnt_done+0x1a/0x30 [lockd]
nfs_destroy_server+0x24/0x30 [nfs]
nfs_free_server+0xce/0x190 [nfs]
nfs_kill_super+0x34/0x40 [nfs]
deactivate_locked_super+0x57/0x90
deactivate_super+0x4e/0x70
mntput_no_expire+0xcc/0x120
mntput+0x26/0x40
release_mounts+0x77/0x90
put_mnt_ns+0x78/0x90
free_nsproxy+0x1f/0xb0
switch_task_namespaces+0x50/0x60
exit_task_namespaces+0x10/0x20
do_exit+0x456/0x8a0
do_group_exit+0x3f/0xa0
get_signal_to_deliver+0x1a5/0x5c0
? pollwake+0x66/0x70
do_signal+0x68/0x610
? security_file_alloc+0x16/0x20
? eventfd_ctx_read+0x58/0x190
do_notify_resume+0x65/0x80
? __audit_syscall_exit+0x3ec/0x450
int_signal+0x12/0x17

RIP [<ffffffffa0498391>] rpc_create+0x401/0x540 [sunrpc]
Fixing recursive fault but reboot is needed!

Comment 58 Stanislav Kinsbursky 2012-07-09 09:05:13 UTC
Stefan, could you, please, install and configure kdump on you machine and extract full log from kernel core?

Here is the simpliest way to do so:
makedumpfile —dump-dmesg <core> <out_text_file>

Comment 59 J. Bruce Fields 2012-07-12 14:39:03 UTC
*** Bug 839515 has been marked as a duplicate of this bug. ***

Comment 60 Stefan Ring 2012-07-15 21:06:02 UTC
Stanislav, does kdump even generate a core file for this? It's not really a crash/panic after all, just an oops (I think). At the moment, I'm having trouble activating kdump. When I trigger a crash using sysrq-trigger, it panics as usual and doesn't start the crash-kernel at all. I tested the setup in a virtual machine, where it works just fine.

Comment 61 Stanislav Kinsbursky 2012-07-16 08:17:48 UTC
First of all, you have to make sure, that CONFIG_PANIC_ON_OOPS_VALUE kernel option is not equal to zero.
After enabling kdump you have to reboot.

Comment 62 Josh Boyer 2012-07-17 13:29:19 UTC
FYI, the 3.4.5-2.fc17 build that has been submitted for updates-testing contains the 4 patches that are in the for-3.4-take-3 branch mentioned in comment #49.  One should be able to use that for debugging any further issues.

Comment 63 Stefan Ring 2012-07-17 20:21:38 UTC
(In reply to comment #61)
> First of all, you have to make sure, that CONFIG_PANIC_ON_OOPS_VALUE kernel
> option is not equal to zero.

Thanks for this info!

Arghh, the crash kernel has at least tried to boot all along, but for some reason, the secondary kernel does not display anything when nouveau modesetting is in use :(. Now I need to get the actual dumping working, and then I'll just have to somehow manage to trigger the oops again...

Comment 64 Stefan Ring 2012-07-18 12:50:07 UTC
Ok, I've finally managed to configure kdump. dracut has made life difficult for me. The panic on oops is a very recent addition which doesn't even exist in my kernel version, but the effect can apparently more easily be had via the "oops=panic" command line option.

Now I'll just need to wait for it to happen again...

Comment 65 Tom Horsley 2012-07-23 15:34:11 UTC
Just to update this with my experiences with recently released kernels:

kernel-3.4.4-5.fc17.x86_64 - still got the lockd oops when I rebooted this
after an update the other day.

kernel-3.4.5-2.fc17.x86_64 - this was the update I got above, and when I
rebooted this morning, the system did not get the oops anymore (Yah!)

kernel-3.4.6-2.fc17.x86_64 - this is what I'm now running after the above
reboot, hopefully it won't get the oops anymore either, but haven't had any
reason to reboot yet.

Comment 66 Stefan Ring 2012-08-02 17:53:06 UTC
And a status update from me as well: still waiting for the oops to occur again. It's shy. It knows I'm watching :(.

Comment 67 Stefan Ring 2012-08-04 18:56:10 UTC
It happened again just now, but unfortunately, the kdump kernel was not booted for some reason, although I can verify that it works when I write "c" to /proc/sysrq-trigger.

Comment 68 Stefan Ring 2012-08-12 09:37:31 UTC
I have another one on foto now. The thing is, with oops=panic, no kdump gets triggered. It just blinks the keyboard LEDs. As I said already, a "c" sysrq-trigger does in fact start up kdump and create a memory dump.

I'm still running the exact same version described in comment 56.
Anyway, the reconstructed stack trace looks like this now:

CR2: 0000000000000008
Process mysqld

Call Trace:
? __schedule+0x3c7
nsm_create+0x8b
nsm_mon_unmon+0x64
nlm_destroy_host_locked+0x6b
nlmclnt_release_host+0x88
nlmclnt_done+0x1a
nfs_destroy_server+0x24
nfs_free_server+0xce
nfs_kill_super+0x34
deactivate_locked_super+0x57
deactivate_super+0x4e
mntput_no_expire+0xcc
mntput+0x26
release_mounts+0x77
put_mnt_ns+0x78
free_nsproxy+0x1f
switch_task_namespaces+0x50
exit_task_namespaces+0x10
do_exit+0x456
do_group_exit+0x3f
sys_exit_group+0x17
system_call_fastpath+0x16
RIP rpc_create+0x401 [sunrpc]
Kernel panic - not syncing

Subjectively, it seems to happen only when I've used large amounts of RAM during the session, probably with a small amount paged out, so that during shutdown the waking up of various processes causes noticeable disk accesses.

Do you know if it is on purpose that oops=panic does not trigger a kdump?

Comment 69 Stanislav Kinsbursky 2012-08-13 10:05:34 UTC
This all looks very strange.
According to your trace, mysqld is in container with it's own mount and pid namespace (at least). And it's the init of this container. And it's have NFS mounts inside.
If so, then "killall -9 mysqld" most probably will trigger this oops.
Could you try it, please?

Comment 70 Stefan Ring 2012-08-13 10:43:06 UTC
(In reply to comment #69)
> This all looks very strange.
> According to your trace, mysqld is in container with it's own mount and pid
> namespace (at least). And it's the init of this container. And it's have NFS
> mounts inside.

The crashing RIP is 3391 (rpc_create starts at 2f90, rpc_new_client was inlined):

    3375:       0f 87 85 00 00 00       ja     3400 <rpc_create+0x470>
    337b:       65 48 8b 04 25 00 00    mov    %gs:0x0,%rax
    3382:       00 00 
    3384:       48 8b 80 38 05 00 00    mov    0x538(%rax),%rax
    338b:       4c 89 e7                mov    %r12,%rdi
    338e:       4d 89 e6                mov    %r12,%r14
 => 3391:       48 8b 70 08             mov    0x8(%rax),%rsi
    3395:       48 83 c6 45             add    $0x45,%rsi
    3399:       e8 22 e1 ff ff          callq  14c0 <rpc_clnt_set_nodename>
    339e:       4c 89 e7                mov    %r12,%rdi
    33a1:       e8 aa ef ff ff          callq  2350 <rpc_register_client>
    33a6:       e9 b4 fc ff ff          jmpq   305f <rpc_create+0xcf>
    33ab:       0f 1f 44 00 00          nopl   0x0(%rax,%rax,1)


From what I see, the crash happens here: <http://lxr.free-electrons.com/source/net/sunrpc/clnt.c?v=3.5#L368>, because something in the chain current->nsproxy->uts_ns->name (inside utsname()) is NULL. Did you also come to this conclusion?

> If so, then "killall -9 mysqld" most probably will trigger this oops.
> Could you try it, please?

Yes, I will try that later.

Comment 71 Stanislav Kinsbursky 2012-08-13 10:55:12 UTC
Thanks. I know where the bug is.

static struct rpc_clnt * rpc_new_client(...)
{
< snip >

rpc_clnt_set_nodename(clnt, utsname()->nodename);

<snip>
}

static inline struct new_utsname *utsname(void)
{
        return &current->nsproxy->uts_ns->name;
}


current->nsproxy is NULL already.

Comment 72 Stanislav Kinsbursky 2012-08-13 11:26:09 UTC
Patch sent to mainline.
Topic: "SUNRPC: check current nsproxy before set of node name on client creation"

Comment 73 Stefan Ring 2012-08-13 15:08:50 UTC
> If so, then "killall -9 mysqld" most probably will trigger this oops.
> Could you try it, please?

Nothing happened, except mysqld died.

I will update to the most recent F17 kernel and apply your new patch tomorrow.

Comment 74 Stanislav Kinsbursky 2012-08-13 15:39:05 UTC
(In reply to comment #73)
> 
> Nothing happened, except mysqld died.
> 
> I will update to the most recent F17 kernel and apply your new patch
> tomorrow.

This is expected. Otherwise you would experience this oops every time.
I don't know, what you or mysqld is doing, but there have to be NFS mounts on your node (mounted by mysqld or it's child) to trigger oops on "kill -9" command.

Comment 75 Stefan Ring 2012-08-13 16:10:12 UTC
I'm not doing anything weird. If I were, I would have described it. Yes, I do have an NFS mount, but MySQL has nothing to do with that one. It is the default Fedora package in the default location on a SATA disk. I mounted the NFS before I started mysqld and unmounted it before trying to shutdown (which led to the oops).

Comment 76 Stefan Ring 2012-08-15 14:45:15 UTC
I've upgraded to 3.5.1-1.fc17 with this [1] patch applied, but unfortunately, something much worse happens now (iscsi related, #848425), so I cannot comment on the state of affairs regarding the NFS problem.

[1] https://lkml.org/lkml/2012/8/13/123

Comment 77 H.J. Lu 2012-08-15 18:09:08 UTC
I also saw

[443503.679360] BUG: unable to handle kernel NULL pointer dereference at 0000000000000014
[443503.679386] IP: [<ffffffffa01e20aa>] svc_destroy+0x1a/0x130 [sunrpc]
[443503.679413] PGD 0 
[443503.679420] Oops: 0000 [#1] SMP 
[443503.679429] CPU 11 
[443503.679434] Modules linked in: nfs fscache tpm_bios igb ptp pps_core i7core_edac ioatdma edac_core dca lpc_ich coretemp kvm_intel i2c_i801 snd_hda_codec_realtek shpchp mfd_core kvm snd_hda_intel snd_hda_codec snd_hwdep snd_pcm nfsd snd_page_alloc snd_timer nfs_acl snd auth_rpcgss microcode soundcore lockd sunrpc uinput crc32c_intel ghash_clmulni_intel firewire_ohci firewire_core crc_itu_t nouveau mxm_wmi wmi video i2c_algo_bit drm_kms_helper ttm drm i2c_core [last unloaded: scsi_wait_scan]
[443503.679565] 
[443503.679568] Pid: 13391, comm: rpc.nfsd Not tainted 3.5.1-1.fc17.x86_64 #1 Intel Corporation S5520SC/S5520SC
[443503.679584] RIP: 0010:[<ffffffffa01e20aa>]  [<ffffffffa01e20aa>] svc_destroy+0x1a/0x130 [sunrpc]
[443503.679607] RSP: 0018:ffff880322801e58  EFLAGS: 00010246
[443503.679625] RAX: 00000000ffffff91 RBX: 0000000000000000 RCX: 0000000000000100
[443503.679633] RDX: 0000000000000100 RSI: 0000000050251f41 RDI: 0000000000000000
[443503.679642] RBP: ffff880322801e60 R08: ffff88065c1cd000 R09: 0000000000000000
[443503.679650] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000002
[443503.679659] R13: 0000000000000004 R14: ffff880322801f58 R15: 00007f2d0d0212ae
[443503.679668] FS:  00007f2d0cff4740(0000) GS:ffff88066fca0000(0000) knlGS:0000000000000000
[443503.679684] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[443503.679698] CR2: 0000000000000014 CR3: 000000065be8d000 CR4: 00000000000007e0
[443503.679739] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[443503.679796] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[443503.679837] Process rpc.nfsd (pid: 13391, threadinfo ffff880322800000, task ffff88035d701710)
[443503.679878] Stack:
[443503.679895]  ffff880382fae008 ffff880322801ee0 ffffffffa0285b7f 00007f2dffffff91
[443503.679961]  ffff880382fae009 ffff880322801e8f 0034fffffffffff4 0000000000000002
[443503.680023]  ffff880322801ea8 ffffffff81128586 ffff880322801ee0 ffffffff811a89d5
[443503.680103] Call Trace:
[443503.680133]  [<ffffffffa0285b7f>] write_ports+0x2cf/0x3e0 [nfsd]
[443503.680185]  [<ffffffff81128586>] ? get_zeroed_page+0x16/0x20
[443503.680229]  [<ffffffff811a89d5>] ? simple_transaction_get+0xc5/0xe0
[443503.680264]  [<ffffffffa02858b0>] ? write_gracetime+0x60/0x60 [nfsd]
[443503.680295]  [<ffffffffa0285027>] nfsctl_transaction_write+0x57/0x90 [nfsd]
[443503.680327]  [<ffffffff811861bc>] vfs_write+0xac/0x180
[443503.680348]  [<ffffffff811864ea>] sys_write+0x4a/0x90
[443503.680365]  [<ffffffff8160a26d>] system_call_fastpath+0x1a/0x1f
[443503.680385] Code: 31 c0 e8 82 63 41 e1 eb be e8 23 60 e7 e0 0f 1f 00 55 48 89 e5 53 66 66 66 66 90 f6 05 6c 1c 02 00 02 48 89 fb 0f 85 ef 00 00 00 <8b> 43 14 85 c0 0f 84 ce 00 00 00 83 e8 01 85 c0 89 43 14 0f 85 
[443503.680724] RIP  [<ffffffffa01e20aa>] svc_destroy+0x1a/0x130 [sunrpc]
[443503.680761]  RSP <ffff880322801e58>
[443503.680777] CR2: 0000000000000014
[443503.685860] ---[ end trace 7a679bc1c3066273 ]---
[root@gnu-mic-2 gcc]#

Comment 78 Jeff Layton 2012-08-16 14:39:02 UTC
*** Bug 848740 has been marked as a duplicate of this bug. ***

Comment 79 Jeff Layton 2012-08-16 15:05:41 UTC
(In reply to comment #77)
> I also saw
> 
> [443503.679360] BUG: unable to handle kernel NULL pointer dereference at
> 0000000000000014
> [443503.679386] IP: [<ffffffffa01e20aa>] svc_destroy+0x1a/0x130 [sunrpc]

I think the above is unrelated to the other issues in this bug. It looks like svc_destroy got passed a NULL pointer. Could you open a new bug for this one?

Comment 80 Stefan Ring 2012-08-27 11:47:54 UTC
(In reply to comment #69)
> This all looks very strange.
> According to your trace, mysqld is in container with it's own mount and pid
> namespace (at least). And it's the init of this container. And it's have NFS
> mounts inside.

I suspect that this is because of systemd's PrivateTmp feature. On the same system, this is one of the other problems that plague me: bug #851970.

Because of this, I'll have to shut down everything in a well defined order before rebooting, so I will not be able to do meaningful testing of this feature in the near future. I'm running with your latest patch applied, at least, for a while now.

Comment 81 Jeff Layton 2012-12-18 01:55:51 UTC
Whew, this bug is a mess...

It sounds like the originally reported bug is now fixed in more recent kernels, based on comment 76.

The oops in comment #77 is likely a duplicate of bug 848867.

At this point, I'm going to go ahead and close this bug. If anyone is still suffering from the originally reported issue, then please reopen this bug. If you are suffering from a different one, then please open a new bug.

Comment 82 Stefan Ring 2012-12-23 10:39:53 UTC
It seems that everything that went on before I first chimed in (comment 50) has gone into the released Fedora kernel. From that point on, there were more patches.

First, the 4 ones from http://git.linux-nfs.org/?p=bfields/linux-topics.git;a=shortlog;h=refs/heads/for-3.4-take-3

They have all been taken from the mainline and have gone into the released F17 kernel since then.

OTOH, I still experienced a crash with those 4 applied (comment 56). This led to the posting of a patch in <https://lkml.org/lkml/2012/8/13/123>. The thread petered out with no patch applied. Instead, it seems to have been supplanted by 1b63a75180c6c65c71655c250a4e6b578ba7d1c0 (and probably ba9b584c1dc37851d9c6ca6d0d2ccba55d9aad04, its direct successor), both of which have not made their way into 3.6.11, and by extension, into the F17 kernel.

So technically, it's still not fixed. Practically, it's not easily triggered anymore because of a systemd upgrade described below.

Right now, it would be very time consuming for me to try and reproduce it again, but I think I know how one would do that. In the meantime, an update to systemd has happened that will not cause the code path in question to be taken, so the update from bug #851970, comment 24 needs to be taken out for this to work.

- Boot up normally
- Mount an NFS share
- Start the MySQL service (it has PrivateTmp set, which is key to this issue)
- Use up all the memory. If MySQL has not been configured to bypass the file system cache, this can be done by loading a large dump into it.
- Unmount the NFS share
- Reboot

The "use up all memory" seems to be required to trigger disk accesses during shutdown, thus causing waits and scheduler intervention.


Note You need to log in before you can comment on or make changes to this bug.