Bug 1127000 - qemu smb share leaves a lot of zombies
qemu smb share leaves a lot of zombies
Status: RESOLVED INVALID
Classification: openSUSE
Product: openSUSE Tumbleweed
Classification: openSUSE
Component: Virtualization:Other
Current
Other Other
: P5 - None : Normal (vote)
: ---
Assigned To: David Mulder
E-mail List
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2019-02-26 11:29 UTC by Jiri Slaby
Modified: 2022-03-30 13:20 UTC (History)
3 users (show)

See Also:
Found By: ---
Services Priority:
Business Priority:
Blocker: ---
Marketing QA Status: ---
IT Deployment: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Jiri Slaby 2019-02-26 11:29:23 UTC
With this commandline:
/usr/bin/qemu-system-x86_64 -machine accel=kvm -k en-us -smp 4 -daemonize -pidfile /tmp/qemu.pid.30512 -device virtio-rng-pci -device ich9-usb-ehci1,multifunction=on,id=ehci -device ich9-usb-uhci1,masterbus=ehci.0,multifunction=on -device ich9-usb-uhci2,masterbus=ehci.0,firstport=2,multifunction=on -device ich9-usb-uhci3,masterbus=ehci.0,firstport=4,multifunction=on -drive file=/home/new/win.qcow2,discard=unmap -soundhw ac97 -spice disable-ticketing,gl=on,unix,addr=/tmp/qemu-spice.30512.sock -device virtio-serial -chardev spicevmc,id=vdagent,name=vdagent -device virtserialport,chardev=vdagent,name=com.redhat.spice.0 -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1 -chardev spicevmc,name=usbredir,id=usbredirchardev2 -device usb-redir,chardev=usbredirchardev2,id=usbredirdev2 -net user,smb=/home/smb,hostfwd=tcp::3389-:3389 -net nic,model=rtl8139 -rtc base=localtime -vga qxl -device usb-tablet -m 1G

