Unable to kill a non-zombie process with -9
Rick Macklem
rmacklem at uoguelph.ca
Fri Oct 31 19:07:02 UTC 2014
elof2 at sentor.se wrote:
>
> No one have any thoughts about this?
>
> Its happening sporadically on several FreeBSD 10 machines of mine,
> while
> all of the FreeBSD 9-machines work just fine.
>
> If the problem isn't fixed, people won't be able to upgrade to and
> run
> snort on FreeBSD 10.
>
> log:
>
> > I'm starting snort (as root).
> >
> > <<<lots of startup logs for pid 22646>>>
> > Oct 15 08:46:59 snort[22646]: Initializing daemon mode
> > Oct 15 08:46:59 snort[22648]: Daemon initialized, signaled parent
> > pid: 22646
> > Oct 15 08:46:59 snort[22648]: Reload thread starting...
> > Oct 15 08:46:59 snort[22648]: Reload thread started, thread
> > 0x8146e8800 (22648)
> > End of log.
> >
> > Error! Nothing more happens with the snort process!
> > Normally it should continue and log the following lines as well:
> >
> >
> > snort[nnn]: Decoding Ethernet
> > snort[nnn]: Checking PID path...
> > snort[nnn]: PID path stat checked out ok, PID path set to /var/run/
> > snort[nnn]: Writing PID "7627" to file "/var/run//snort_mon0.pid"
> > snort[nnn]: Chroot directory = /usr/foobar/log
> > snort[nnn]: Set gid to 100
> > snort[nnn]: Set uid to 100
> > snort[nnn]:
> > snort[nnn]: --== Initialization Complete ==--
> > snort[nnn]: Commencing packet processing (pid=nnn)
> >
> >
> >
> >
> >
> > When looking at this half-started snort process with 'ps', it looks
> > like
> > this:
> >
> > ps faxulwwj 22648
> > USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME
> > COMMAND UID PPID CPU PRI NI MWCHAN PGID SID JOBC
> > root 22648 51.8 1.1 488552 179344 - Rs 8:46AM 53:06.52
> > /usr/local/bin/s 0 1 0 88 0 - 22648 22648 0
> >
> >
> > The process is still owned by root, so just as the missing log
> > lines are
> > saying, it has not yet performed any change of uid/gid.
> >
> >
> >
> >
> > So there seem to be two questions.
> >
> > Q1)
> > What happens between "Reload thread started, thread 0x8146e8800
> > (22648)" and
> > "Decoding Ethernet"?
> > Apparently something goes wrong here on FreeBSD 10.0.
> > (this problem does not always occur, sometimes snort start just
> > fine)
> >
> > Q2)
> > When the process has frozen in this half-started state, it can't be
> > killed
> > even with a -9. Why?
> >
> >
> >
> >
> > John-Mark asked me for some debugging info. Here it is:
> >
> > I now run 'kill 22648' on the above semi-started process:
> >
> > USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME
> > COMMAND UID
> > PPID CPU PRI NI MWCHAN PGID SID JOBC
> > old root 22648 51.8 1.1 488552 179344 - Rs 8:46AM 53:06.52
> > /usr/local/bin/s 0 1 0 88 0 - 22648 22648 0
> > new root 22648 52.3 1.1 488552 179344 - Rs 8:46AM 53:36.48
> > /usr/local/bin/s 0 1 0 52 0 - 22648 22648 0
> >
> > No change.
> >
> >
> >
> > kill -9 22648
> >
> > USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME
> > COMMAND UID
> > PPID CPU PRI NI MWCHAN PGID SID JOBC
> > old root 22648 51.8 1.1 488552 179344 - Rs 8:46AM 53:06.52
> > /usr/local/bin/s 0 1 0 88 0 - 22648 22648 0
> > new root 22648 37.7 1.1 488552 179344 - Ts 8:46AM 53:50.87
> > /usr/local/bin/s 0 1 0 52 0 - 22648 22648 0
> >
> > Less CPU-usage and STAT changed to "Ts".
> >
> >
> >
> >
> > kill -CONT 22648
> >
> > USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME
> > COMMAND UID
> > PPID CPU PRI NI MWCHAN PGID SID JOBC
> > old root 22648 51.8 1.1 488552 179344 - Rs 8:46AM 53:06.52
> > /usr/local/bin/s 0 1 0 88 0 - 22648 22648 0
> > new root 22648 0.0 1.1 488552 179344 - Ts 8:46AM 53:50.88
> > /usr/local/bin/s 0 1 0 52 0 - 22648 22648 0
> >
> > No change except cpu is down to 0.
> >
> >
> > I now start 'kgdb'
> > info threads
> > I found two threads for snort, doing a bt for both of them:
> > 372 Thread 100602 (PID=22648: snort) sched_switch
> > (td=0xfffff802c061f490,
> > newtd=<value optimized out>, flags=<value optimized out>) at
> > /usr/src/sys/kern/sched_ule.c:1962
> > 371 Thread 100598 (PID=22648: snort) sched_switch
> > (td=0xfffff80221857000,
> > newtd=<value optimized out>, flags=<value optimized out>) at
> > /usr/src/sys/kern/sched_ule.c:1962
> > thread 372
> > [Switching to thread 372 (Thread 100602)]#0 sched_switch
> > (td=0xfffff802c061f490, newtd=<value optimized out>, flags=<value
> > optimized
> > out>) at /usr/src/sys/kern/sched_ule.c:1962
> > 1962 in /usr/src/sys/kern/sched_ule.c
> > bt
> > #0 sched_switch (td=0xfffff802c061f490, newtd=<value optimized
> > out>,
> > flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1962
> > #1 0xffffffff808b8c1e in mi_switch (flags=266, newtd=0x0) at
> > /usr/src/sys/kern/kern_synch.c:494
> > #2 0xffffffff808c04b0 in thread_suspend_switch
> > (td=0xfffff802c061f490) at
> > /usr/src/sys/kern/kern_thread.c:883
> > #3 0xffffffff808c0276 in thread_single (mode=1) at
> > /usr/src/sys/kern/kern_thread.c:713
> > #4 0xffffffff8087c1bb in exit1 (td=0xfffff802c061f490, rv=9) at
> > /usr/src/sys/kern/kern_exit.c:180
> > #5 0xffffffff808b2faf in sigexit (td=<value optimized out>,
> > sig=<value
> > optimized out>) at /usr/src/sys/kern/kern_sig.c:2935
> > #6 0xffffffff808b3669 in postsig (sig=<value optimized out>) at
> > /usr/src/sys/kern/kern_sig.c:2822
> > #7 0xffffffff808f6f57 in ast (framep=<value optimized out>) at
> > /usr/src/sys/kern/subr_trap.c:271
> > #8 0xffffffff80c75870 in Xfast_syscall () at
> > /usr/src/sys/amd64/amd64/exception.S:416
> > #9 0x0000000801d6f19a in ?? ()
> > Previous frame inner to this frame (corrupt stack?)
> >
> >
> > thread 371
> > [Switching to thread 371 (Thread 100598)]#0 sched_switch
> > (td=0xfffff80221857000, newtd=<value optimized out>, flags=<value
> > optimized
> > out>) at /usr/src/sys/kern/sched_ule.c:1962
> > 1962 in /usr/src/sys/kern/sched_ule.c
> > bt
> > #0 sched_switch (td=0xfffff80221857000, newtd=<value optimized
> > out>,
> > flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1962
> > #1 0xffffffff808b8c1e in mi_switch (flags=260, newtd=0x0) at
> > /usr/src/sys/kern/kern_synch.c:494
> > #2 0xffffffff808f2e3a in sleepq_wait (wchan=0x0, pri=0) at
> > /usr/src/sys/kern/subr_sleepqueue.c:620
> > #3 0xffffffff80864aad in _cv_wait (cvp=0xffffffff8147a500,
> > lock=0xffffffff8147a480) at /usr/src/sys/kern/kern_condvar.c:139
> > #4 0xffffffff808fb05f in vmem_xalloc (vm=0xffffffff8147a480,
> > size0=<value
> > optimized out>, align=<value optimized out>, phase=0,
> > nocross=<value
> > optimized out>, minaddr=0, maxaddr=18446735286768857088,
> > flags=8194,
> > addrp=<value optimized out>) at /usr/src/sys/kern/subr_vmem.c:1196
> > #5 0xffffffff808fae6b in vmem_alloc (vm=0x0, size=0, flags=<value
> > optimized
> > out>, addrp=0xfffffe0466e1d6e8) at
> > /usr/src/sys/kern/subr_vmem.c:1082
This looks vaguely similar to what I get when I run the system out of
boundary tags. (I say "vaguely similar" because you haven't run out of
boundary tags, but you may have vmem_xalloc() failing.)
When these functions are called with M_NOWAIT, they return failure and
a higher level call in the allocation call stack retries it. Then it
loops in the kernel in "R" state, which is why it isn't killable.
For my case, I believe it happens when the kernel address space gets too
fragmented. Also, alc@ recently fixed a problem for low kernel
memory cases. I've cc'd him in case he may be able to help?
Btw Alan, I was never able to reproduce the M_WAITOK case although my
kernel was older than the patch you discussed. I can fairly easily
reproduce the M_NOWAIT case, but haven't tried with a recent kernel yet.
I have no idea if increasing vm.kmem_size_max might help?
rick
> > #6 0xffffffff80b0fa58 in kmem_malloc (vmem=0xffffffff8147a480,
> > size=2139729920, flags=2) at /usr/src/sys/vm/vm_kern.c:314
> > #7 0xffffffff80b08dfb in uma_large_malloc (size=<value optimized
> > out>,
> > wait=2) at /usr/src/sys/vm/uma_core.c:1006
> > #8 0xffffffff80898cf3 in malloc (size=2139729920,
> > mtp=0xffffffff813a0450,
> > flags=0) at /usr/src/sys/kern/kern_malloc.c:520
> > #9 0xffffffff8096307b in bpf_buffer_ioctl_sblen
> > (d=0xfffff80159ea9000,
> > i=<value optimized out>) at /usr/src/sys/net/bpf_buffer.c:183
> > #10 0xffffffff80960a3c in bpfioctl (dev=0x0, cmd=<value optimized
> > out>,
> > addr=0xfffff801fbd06b40 "", flags=0, td=0xfffff80221857000) at
> > /usr/src/sys/net/bpf.c:408
> > #11 0xffffffff807ac1df in devfs_ioctl_f (fp=0xfffff8002b3d9d20,
> > com=3221504614, data=0xfffff801fbd06b40, cred=<value optimized
> > out>,
> > td=0xfffff80221857000) at /usr/src/sys/fs/devfs/devfs_vnops.c:757
> > #12 0xffffffff808fdfae in kern_ioctl (td=0xfffff80221857000,
> > fd=<value
> > optimized out>, com=0) at file.h:319
> > #13 0xffffffff808fdd2f in sys_ioctl (td=0xfffff80221857000,
> > uap=0xfffffe0466e1da40) at /usr/src/sys/kern/sys_generic.c:702
> > #14 0xffffffff80c8f117 in amd64_syscall (td=0xfffff80221857000,
> > traced=0) at
> > subr_syscall.c:134
> > #15 0xffffffff80c7580b in Xfast_syscall () at
> > /usr/src/sys/amd64/amd64/exception.S:391
> > #16 0x0000000801d8f08a in ?? ()
> > Previous frame inner to this frame (corrupt stack?)
> >
> >
> > Let me know if I can debug this any further.
> >
> > /Elof
> >
> >
> >
> > On Thu, 9 Oct 2014, John-Mark Gurney wrote:
> >
> >> elof2 at sentor.se wrote this message on Wed, Oct 08, 2014 at 13:30
> >> +0200:
> >>>
> >>> I guess this is a bug report for FreeBSD 10.0.
> >>>
> >>>
> >>>
> >>> Sometimes I can't kill my snort process on FreeBSD 10.0.
> >>> It won't die, even with kill -9.
> >>>
> >>> I'm not talking about a zombie process. Snort is a process that
> >>> should
> >>> die normally.
> >>> I've run snort on over 100 nodes since FreeBSD v6.x and I've
> >>> never seen
> >>> this behavior until now in FreeBSD 10.0.
> >>>
> >>>
> >>> Example:
> >>>
> >>> #ps faxuw
> >>> USER PID %CPU %MEM VSZ RSS TT STAT STARTED
> >>> TIME
> >>> COMMAND
> >>> root 49222 53.4 2.2 492648 183012 - Rs 11:46AM
> >>> 7:05.59
> >>> /usr/local/bin/snort -q -D -c snort.conf
> >>> root 47937 0.0 2.2 488552 182864 - Ts 10:56AM
> >>> 29:35.98
> >>> /usr/local/bin/snort -q -D -c snort.conf
> >>
> >> What is the MWCHAN? add l to the ps command...
> >>
> >>> The pid 47937 has been killed (repeatedly) with -9.
> >>> Its status is "Ts" meaning it is Stopped.
> >>
> >> have you tried to kill -CONT <pid> to resume it?
> >>
> >>> But it won't actually die and disappear. The only way to get rid
> >>> of it
> >>> seem to be to reboot the machine. :-(
> >>>
> >>> (pid 49222 is the new process that was started after 47937 was
> >>> killed)
> >>>
> >>>
> >>> The problem doesn't happen all the time and I haven't found any
> >>> patterns
> >>> as to when it does. :-(
> >>> If I restart snort once every day, it fails to die approximately
> >>> 2-4 times
> >>> per month.
> >>> Even though the problem doesn't happen on every kill, it is a
> >>> definately a
> >>> recurring event.
> >>
> >> Can you run kgdb on the machine? (yes, it works on a live
> >> machine), use
> >> info threads to find the thread id, and then use thread <threadid>
> >> to
> >> switch to it, and run bt to get a back trace...
> >>
> >>> I began to see it on a heavily loaded 10GE sensor, so I thought
> >>> it could
> >>> have something to do with the ix driver, or the heavy load.
> >>> But now another FreeBSD 10.0-sensor had the exact same problem,
> >>> and this
> >>> sensor don't have any 10GE NICs. In fact, this sensor has been
> >>> running
> >>> just fine with both FreeBSD 9.1 and 9.3 for the past years. Snort
> >>> has
> >>> always terminated correctly! After I reinstalled this machine
> >>> with FreeBSD
> >>> 10.0 last friday, snort has then terminated correctly every day
> >>> until
> >>> today, when it failed with the above pid 47937. (this sensor use
> >>> the 'em'
> >>> driver, not 'ixgbe')
> >>>
> >>> I'm running snort with the same configuration, settings, version,
> >>> daq,
> >>> libs, etc on 10.0 as I do on 9.3.
> >>> None of the 9.3 sensors have this problem, so it has to be
> >>> something new
> >>> in FreeBSD 10.0.
> >>
> >> --
> >> John-Mark Gurney Voice: +1 415 225 5579
> >>
> >> "All that I will do, has been done, All that I have, has not."
> >>
> > _______________________________________________
> > freebsd-net at freebsd.org mailing list
> > http://lists.freebsd.org/mailman/listinfo/freebsd-net
> > To unsubscribe, send any mail to
> > "freebsd-net-unsubscribe at freebsd.org"
> >
> _______________________________________________
> freebsd-net at freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-net
> To unsubscribe, send any mail to
> "freebsd-net-unsubscribe at freebsd.org"
>
More information about the freebsd-net
mailing list