DragonFlyBSD

I'm seeing the same behavior with my vkernel-mp work. Often the
vkernel hangs and is unkillable leaving the processes around until I
reboot and I see these messages. I haven't seen them otherwise and
rebooting succeeds without intervention.

Joe

:I'm seeing the same behavior with my vkernel-mp work. Often the
:vkernel hangs and is unkillable leaving the processes around until I
:reboot and I see these messages. I haven't seen them otherwise and
:rebooting succeeds without intervention.
:
:Joe

You should always be able to kill -9 a vkernel.  Can you gdb it when
    it is in that state?

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

I run it from gdb to start with and when I try to kill it via gdb it
hangs.

Program received signal SIGQUIT, Quit.
0x282c5858 in sigsuspend () from /usr/lib/libc.so.6
(gdb) bt
#0 0x282c5858 in sigsuspend () from /usr/lib/libc.so.6
#1 0x282766a8 in _sigsuspend (set=0x0)
at
/home/josepht/src/vksrc.cvs.2/lib/libthread_xu/thread/thr_sig.c:202
#2 0x282c285c in sigpause () from /usr/lib/libc.so.6
#3 0x08203ee5 in cpu_idle ()
at
/home/josepht/src/vksrc/sys/platform/vkernel/i386/cpu_regs.c:707
#4 0x00000000 in ?? ()
(gdb) k
Kill the program being debugged? (y or n) y

^^^ nothing

Here's what I see in kgdb:

• 50 Thread 0xdd919e00 (PID=13027: kernel.debug) lwkt_switch ()
  at thread2.h:177
  49 Thread 0xd688c600 (PID=13027: kernel.debug) lwkt_switch ()
  at thread2.h:177

(kgdb) thread 50
[Switching to thread 50 (Thread 0xdd919e00)]#0 lwkt_switch () at
thread2.h:177
177 globaldata_t gd = curtd->td_gd;
(kgdb) bt
#0 lwkt_switch () at thread2.h:177
#1 0xc020c4b1 in tsleep (ident=0xd68a9ac0, flags=256,
wmesg=0xc0429363 "pause", timo=0)
at /home/josepht/src/vksrc.cvs.2/sys/kern/kern_synch.c:473
#2 0xc01ffb51 in kern_sigsuspend (set=0x0)
at /home/josepht/src/vksrc.cvs.2/sys/kern/kern_sig.c:551
#3 0xc01ffb94 in sys_sigsuspend (uap=0x0)
at /home/josepht/src/vksrc.cvs.2/sys/kern/kern_sig.c:571
#4 0xc03db1a8 in syscall2 (frame=0xdd996d40)
at
/home/josepht/src/vksrc.cvs.2/sys/platform/pc32/i386/trap.c:1340
#5 0xc03c2b55 in Xint0x80_syscall ()
at
/home/josepht/src/vksrc.cvs.2/sys/platform/pc32/i386/exception.s:872
#6 0x282c5858 in ?? ()
#7 0x41007cf0 in ?? ()
#8 0x0000002f in ?? ()
#9 0x00000000 in ?? ()
#10 0x00000000 in ?? ()
#11 0x00000000 in ?? ()
#12 0x00000000 in ?? ()
#13 0x14d81000 in ?? ()
#14 0xff800000 in ?? ()
#15 0xdd919e00 in ?? ()
#16 0xdd996bcc in ?? ()
#17 0xdd996b9c in ?? ()
#18 0xdd918600 in ?? ()
#19 0xc0207152 in lwkt_switch ()
at /home/josepht/src/vksrc.cvs.2/sys/kern/lwkt_thread.c:749
Previous frame inner to this frame (corrupt stack?)

Joe

:Got this today when I rebooted:
:
:Jun 27 16:21:47 ylem reboot: rebooted by root
:pflog0: promiscuous mode disabled
:boot() called on cpu#0
:Waiting (max 60 seconds) for system thread vnlru to stop...stopped
:Waiting (max 60 seconds) for system thread bufdaemon to stop...stopped
:Waiting (max 60 seconds) for system thread syncer to stop...stopped
:
:syncing disks... 20 3
:done
:unmount(0xda065be0): Forced unmount: 0 namecache references still present
:unmount(0xda065be0): Forced unmount: 6 process references still present
:unmount(0xda065700): Forced unmount: 8 namecache references still present
:unmount(0xda065700): Forced unmount: 14 process references still present
:Uptime: 1h45m41s
:
:
:And then it stopped. Had to power cycle the machine to get it to reboot.
:
:Code is latest -HEAD.
:
:--Peter

