PANIC: vfs_fruit for time machine backup causes PANIC

[Anoop C S]

On Sun, 2020-04-12 at 11:24 +0200, Rouven WEILER via samba-technical
wrote:
> In a previous email I mentioned that I got issue with samba 4.12.1 on
> Illumos/OpenIndiana and MacOS 10.15.4.
> I digged a little bit more and found out that the PANIC is caused
> when trying to do a time machine backup.
> 
> Plain samba works a as always. There seems to be only issues with
> time machine backup.
> 
> Everything worked before samba-4.12.0 and MacOS 10.15.4. I cannot
> tell which change cause the issues...
> 
> Staring from a new time capsule share I got the following:
> Creating a new time machine backup shows, I get a
> „.com.apple.timemachine.supported“ file added in to the share.
> 
> MacOS tells in it’s logs: „Failed to read capabilities for
> 'file:///Volumes/FileVault/', error: Socket is not connected“.
> 
> The smbd.log with loglevel vfs:10 shows:

Is it possible for you to reproduce with log level 10 set in general
rather than just vfs? It might gives us more context around the
assertion failure leading to smbd panic.

> [2020/04/12 11:15:21.534742,  5, pid=1707, effective(500, 500),
> real(0, 0), class=vfs]
> ../../source3/smbd/vfs.c:1395(check_reduced_name)
>   check_reduced_name: .com.apple.timemachine.supported reduced to
> /export/home/timecapsule/.com.apple.timemachine.supported
> [2020/04/12 11:15:21.534789, 10, pid=1707, effective(500, 500),
> real(0, 0), class=vfs]
> ../../source3/modules/vfs_streams_xattr.c:379(streams_xattr_open)
>   streams_xattr_open called for .com.apple.timemachine.supported with
> flags 0x20080
> [2020/04/12 11:15:21.535160,  0]
> ../../lib/dbwrap/dbwrap.c:82(dbwrap_record_get_value)
>   PANIC: assert failed at ../../lib/dbwrap/dbwrap.c(82): rec-
> >value_valid

Similar assertion failures were fixed sometime back and I could see
those present in v4-12-stable branch. May be we missed some other
place..