After some time running, I see a lot of smbd zombie processes:
> xslaby   30546  2.4  7.4 2572952 1213920 ?     Tl   úno24  60:58 /usr/bin/qemu-system-x86_64 -machine accel=kvm -k en-us -smp 4 -daemonize -pidfile /tmp/qemu.pid.30512 -device virtio-rng-pci -device ich9-usb-ehci1,multifunction=on,id=ehci -device ich9-usb-uhci1,masterbus=ehci.0,multifunction=on -device ich9-usb-uhci2,masterbus=ehci.0,firstport=2,multifunction=on -device ich9-usb-uhci3,masterbus=ehci.0,firstport=4,multifunction=on -drive file=/home/new/win.qcow2,discard=unmap -soundhw ac97 -spice disable-ticketing,gl=on,unix,addr=/tmp/qemu-spice.30512.sock -device virtio-serial -chardev spicevmc,id=vdagent,name=vdagent -device virtserialport,chardev=vdagent,name=com.redhat.spice.0 -chardev spicevmc,name=usbredir,id=usbredirchardev1 -device usb-redir,chardev=usbredirchardev1,id=usbredirdev1 -chardev spicevmc,name=usbredir,id=usbredirchardev2 -device usb-redir,chardev=usbredirchardev2,id=usbredirdev2 -net user,smb=/home/smb,hostfwd=tcp::3389-:3389 -net nic,model=rtl8139 -rtc base=localtime -vga qxl -device usb-tablet -m 1G
> xslaby   30600  0.0  0.1  49892 20088 ?        Ss   úno24   0:01  \_ /usr/sbin/smbd -l /tmp/qemu-smb.ZIY0XZ -s /tmp/qemu-smb.ZIY0XZ/smb.conf
> xslaby   30602  0.0  0.0  45440  4892 ?        S    úno24   0:00      \_ /usr/sbin/smbd -l /tmp/qemu-smb.ZIY0XZ -s /tmp/qemu-smb.ZIY0XZ/smb.conf
> xslaby   30603  0.0  0.0  45432  3328 ?        S    úno24   0:00      \_ /usr/sbin/smbd -l /tmp/qemu-smb.ZIY0XZ -s /tmp/qemu-smb.ZIY0XZ/smb.conf
> xslaby   32070  0.0  0.0      0     0 ?        Z    úno24   0:00      \_ [smbd] <defunct>
> xslaby    1184  0.0  0.0      0     0 ?        Z    úno24   0:00      \_ [smbd] <defunct>
> xslaby    2708  0.0  0.0      0     0 ?        Z    úno24   0:00      \_ [smbd] <defunct>
> xslaby    2902  0.0  0.0      0     0 ?        Z    úno24   0:00      \_ [smbd] <defunct>
> xslaby    3834  0.0  0.0      0     0 ?        Z    úno24   0:00      \_ [smbd] <defunct>
> xslaby    4514  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    7508  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    9429  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   10975  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   12896  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   14454  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   16387  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   18100  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   19775  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   21479  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   31399  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    2457  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    4636  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    6490  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    8795  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   10394  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   12068  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   13606  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   15829  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   17444  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   19211  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   20870  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   22653  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   25946  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   27950  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   29908  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   31403  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby     378  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    1887  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    3610  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    5101  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    6557  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    8027  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    9534  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   10978  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   12442  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   13894  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   15346  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   16831  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   18284  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   19741  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   21197  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   22659  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   24110  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   25926  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   27476  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   29449  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   30944  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   32378  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    1418  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    2914  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    5694  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    7345  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby    8838  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   10286  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   11743  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   13175  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   14215  0.0  0.0      0     0 ?        Z    úno25   0:00      \_ [smbd] <defunct>
> xslaby   15492  0.0  0.0      0     0 ?        Z    06:38   0:00      \_ [smbd] <defunct>
> xslaby   18349  0.0  0.0      0     0 ?        Z    06:53   0:00      \_ [smbd] <defunct>
> xslaby   20043  0.0  0.0      0     0 ?        Z    07:08   0:00      \_ [smbd] <defunct>
> xslaby   21654  0.0  0.0      0     0 ?        Z    07:23   0:00      \_ [smbd] <defunct>
> xslaby   23364  0.0  0.0      0     0 ?        Z    07:38   0:00      \_ [smbd] <defunct>
> xslaby   24473  0.0  0.0      0     0 ?        Z    07:53   0:00      \_ [smbd] <defunct>
> xslaby   26134  0.0  0.0      0     0 ?        Z    08:08   0:00      \_ [smbd] <defunct>
> xslaby   27373  0.0  0.0      0     0 ?        Z    08:23   0:00      \_ [smbd] <defunct>
> xslaby   28757  0.0  0.0      0     0 ?        Z    08:38   0:00      \_ [smbd] <defunct>
> xslaby   29947  0.0  0.0      0     0 ?        Z    08:53   0:00      \_ [smbd] <defunct>
> xslaby   31154  0.0  0.0      0     0 ?        Z    09:08   0:00      \_ [smbd] <defunct>
> xslaby   32462  0.0  0.0      0     0 ?        Z    09:23   0:00      \_ [smbd] <defunct>
> xslaby    1347  0.0  0.0      0     0 ?        Z    09:38   0:00      \_ [smbd] <defunct>
> xslaby    2581  0.0  0.0      0     0 ?        Z    09:53   0:00      \_ [smbd] <defunct>
> xslaby    4173  0.0  0.0      0     0 ?        Z    10:08   0:00      \_ [smbd] <defunct>
> xslaby    5370  0.0  0.0      0     0 ?        Z    10:23   0:00      \_ [smbd] <defunct>
> xslaby    6652  0.0  0.0      0     0 ?        Z    10:38   0:00      \_ [smbd] <defunct>
> xslaby    7813  0.0  0.0      0     0 ?        Z    10:53   0:00      \_ [smbd] <defunct>
> xslaby    9252  0.0  0.0      0     0 ?        Z    11:08   0:00      \_ [smbd] <defunct>
> xslaby   10823  0.0  0.0      0     0 ?        Z    11:23   0:00      \_ [smbd] <defunct>
> xslaby   12232  0.0  0.0      0     0 ?        Z    11:38   0:00      \_ [smbd] <defunct>
> xslaby   13917  0.0  0.0      0     0 ?        Z    11:53   0:00      \_ [smbd] <defunct>
> xslaby   16442  0.0  0.0      0     0 ?        Z    12:08   0:00      \_ [smbd] <defunct>
> xslaby   18652  0.0  0.0      0     0 ?        Z    12:23   0:00      \_ [smbd] <defunct>