Post your 'df' output from a running system.  Are you using any
    nullfs, mfs, or nfs mounts?

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

:I run it from gdb to start with and when I try to kill it via gdb it
:hangs.
:
:
:(kgdb) thread 50
:[Switching to thread 50 (Thread 0xdd919e00)]#0 lwkt_switch () at
:thread2.h:177
:177 globaldata_t gd = curtd->td_gd;
:(kgdb) bt
:#0 lwkt_switch () at thread2.h:177
:#1 0xc020c4b1 in tsleep (ident=0xd68a9ac0, flags=256,
: wmesg=0xc0429363 "pause", timo=0)
: at /home/josepht/src/vksrc.cvs.2/sys/kern/kern_synch.c:473
:#2 0xc01ffb51 in kern_sigsuspend (set=0x0)
: at /home/josepht/src/vksrc.cvs.2/sys/kern/kern_sig.c:551
:#3 0xc01ffb94 in sys_sigsuspend (uap=0x0)
: at /home/josepht/src/vksrc.cvs.2/sys/kern/kern_sig.c:571
:#4 0xc03db1a8 in syscall2 (frame=0xdd996d40)
: at
:/home/josepht/src/vksrc.cvs.2/sys/platform/pc32/i386/trap.c:1340
:#5 0xc03c2b55 in Xint0x80_syscall ()
: at
:/home/josepht/src/vksrc.cvs.2/sys/platform/pc32/i386/exception.s:872
:
:Joe

This kinda sounds like a bad interaction between gdb and the vkernel.

Try running the vkernel normally, without gdb.  Get it to hang while
    halting, and see if you can kill -9 the vkernel process(es) from another
    xterm.

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

That seems to work much better.

Joe

1. df -h
   Filesystem Size Used Avail Capacity Mounted on
   /dev/da0s1a 32G 11G 18G 38% /
   /dev/da1s1e 135G 71G 53G 57% /home
   procfs 4.0K 4.0K 0B 100% /proc
   linprocfs 4.0K 4.0K 0B 100% /usr/pkg/emul/linux/proc

No nullfs, mfs, or nfs.

FYI, this is not a vkernel.

--Peter

I managed to get a vkernel to hang and cannot kill -9 it. I attached
gdb and this is what I get:

(gdb) bt
#0 0x282c5858 in ?? ()
Error accessing memory address 0x41007cf0: Bad address.
(gdb) info registers
eax 0x155 341
ecx 0x0 0
edx 0x28340100 674496768
ebx 0x2827b72c 673691436
esp 0x41007cf0 0x41007cf0
ebp 0x41007d3c 0x41007d3c
esi 0x0 0
edi 0x41007d54 1090551124
eip 0x282c5858 0x282c5858
eflags 0x206 518
cs 0x1f 31
ss 0x2f 47
ds 0x2f 47
es 0x2f 47
fs 0x83 131
gs 0x7b 123
(gdb) disassemble $eip
No function contains specified address.

Joe

:I managed to get a vkernel to hang and cannot kill -9 it. I attached
:gdb and this is what I get:

Ok, I think its related to the threading.  Could you email me your
   current patch set and the tests you are running that get the vkernel
   into its unkillable state?  I'll try to reproduce it and track the
   problem down.

How far into the boot sequence is your threaded vkernel getting now?
   If its getting to init then I have to get the multi-threaded VMSPACE_*
   support working (else things will explode).

-Matt

:# df -h
:Filesystem Size Used Avail Capacity Mounted on
:/dev/da0s1a 32G 11G 18G 38% /
:/dev/da1s1e 135G 71G 53G 57% /home
:procfs 4.0K 4.0K 0B 100% /proc
:linprocfs 4.0K 4.0K 0B 100% /usr/pkg/emul/linux/proc
:
:No nullfs, mfs, or nfs.
:
:FYI, this is not a vkernel.
:
:--Peter