> [2020/04/12 11:15:21.535322,  0]
> ../../source3/lib/util.c:830(smb_panic_s3)
>   PANIC (pid 1707): assert failed: rec->value_valid
> [2020/04/12 11:15:21.536138,  0]
> ../../lib/util/fault.c:265(log_stack_trace)
>   BACKTRACE: 37 stack frames:
>    #0 /usr/lib/samba/amd64/libsamba-
> util.so.0.0.1'log_stack_trace+0x26 [0xfffffd7fee51de66]
>    #1 /usr/lib/samba/amd64/libsmbconf.so.0'smb_panic_s3+0x26
> [0xfffffd7fedf5a596]
>    #2 /usr/lib/samba/amd64/libsamba-util.so.0.0.1'smb_panic+0x1f
> [0xfffffd7fee51df3f]
>    #3 /usr/lib/samba/private/amd64/libdbwrap-
> samba4.so'dbwrap_record_get_value+0x2a [0xfffffd7fece2627a]
>    #4 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'get_share_mode_lock+0x109 [0xfffffd7fee7195c9]
>    #5 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'smbd_contend_level2_oplocks_begin+0xa1 [0xfffffd7fee7f7761]
>    #6 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'brl_lock+0x635 [0xfffffd7fee710f45]
>    #7 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'do_lock_fn+0xa4 [0xfffffd7fee70d534]
>    #8 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'share_mode_do_locked_fn+0x86 [0xfffffd7fee7174b6]
>    #9
> /usr/lib/samba/amd64/libsmbconf.so.0'dbwrap_watched_do_locked_fn+0xfa
> [0xfffffd7fedf622ca]
>    #10 /usr/lib/samba/private/amd64/libdbwrap-
> samba4.so'db_tdb_do_locked+0x12f [0xfffffd7fece295cf]
>    #11 /usr/lib/samba/private/amd64/libdbwrap-
> samba4.so'dbwrap_do_locked+0x48 [0xfffffd7fece269a8]
>    #12
> /usr/lib/samba/amd64/libsmbconf.so.0'dbwrap_watched_do_locked+0x6f
> [0xfffffd7fedf60d7f]
>    #13 /usr/lib/samba/private/amd64/libdbwrap-
> samba4.so'dbwrap_do_locked+0x48 [0xfffffd7fece269a8]
>    #14 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'share_mode_do_locked+0xd2 [0xfffffd7fee719b82]
>    #15 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'do_lock+0xf0 [0xfffffd7fee70dfe0]
>    #16 /usr/lib/samba/amd64/vfs/fruit.so'fruit_create_file+0x7ba
> [0xfffffd7fe88a55aa]
>    #17 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'smbd_smb2_request_process_create+0xa07 [0xfffffd7fee7d3237]
>    #18 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'smbd_smb2_request_dispatch+0xc8f [0xfffffd7fee7c985f]
>    #19 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'smbd_smb2_connection_handler+0x621 [0xfffffd7fee7ca7e1]
>    #20
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'tevent_common_invoke
> _fd_handler+0x80 [0xfffffd7fecfca580]
>    #21
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'epoll_event_loop_onc
> e+0x22c [0xfffffd7fecfd180c]
>    #22
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'std_event_loop_once+
> 0x40 [0xfffffd7fecfcf8f0]
>    #23
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'_tevent_loop_once+0x
> 95 [0xfffffd7fecfc9bd5]
>    #24
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'tevent_common_loop_w
> ait+0x23 [0xfffffd7fecfc9e43]
>    #25
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'std_event_loop_wait+
> 0x40 [0xfffffd7fecfcf870]
>    #26 /usr/lib/samba/private/amd64/libsmbd-base-
> samba4.so'smbd_process+0x777 [0xfffffd7fee7b8677]
>    #27 /usr/lib/samba/sbin/amd64/smbd'smbd_accept_connection+0x189
> [0x40d5b9]
>    #28
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'tevent_common_invoke
> _fd_handler+0x80 [0xfffffd7fecfca580]
>    #29
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'epoll_event_loop_onc
> e+0x22c [0xfffffd7fecfd180c]
>    #30
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'std_event_loop_once+
> 0x40 [0xfffffd7fecfcf8f0]
>    #31
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'_tevent_loop_once+0x
> 95 [0xfffffd7fecfc9bd5]
>    #32
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'tevent_common_loop_w
> ait+0x23 [0xfffffd7fecfc9e43]
>    #33
> /usr/lib/samba/private/amd64/libtevent.so.0.10.2'std_event_loop_wait+
> 0x40 [0xfffffd7fecfcf870]
>    #34 /usr/lib/samba/sbin/amd64/smbd'main+0x1a0f [0x40f9ff]
>    #35 /usr/lib/samba/sbin/amd64/smbd'_start_crt+0x83 [0x408e73]
>    #36 /usr/lib/samba/sbin/amd64/smbd'_start+0x18 [0x408dd8]
> [2020/04/12 11:15:21.538230,  0]
> ../../source3/lib/dumpcore.c:315(dump_core)
>   dumping core in /var/samba/log/cores/smbd
> [2020/04/12 11:15:21.949051,  0]
> ../../lib/util/become_daemon.c:136(daemon_ready)
>   daemon_ready: daemon 'smbd' finished starting up and ready to serve
> connections
> 
> 
> My smb.conf is:
> #======================= Global Settings
> =====================================
> [global]
> 
>     workgroup = mano-de.dios
>     netbios name = wutz
>     mdns name = mdns
>     multicast dns register = yes
>     server string = Filet Server (%v)
>     server role = standalone server
>     log file = /var/log/samba/smbd.log
>     max log size = 50
>     wins support = yes
>     dns proxy = no
>     guest account = nobody
>     fruit:aapl = yes
>     fruit:model = RackMac
>     log level = vfs:10
> 
> #============================ Share Definitions
> ==============================
> [homes]
>     comment = Home Share 
>     browseable = no
>     writable = yes
>     guest ok = no
>     vfs objects = catia fruit zfsacl streams_xattr 
>     fruit:resource = xattr
>     fruit:metadata = netatalk
>     fruit:locking = netatalk
>     fruit:encoding = native
> 
> [FileVault]
>     comment = Apple Time Capsule
>     path = /export/home/timecapsule
>     browseable = no
>     writeable = no
>     valid users = @admin
>     write list = @admin
>     guest ok = no
>     vfs objects = catia fruit zfsacl streams_xattr 
>     fruit:resource = xattr
>     fruit:metadata = netatalk
>     fruit:locking = netatalk
>     fruit:encoding = native
>     fruit:time machine = yes