They should be reaped when new one starts, IMO.

I am using
$ qemu-kvm --version
QEMU emulator version 3.1.0

from the Virtualization project. But it does not matter, it happens for a long time.
Comment 1 Bruce Rogers 2019-02-27 22:23:21 UTC
I see this as well, using your example. I'll try to figure out what's going on.
Comment 2 Bruce Rogers 2019-02-28 17:34:28 UTC
What I am seeing is that the parent of the zombied smbd processes is smbd. As I understand it, the parent is the at fault when a child gets left in a zombie state. I'm adding David Mulder, samba engineer, to see what perspective he might have on this.

I'll continue to try to do more investigations.

Since I assumed that non-root usage of smbd is quite a bit less common, I guessed that I might not see this issue if I did the test as root, but I still see these defunct processes when running qemu (and subsequently the spawned smbd process) as root, so I'm dropping that line of investigation.

I was watching on pstree to see what was happening and here's what I've seen:
...
... ├─qemu-system-x86(18633)─┬─smbd(19726)─┬─cleanupd(19729)
... │                        │             ├─smbd(19931)
... │                        │             └─smbd-notifyd(19728)

The 19931 process then, after some time becomes zombied.

I've not investigated this much further but it seems that normally there isn't a smbd child of smbd parent, So this may indicate something has gone wrong within smbd in our case.
Comment 3 Bruce Rogers 2019-02-28 18:28:10 UTC
David, for additional context, here hs what the config file looks like, which is referenced on the smbd commmand line (as you see in Jiri's initial comment's ps dump)
[global]
private dir=/tmp/qemu-smb.NZ21XZ
interfaces=127.0.0.1
bind interfaces only=yes
pid directory=/tmp/qemu-smb.NZ21XZ
lock directory=/tmp/qemu-smb.NZ21XZ
state directory=/tmp/qemu-smb.NZ21XZ
cache directory=/tmp/qemu-smb.NZ21XZ
ncalrpc dir=/tmp/qemu-smb.NZ21XZ/ncalrpc
log file=/tmp/qemu-smb.NZ21XZ/log.smbd
smb passwd file=/tmp/qemu-smb.NZ21XZ/smbpasswd
security = user
map to guest = Bad User
load printers = no
printing = bsd
disable spoolss = yes
usershare max shares = 0
[qemu]
path=/tmp/smb
read only=no
guest ok=yes
force user=brogers
Comment 4 Jiri Slaby 2019-03-01 06:27:46 UTC
(In reply to Bruce Rogers from comment #2)
> What I am seeing is that the parent of the zombied smbd processes is smbd.

Agreed, my post acknowledges that too:

(In reply to Jiri Slaby from comment #0)
> > xslaby   30600  0.0  0.1  49892 20088 ?        Ss   úno24   0:01  \_ /usr/sbin/smbd -l /tmp/qemu-smb.ZIY0XZ -s /tmp/qemu-smb.ZIY0XZ/smb.conf
> > xslaby   30602  0.0  0.0  45440  4892 ?        S    úno24   0:00      \_ /usr/sbin/smbd -l /tmp/qemu-smb.ZIY0XZ -s /tmp/qemu-smb.ZIY0XZ/smb.conf
> > xslaby   30603  0.0  0.0  45432  3328 ?        S    úno24   0:00      \_ /usr/sbin/smbd -l /tmp/qemu-smb.ZIY0XZ -s /tmp/qemu-smb.ZIY0XZ/smb.conf
> > xslaby   32070  0.0  0.0      0     0 ?        Z    úno24   0:00      \_ [smbd] <defunct>

32070 zombie's parent is 30600 -- /usr/sbin/smbd
Comment 5 Jiri Slaby 2019-03-01 07:32:55 UTC
I added log level=10 to the smb.conf file, sent HUP to smbd and this happened when a new zombie appeared:
> xslaby   22053  0.0  0.0      0     0 ?        Z    08:29   0:00      \_ [smbd] <defunct>


> [2019/03/01 08:27:41.975369, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:43(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(deadtime) (nil) called
> [2019/03/01 08:27:41.975580, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:54(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled
> [2019/03/01 08:27:41.975732, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:43(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(housekeeping) (nil) called
> [2019/03/01 08:27:41.975885,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/process.c:2898(housekeeping_fn)
>   housekeeping
> [2019/03/01 08:27:41.976026,  4, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal)
>   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2019/03/01 08:27:41.976197,  5, pid=30600, effective(500, 500), real(500, 500)] ../libcli/security/security_token.c:53(security_token_debug)
>   Security token: (NULL)
> [2019/03/01 08:27:41.976333,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/auth/token_util.c:850(debug_unix_user_token)
>   UNIX token of user 0
>   Primary group is 0 and contains 0 supplementary groups
> [2019/03/01 08:27:41.976560,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/uid.c:455(smbd_change_to_root_user)
>   change_to_root_user: now uid=(500,500) gid=(500,500)
> [2019/03/01 08:27:41.976758, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:54(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled
> [2019/03/01 08:28:42.035532, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:43(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(deadtime) (nil) called
> [2019/03/01 08:28:42.035742, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:54(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled
> [2019/03/01 08:28:42.035898, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:43(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(housekeeping) (nil) called
> [2019/03/01 08:28:42.036084,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/process.c:2898(housekeeping_fn)
>   housekeeping
> [2019/03/01 08:28:42.036318,  4, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal)
>   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2019/03/01 08:28:42.036475,  5, pid=30600, effective(500, 500), real(500, 500)] ../libcli/security/security_token.c:53(security_token_debug)
>   Security token: (NULL)
> [2019/03/01 08:28:42.036618,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/auth/token_util.c:850(debug_unix_user_token)
>   UNIX token of user 0
>   Primary group is 0 and contains 0 supplementary groups
> [2019/03/01 08:28:42.036853,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/uid.c:455(smbd_change_to_root_user)
>   change_to_root_user: now uid=(500,500) gid=(500,500)
> [2019/03/01 08:28:42.037050, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:54(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled
> [2019/03/01 08:29:38.817934, 10, pid=22053, effective(500, 500), real(500, 500)] ../source3/lib/messages_dgm_ref.c:175(msg_dgm_ref_destructor)
>   msg_dgm_ref_destructor: refs=(nil)
> [2019/03/01 08:29:38.819135, 10, pid=22053, effective(500, 500), real(500, 500)] ../source3/lib/messages_dgm_ref.c:92(messaging_dgm_ref)
>   messaging_dgm_ref: messaging_dgm_init returned Úspěch
> [2019/03/01 08:29:38.819359, 10, pid=22053, effective(500, 500), real(500, 500)] ../source3/lib/messages_dgm_ref.c:121(messaging_dgm_ref)
>   messaging_dgm_ref: unique = 9155697459312363793
> [2019/03/01 08:29:38.819605, 10, pid=22053, effective(500, 500), real(500, 500)] ../source3/lib/messages_dgm.c:1586(messaging_dgm_wipe_fn)
>   messaging_dgm_cleanup(30600) returned Prostředek je dočasně nepřístupný
> [2019/03/01 08:29:38.819742, 10, pid=22053, effective(500, 500), real(500, 500)] ../source3/lib/messages_dgm.c:1586(messaging_dgm_wipe_fn)
>   messaging_dgm_cleanup(30602) returned Prostředek je dočasně nepřístupný
> [2019/03/01 08:29:38.819866, 10, pid=22053, effective(500, 500), real(500, 500)] ../source3/lib/messages_dgm.c:1586(messaging_dgm_wipe_fn)
>   messaging_dgm_cleanup(30603) returned Prostředek je dočasně nepřístupný
> [2019/03/01 08:29:38.819964, 10, pid=22053, effective(500, 500), real(500, 500)] ../source3/lib/messages.c:1441(mess_parent_dgm_cleanup)
>   messaging_dgm_wipe returned ok
> [2019/03/01 08:29:38.820149, 10, pid=22053, effective(500, 500), real(500, 500)] ../source3/lib/messages_dgm_ref.c:175(msg_dgm_ref_destructor)
>   msg_dgm_ref_destructor: refs=(nil)
> [2019/03/01 08:29:39.062676, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:43(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(keepalive) (nil) called
> [2019/03/01 08:29:39.063132, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:54(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(keepalive) (nil) rescheduled
> [2019/03/01 08:29:42.039432, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:43(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(deadtime) (nil) called
> [2019/03/01 08:29:42.039653, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:54(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled
> [2019/03/01 08:29:42.039799, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:43(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(housekeeping) (nil) called
> [2019/03/01 08:29:42.039965,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/process.c:2898(housekeeping_fn)
>   housekeeping
> [2019/03/01 08:29:42.040136,  4, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal)
>   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2019/03/01 08:29:42.040321,  5, pid=30600, effective(500, 500), real(500, 500)] ../libcli/security/security_token.c:53(security_token_debug)
>   Security token: (NULL)
> [2019/03/01 08:29:42.040461,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/auth/token_util.c:850(debug_unix_user_token)
>   UNIX token of user 0
>   Primary group is 0 and contains 0 supplementary groups
> [2019/03/01 08:29:42.040774,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/uid.c:455(smbd_change_to_root_user)
>   change_to_root_user: now uid=(500,500) gid=(500,500)
> [2019/03/01 08:29:42.041164,  6, pid=30600, effective(500, 500), real(500, 500)] ../source3/param/loadparm.c:2336(lp_file_list_changed)
>   lp_file_list_changed()
>   file /tmp/qemu-smb.ZIY0XZ/smb.conf -> /tmp/qemu-smb.ZIY0XZ/smb.conf  last mod_time: Fri Mar  1 08:26:57 2019
>   
> [2019/03/01 08:29:42.041492, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:54(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled
> [2019/03/01 08:30:42.095497, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:43(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(deadtime) (nil) called
> [2019/03/01 08:30:42.095783, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:54(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(deadtime) (nil) rescheduled
> [2019/03/01 08:30:42.095988, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:43(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(housekeeping) (nil) called
> [2019/03/01 08:30:42.096174,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/process.c:2898(housekeeping_fn)
>   housekeeping
> [2019/03/01 08:30:42.096324,  4, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/sec_ctx.c:320(set_sec_ctx_internal)
>   setting sec ctx (0, 0) - sec_ctx_stack_ndx = 0
> [2019/03/01 08:30:42.096478,  5, pid=30600, effective(500, 500), real(500, 500)] ../libcli/security/security_token.c:53(security_token_debug)
>   Security token: (NULL)
> [2019/03/01 08:30:42.096630,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/auth/token_util.c:850(debug_unix_user_token)
>   UNIX token of user 0
>   Primary group is 0 and contains 0 supplementary groups
> [2019/03/01 08:30:42.096855,  5, pid=30600, effective(500, 500), real(500, 500)] ../source3/smbd/uid.c:455(smbd_change_to_root_user)
>   change_to_root_user: now uid=(500,500) gid=(500,500)
> [2019/03/01 08:30:42.097039, 10, pid=30600, effective(500, 500), real(500, 500)] ../source3/lib/util_event.c:54(smbd_idle_event_handler)
>   smbd_idle_event_handler: idle_evt(housekeeping) (nil) rescheduled
>
Comment 6 Bruce Rogers 2019-03-11 14:33:08 UTC
Dave, I'm going to reassign to you, since as I understand it, it would be be smbd itself which would be at fault here.
Comment 7 Jiri Slaby 2019-07-18 04:45:04 UTC
Any updates to this? It still happens...
Comment 8 David Mulder 2019-07-18 16:10:34 UTC
Always assign samba bugs to samba-maintainers@suse.de. I never even saw this bug (as evidenced by the lack of response).
Comment 9 David Mulder 2019-07-18 16:22:38 UTC
Here's another report of the same issue:
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=236715
Comment 10 David Mulder 2019-07-18 16:25:33 UTC
Here's another report:
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=816725

Seems this has been a problem for a long time.
Comment 11 David Mulder 2019-07-18 16:26:41 UTC
And here's an open samba bug on the issue:
https://bugzilla.samba.org/show_bug.cgi?id=13887
Comment 12 David Mulder 2022-03-30 13:20:55 UTC
This is not a samba bug, but a qemu bug: https://gitlab.freedesktop.org/slirp/libslirp/-/merge_requests/61