I'm still not having any luck reproducing it, but I'm still trying.
    Try unmounting procfs and linprocfs manually without -f and see
    if it complains about any of them.

I know there are issues in this area, its just a matter of figuring
    out what is causing the hanging refs.

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

I tried unmounting both procfs and linprocfs with the same results. I
also edited fstab and got rid of everything except / and swap. When I did
that, I still got the "Forced unmount" messages, but only got 2 instead
of 4. Does that help?

--Peter

Now I'm seeing acpi_button messages:

boot() called on cpu#1
Switching to cpu #0 for shutdown
Waiting (max 60 seconds) for system thread vnlru to stop...stopped
Waiting (max 60 seconds) for system thread bufdaemon to stop...stopped
Waiting (max 60 seconds) for system thread syncer to stop...stopped

syncing disks... 13 1
done
unmount(0xd9f157c0): Forced unmount: 0 namecache references still present
unmount(0xd9f157c0): Forced unmount: 6 process references still present
unmount(0xd9f152e0): Forced unmount: 8 namecache references still present
unmount(0xd9f152e0): Forced unmount: 14 process references still present
Uptime: 53m53s
acpi_button0: wake_prep enabled gpe 0x17 for state 0
acpi_button1: wake_prep enabled gpe 0x8 for state 0

This still happens with acpi disabled (the freeze and forced unmounts).

:Peter Avalos <pavalos@theshell.com> added the comment:
:
:Now I'm seeing acpi_button messages:

Ok, I'm not sure what is going on with the buttons.  But lets try
    to get some additional information on the forced unmounts.  I don't
    like the fact that 14 processes seem to be stuck.

Lets try to get a good kernel core for this condition.  Here's a patch
    which will hopefully print out which mount(s) are having problems, and
    will also panic the system when it hits a mount with more then 12 
    process references (the idea being to try to get a snapshot of the
    kernel when its in this situation that can then be kgdb'd).

Once you get a good kernel core, remove the panic.

I have a feeling that the freeze is due to the mount confusion and not
    ACPI, but I could be wrong.

Index: vfs_syscalls.c ===================================================================
RCS file: /cvs/src/sys/kern/vfs_syscalls.c,v
retrieving revision 1.117
diff u -p -r1.117 vfs_syscalls.c
-- vfs_syscalls.c 26 Jun 2007 20:39:33 0000 1.117
++ vfs_syscalls.c 7 Jul 2007 19:06:17 -0000
@ -678,6 +678,8 @ mount_warning(mp, "Forced unmount: "
"%d process references still "
"present", mp>mnt_refs);
freeok = 0;
if (panicstr == NULL && mp->mnt_refs > 12)
+ panic("Panicing on forced unmount");
}
}

@ -758,7 +760,10 @ kvprintf(ctl, va);
kprintf("\n");
kfree(buf, M_TEMP);
} else {
- kprintf("unmount(p): ", mp);
+ kprintf("unmount(%p", mp);
+ if (mp->mnt_ncmounton.ncp &x%x mp->mnt_ncmounton.ncp->nc_name)
+ kprintf(",%s", mp->mnt_ncmounton.ncp->nc_name);
+ kprintf("): ");
kvprintf(ctl, va);
kprintf("\n");
}

When I was doing some testing I noticed that if I only mount / (ufs) then
I only get 2 warnings. So the 4 warning are actually 2 from each ufs mount.
Not sure if that helps...I'll try the patch.

--Peter

Oh, and it still freezes with ACPI disabled, so I'd agree that it's a
mount problem and not acpi.

