'show alllocks' of completely locked machine [Was: Re: Complete IO lockup, state "ufs" from userland, debuging help wanted]

Mon Mar 6 20:10:48 UTC 2017

On 03/06/17 at 08:56P, Harry Schmalzbauer wrote:
>  Bez?glich Harry Schmalzbauer's Nachricht vom 05.03.2017 22:59 (localtime):
> >  Hello,
> >
> > I can easily lock up FreeBSD stable/11 from userland. Not that I want to...
> > I'm running squid, which starts an authentication helper
> > "*negotiate_kerberos_auth*", which seems to be the culprit.
> > Completely all IO is blocked, there's no way to get anything from any
> > filesystem.
> > All non IO-requesting processes(threads) run well, including sshd and
> > shells.
> > There's no load (neither cpu nor io) just any process requesting io
> > stucks in state "ufs"
> >
> > Can anyone help me finding out what's going wrong?
> > Serial console is available.
> 
> Dear hackers,
> 
> I managed to get into DDB, but I'm lost from there?
> 
> What information could be usefull to find out the cause of this complete
> lockup?
> 
> I'd need someone who could guide me through ? I'd pay for a debuging
> lesson! (quiet constrained budget though)
> 
> This happens when the machine got stuck:
> 
> intr_event_handle() at intr_event_handle+0x9c/frame 0xfffffe0093dcb7d0
> intr_execute_handlers() at intr_execute_handlers+0x48/frame
> 0xfffffe0093dcb800
> lapic_handle_intr() at lapic_handle_intr+0x68/frame 0xfffffe0093dcb840
> Xapic_isr1() at Xapic_isr1+0xb7/frame 0xfffffe0093dcb840
> --- interrupt, rip = 0xffffffff807b9bd6, rsp = 0xfffffe0093dcb910, rbp =
> 0xfffffe0093dcb910 ---
> acpi_cpu_c1() at acpi_cpu_c1+0x6/frame 0xfffffe0093dcb910
> acpi_cpu_idle() at acpi_cpu_idle+0x2ea/frame 0xfffffe0093dcb960
> cpu_idle_acpi() at cpu_idle_acpi+0x3f/frame 0xfffffe0093dcb980
> cpu_idle() at cpu_idle+0x8f/frame 0xfffffe0093dcb9a0
> sched_idletd() at sched_idletd+0x436/frame 0xfffffe0093dcba70
> fork_exit() at fork_exit+0x84/frame 0xfffffe0093dcbab0
> fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe0093dcbab0
> --- trap 0, rip = 0, rsp = 0, rbp = 0 ---
> 
> 
> db> show alllocks
> Process 1259 (negotiate_kerberos_) thread 0xfffff80005ddea00 (100096)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1258 (negotiate_kerberos_) thread 0xfffff80005ddc500 (100252)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1257 (negotiate_kerberos_) thread 0xfffff80005ddda00 (100247)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1256 (negotiate_kerberos_) thread 0xfffff80065612500 (100261)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1255 (negotiate_kerberos_) thread 0xfffff80065612a00 (100260)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1254 (negotiate_kerberos_) thread 0xfffff80065613000 (100257)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1253 (negotiate_kerberos_) thread 0xfffff80065614000 (100254)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1252 (negotiate_kerberos_) thread 0xfffff800651e1000 (100246)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1251 (negotiate_kerberos_) thread 0xfffff80005ddca00 (100251)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1250 (negotiate_kerberos_) thread 0xfffff800651e2a00 (100241)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1251 (negotiate_kerberos_) thread 0xfffff80005ddca00 (100251)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1250 (negotiate_kerberos_) thread 0xfffff800651e2a00 (100241)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1247 (sqtop) thread 0xfffff80065650a00 (100259)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1184 (systat) thread 0xfffff80065613a00 (100255)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1042 (negotiate_kerberos_) thread 0xfffff800651e2500 (100242)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 1041 (negotiate_kerberos_) thread 0xfffff800055e4000 (100078)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 639 (cron) thread 0xfffff80005afa000 (100095)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 605 (log_file_daemon) thread 0xfffff800057eda00 (100088)
> exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffff80005b547b0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/uipc_sockbuf.c:283
> Process 604 (ext_ldap_group_acl) thread 0xfffff800057dc000 (100087)
> exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffff80005b550f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/uipc_sockbuf.c:283
> Process 603 (ext_ldap_group_acl) thread 0xfffff80005478000 (100063)
> exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffff80005b410f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/uipc_sockbuf.c:283
> Process 601 (negotiate_kerberos_) thread 0xfffff80005afc000 (100085)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 600 (negotiate_kerberos_) thread 0xfffff80005afc500 (100084)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 599 (negotiate_kerberos_) thread 0xfffff80005478a00 (100061)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 598 (negotiate_kerberos_) thread 0xfffff8000547a000 (100057)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 597 (negotiate_kerberos_) thread 0xfffff80005afca00 (100083)
> exclusive lockmgr ufs (ufs) r = 0 (0xfffff800057555f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/fs/unionfs/union_vnops.c:1905
> Process 596 (negotiate_kerberos_) thread 0xfffff8000559a500 (100068)
> exclusive lockmgr ufs (ufs) r = 0 (0xfffff800055125f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/fs/unionfs/union_vnops.c:1936
> exclusive lockmgr ufs (ufs) r = 0 (0xfffff8000523d068) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/fs/unionfs/union_vnops.c:1905
> Process 595 (negotiate_kerberos_) thread 0xfffff800055e3a00 (100079)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611
> Process 594 (negotiate_kerberos_) thread 0xfffff80005599000 (100072)
> shared lockmgr ufs (ufs) r = 0 (0xfffff8000523d5f0) locked @
> /usr/local/share/deploy-tools/RELENG_11/src/sys/kern/vfs_lookup.c:611

IMO, you'd want to take a crashdump so you can analyze it better.
But first while you are at db> prompt,

db> show allchains
db> show sleepchain

Paste that o/p here and then take the dump:
db> call doadump

Then you can reboot the box:
db> reboot

Once it comes back up, you can look at the crashdump (usually at
/var/crash/)
# kgdb /boot/kernel/kernel /var/crash/<vmcore>.N

In such situations, https://github.com/bsdjhb/kdbg is really useful. 

Cheers,
Hiren
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 603 bytes
Desc: not available
URL: <http://lists.freebsd.org/pipermail/freebsd-stable/attachments/20170306/0aa97b23/attachment.sig>