(kgdb) bt
#0 dumpsys () at thread.h:83
#1 0xc0199802 in boot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:371
#2 0xc0199b1f in panic (fmt=Variable "fmt" is not available.
) at /usr/src/sys/kern/kern_shutdown.c:796
#3 0xc01efae4 in dounmount (mp=0xd9f152e0, flags=524288) at /usr/src/sys/kern/vfs_syscalls.c:682
#4 0xc01e80ad in vfs_umountall_callback (mp=0xd9f152e0, data=0x0) at /usr/src/sys/kern/vfs_subr.c:1561
#5 0xc01eb1ba in mountlist_scan (callback=0xc01e808e <vfs_umountall_callback>, data=0x0, how=Variable "how" is not available.
) at /usr/src/sys/kern/vfs_mount.c:815
#6 0xc01e74f5 in vfs_unmountall () at /usr/src/sys/kern/vfs_subr.c:1550
#7 0xc0199662 in boot (howto=Variable "howto" is not available.
) at /usr/src/sys/kern/kern_shutdown.c:359
#8 0xc019993e in sys_reboot (uap=0xe9265cf0) at /usr/src/sys/kern/kern_shutdown.c:189
#9 0xc02e2829 in syscall2 (frame=0xe9265d40) at /usr/src/sys/platform/pc32/i386/trap.c:1340
#10 0xc02ce215 in Xint0x80_syscall () at /usr/src/sys/platform/pc32/i386/exception.s:872
#11 0x08048d5c in ?? ()
#12 0xbfbff8fc in ?? ()
#13 0x0000002f in ?? ()
#14 0x00000000 in ?? ()
#15 0x00000000 in ?? ()
#16 0x00000000 in ?? ()
#17 0x00000000 in ?? ()
#18 0x080f7000 in ?? ()
#19 0xe8cf0a00 in ?? ()
#20 0xff800000 in ?? ()
#21 0xe92659f4 in ?? ()
#22 0xe92659b4 in ?? ()
#23 0xff8003a4 in ?? ()
#24 0xc01a1e72 in lwkt_switch () at /usr/src/sys/kern/lwkt_thread.c:752
Previous frame inner to this frame (corrupt stack?)

Uploading to leaf now.

Your php processes aren't exiting:

0   841 e8cf3200 00040600 php        00000000 waitmsg
  0   994 e8cf0e00 00040600 php        00000000 waitmsg
  0   995 e8cf0d00 00040600 php        00000000 waitmsg
  0   843 e8cf3000 00040600 php        00000000 waitmsg
  1   840 e8cf3300 00040600 php        00000000 waitmsg
  1   842 e8cf3100 00040600 php        00000000 waitmsg

They are stuck in accept() and the accept() is marked as being
    uninterruptable.

Oh!  Oh my.  WTF.  It's a bug in the network stack.   The local
    unix domain sockets are using sync_soport() when they really
    should not be.

It was an optimization that went a little too far.  sync_soport()
    calls the dispatch function in the context of the caller rather
    then using a protocol thread, but it also waits for the message
    to complete and passes a flags value of 0 (i.e. tells it to ignore
    signals) when it shouldn't.

I'll be able to get this fixed today, definitely.

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

Ok, netisr.c rev 1.35 should fix the problem of php processes getting
stuck on shutdown.

Lets see if that fixes your freeze too.

-Matt

No more forced unmounts...Cool.

Unfortunately, it still freezes after the Uptime: message. I've tried this
with and without ACPI.

Any other ideas?

Am I the only one that is not able to 'reboot' their machine?

--Peter

:No more forced unmounts...Cool.
:
:> Lets see if that fixes your freeze too.
:>=20
:
:Unfortunately, it still freezes after the Uptime: message. I've tried this
:with and without ACPI.
:
:Any other ideas?
:
:Am I the only one that is not able to 'reboot' their machine?

I think so :-).

Start adding kprintf()'s to the kernel in the code paths after the
    Uptime message is printed.  In paricular, the device shutdown
    path (device_shutdown() line 1198 in kern/subr_bus.c).  Also boot
    with verbose mode so the shutdown is verbose too.

Now that we've gotten one issue out of the way at least, is it
    possible to break into the debugger after it freezes or is that still
    a no go?

Another thing to try, drop into single user by killing init
    i.e.  'kill 1', do a ps to make sure everything has been killed
    (the only user processes left should be init, -sh, and your ps),
    and then see if a reboot freezes the system.

It's got to be something stupid simple.  Literally.  The shutdown
    got through all the hard stuff already.  It's like it can't reset
    the cpu or something.

-Matt

Sucks ;)

Okay, I'll give it a shot.

No workie.

Indeed, only kernel threads and init, sh, and ps, but a reboot still freezes
after "Uptime: xxxx"

BTW, with verbose logging, that's where I was getting the acpi_button
messages from.

I got this once or twice somewhere along the lines,
but not reproducibly so, so I've been silent.

do get the occasional:

unmount(0xd9f157c0): Forced unmount: 0 namecache references still present

kinds of things however, but overall, reboot / shutdown tends to work.

affected systems (as I recall) are mostly 'bare',
but do use lots of "nfs -o tcp" mounts via amd..

perhaps this might interact with the sockets you were mentioning ?

(in the netisr.c diff grok attempt, lacking my ip-stack-foo was)

... which means it's stuck at somewhere at the bottom of boot()
in kern_shutdown.c:
/* * Ok, now do things that assume all filesystem activity has * been completed.
*/
EVENTHANDLER_INVOKE(shutdown_post_sync, howto);
crit_enter();
if ((howto & (RB_HALT|RB_DUMP)) == RB_DUMP && !cold)
dumpsys();

/* Now that we're going to really halt the system... */
        EVENTHANDLER_INVOKE(shutdown_final, howto);

for(;;) ;       /* safety against shutdown_reset not working /
        / NOTREACHED */

At first I thought it's in cpu_reset(), but since you didn't see
"Rebooting...", it's stuck in one of event handlers for shutdown_post_sync
and not managed to shutdown_reset(). Please try attached patch to
find which handler is the culprit. Note that you may have to rebuild
modules too, since this patches makes some incompatible changes to
EVENTHANDLER_* APIs.

Cheers.

In some of my own testing I've verified that it never gets to the
shutdown_final handler. I'll try your patch out later today. Thanks!

--Peter

Duh, I forgot including the change to kern_shutdown.c. Can you insert
"eventhandler_show_invoked_funcs = 1;" somewhere just before the call
to EVENTHANDLER_INVOKE(shutdown_post_sync, howto) ?

Cheers.

eventhandler_show_invoked_funcs = 1;    /* ADD THIS! */

EVENTHANDLER_INVOKE(shutdown_post_sync, howto);
crit_enter();
if ((howto & (RB_HALT|RB_DUMP)) RB_DUMP && !cold)
dumpsys();

/* Now that we're going to really halt the system... */
EVENTHANDLER_INVOKE(shutdown_final, howto);

for(;;) ; /* safety against shutdown_reset not working /
/ NOTREACHED */

At first I thought it's in cpu_reset(), but since you didn't see
"Rebooting...", it's stuck in one of event handlers for shutdown_post_sync
and not managed to shutdown_reset(). Please try attached patch to
find which handler is the culprit. Note that you may have to rebuild
modules too, since this patches makes some incompatible changes to
EVENTHANDLER_* APIs.

Cheers.

Index: sys/eventhandler.h
=================================================================
RCS file: /home/source/dragonfly/cvs/src/sys/sys/eventhandler.h,v
retrieving revision 1.7
diff u -p -r1.7 eventhandler.h
-- sys/eventhandler.h 21 May 2006 03:43:47 -0000 1.7
++ sys/eventhandler.h 11 Jul 2007 04:31:07 -0000
@ -43,6 +43,7 @ struct eventhandler_entry
TAILQ_ENTRY(eventhandler_entry) ee_link;
int ee_priority;
void *ee_arg;
const char *ee_name;
};

struct eventhandler_list
@ -55,6 +56,7 @ struct eventhandler_list
};

typedef struct eventhandler_entry *eventhandler_tag;
+extern int eventhandler_show_invoked_funcs;

/*

• Fast handler lists require the eventhandler list be present
  @ -85,13 +87,15 @ do { \
  struct eventhandler_entry *ep = TAILQ_FIRST(&(_el->el_entries)); \
  \
  while (_ep != NULL) { \
  + if (eventhandler_show_invoked_funcs) \
  + kprintf("FAST_INVOKE(" #name ") %s\n", _ep->ee_name); \
  ((struct eventhandler_entry ## name *)_ep)->eh_func(_ep->ee_arg , ## args); \
  _ep = TAILQ_NEXT(_ep, ee_link); \
  } \
  } while (0)

#define EVENTHANDLER_FAST_REGISTER(name, func, arg, priority) \
- eventhandler_register(Xeventhandler_list_ ## name, #name, func, arg, priority)
+ eventhandler_register(Xeventhandler_list_ ## name, #name, #func, func, arg, priority)

#define EVENTHANDLER_FAST_DEREGISTER(name, tag) \
eventhandler_deregister(Xeventhandler_list ## name, tag)
@ -121,13 +125,15 @ do { \
for (ep = TAILQ_FIRST(&(_el->el_entries)); \
_ep != NULL; \
_ep = TAILQ_NEXT(_ep, ee_link)) { \
+ if (eventhandler_show_invoked_funcs) \
+ kprintf("INVOKE %s\n", _ep->ee_name); \
((struct eventhandler_entry ## name *)_ep)->eh_func(_ep->ee_arg , ## args); \
} \
} \
} while (0)

#define EVENTHANDLER_REGISTER(name, func, arg, priority) \
- eventhandler_register(NULL, #name, func, arg, priority)
+ eventhandler_register(NULL, #name, #func, func, arg, priority)

#define EVENTHANDLER_DEREGISTER(name, tag) \
do { \
@ -141,6 +147,7 @ do { \
#ifdef _KERNEL
extern eventhandler_tag eventhandler_register(struct eventhandler_list *list,
char *name,
+ const char *fname,
void *func,
void *arg,
int priority);
Index: kern/subr_eventhandler.c ===================================================================
RCS file: /home/source/dragonfly/cvs/src/sys/kern/subr_eventhandler.c,v
retrieving revision 1.5
diff u -p -r1.5 subr_eventhandler.c
-- kern/subr_eventhandler.c 5 Sep 2006 03:48:12 -0000 1.5
+++ kern/subr_eventhandler.c 11 Jul 2007 04:13:07 -0000
@ -35,6 +35,8 @

MALLOC_DEFINE(M_EVENTHANDLER, "eventhandler", "Event handler records");

int eventhandler_show_invoked_funcs = 0;

/* List of 'slow' lists */
static TAILQ_HEAD(, eventhandler_list) eventhandler_lists;
static int eventhandler_lists_initted = 0;
@ -50,8 +52,8 @ struct eventhandler_entry_generic

• if all priorities are identical.
  */
  eventhandler_tag
  eventhandler_register(struct eventhandler_list *list, char *name,
  void *func, void *arg, int priority)
  eventhandler_register(struct eventhandler_list *list, char *name,
  const char *funcname, void *func, void *arg, int priority) {
  struct eventhandler_entry_generic *eg;
  struct eventhandler_entry *ep;
  @ -88,6 +90,7 @ eventhandler_register(struct eventhandle
  eg->func = func;
  eg->ee.ee_arg = arg;
  eg->ee.ee_priority = priority;
  + eg->ee.ee_name = funcname;

/* sort it into the list */
for (ep = TAILQ_FIRST(&list->el_entries);

So it's getting stuck in dashutdown:

Uptime: 1m13s
INVOKE module_shutdown
INVOKE ahd_shutdown
INVOKE ahd_shutdown
INVOKE dashutdown

:So it's getting stuck in dashutdown:
:
:Uptime: 1m13s
:INVOKE module_shutdown
:INVOKE ahd_shutdown
:INVOKE ahd_shutdown
:INVOKE dashutdown

Doh!  A little matter of dashutdown being called after ahd_shutdown
    instead of before!

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>

I've changed the priorities around. Please update to HEAD with the
new sys/eventhandler.h and driver code updates (in particular ahd)
and test again.

-Matt

Good work everyone! Verified that this is fixed.

:Peter Avalos <pavalos@theshell.com> added the comment:
:
:Good work everyone! Verified that this is fixed.
:
:----------
:status: chatting -> resolved

Whew!

-Matt
                    Matthew Dillon 
                    <dillon@backplane.com>