Firstly, congrats on all the great progress! This is shaping up to be an awesome product!
I've been using the 20.10 Alpha release and have seen some issues with SMB shares, mostly boiling down to two things: 1. Consistent failures to start at boot, and 2. Random disconnections of the share from other machines. I tried looking for JIRAs for these, but couldn't find anything that seemed to exactly match these issues, please correct me if I'm wrong!
For 1:
My SMB shares 100% fail to start at boot. I've tried disabling/re-enabling the SMB service, but it doesn't seem to change anything. During boot I see the following failure messages:
And from smbd.log
From /var/log/daemon.log:
From winbdd.log:
From /var/log/samba4/log.smbd:
After boot if I go to services I can manually start SMB without issue. Is this related to some boot dependencies not being setup and initialized properly prior to smb starting?
Unfortunately for #2 I don't have any concrete info on what might be causing these disconnections. If logs are needed please let me know what I should capture.
Also I see hundreds of these error messages every second that look like:
Are these something I should be worried about?
I've been using the 20.10 Alpha release and have seen some issues with SMB shares, mostly boiling down to two things: 1. Consistent failures to start at boot, and 2. Random disconnections of the share from other machines. I tried looking for JIRAs for these, but couldn't find anything that seemed to exactly match these issues, please correct me if I'm wrong!
For 1:
My SMB shares 100% fail to start at boot. I've tried disabling/re-enabling the SMB service, but it doesn't seem to change anything. During boot I see the following failure messages:
And from smbd.log
[2020/12/09 06:24:09.680312, 0] ../../source3/winbindd/winbindd.c:247(winbindd_sig_term_handler)
Got sig[15] terminate (is_parent=0)
[2020/12/09 06:42:12.954139, 0] ../../source3/winbindd/winbindd_cm.c:1880(wb_open_internal_pipe)
open_internal_pipe: Could not connect to dssetup pipe: NT_STATUS_RPC_INTERFACE_NOT_FOUND
[2020/12/09 06:42:12.974655, 0] ../../source3/rpc_server/rpc_ncacn_np.c:453(rpcint_dispatch)
rpcint_dispatch: DCE/RPC fault in call lsarpc:2E - DCERPC_NCA_S_OP_RNG_ERROR
From /var/log/daemon.log:
Dec 9 06:26:20 tnsbuilds01 systemd[1]: winbind.service: Main process exited, code=exited, status=1/FAILURE
Dec 9 06:26:20 tnsbuilds01 systemd[1]: winbind.service: Failed with result 'exit-code'.
Dec 9 06:26:20 tnsbuilds01 systemd[1]: Failed to start Samba Winbind Daemon.
Dec 9 06:26:20 tnsbuilds01 systemd[1]: Starting Samba SMB Daemon...
Dec 9 06:26:20 tnsbuilds01 exim4[3467]: Starting MTA: exim4.
Dec 9 06:26:20 tnsbuilds01 systemd[1]: Started LSB: exim Mail Transport Agent.
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: [2020/12/09 06:26:20, 0] ../../lib/util/debug.c:1099(reopen_one_log)
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: reopen_one_log: Unable to open new log file '/var/log/samba4/log.smbd': No such file or directory
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: [2020/12/09 06:26:20, 0] ../../lib/util/util.c:363(directory_create_or_exist)
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: directory_create_or_exist: mkdir failed on directory /var/log/samba4/cores: No such file or directory
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: [2020/12/09 06:26:20, 0] ../../source3/lib/dumpcore.c:59(get_default_corepath)
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: Failed to create /var/log/samba4/cores for user 0 with mode 0700
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: [2020/12/09 06:26:20, 0] ../../source3/lib/dumpcore.c:256(dump_core_setup)
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: Unable to setup corepath for smbd: No such file or directory
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: [2020/12/09 06:26:20.966600, 0] ../../lib/util/debug.c:1099(reopen_one_log)
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: reopen_one_log: Unable to open new log file '/var/log/samba4/log.smbd': No such file or directory
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: [2020/12/09 06:26:20.966608, 0] ../../source3/smbd/server.c:1784(main)
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: smbd version 4.13.0-TrueNAS started.
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: Copyright Andrew Tridgell and the Samba Team 1992-2020
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: [2020/12/09 06:26:20.967825, 0] ../../lib/util/util.c:363(directory_create_or_exist)
Dec 9 06:26:20 tnsbuilds01 smbd[4032]: directory_create_or_exist: mkdir failed on directory /var/db/system/samba4/private/msg.sock: No such file or directory
Dec 9 06:26:20 tnsbuilds01 systemd[1]: smbd.service: Main process exited, code=exited, status=1/FAILURE
Dec 9 06:26:20 tnsbuilds01 systemd[1]: smbd.service: Failed with result 'exit-code'.
Dec 9 06:26:20 tnsbuilds01 systemd[1]: Failed to start Samba SMB Daemon.
From winbdd.log:
[2020/12/09 06:24:09.680301, 0] ../../source3/winbindd/winbindd.c:247(winbindd_sig_term_handler)
Got sig[15] terminate (is_parent=1)
[2020/12/09 06:42:12.905710, 0] ../../source3/winbindd/winbindd.c:1784(main)
winbindd version 4.13.0-TrueNAS started.
Copyright Andrew Tridgell and the Samba Team 1992-2020
[2020/12/09 06:42:12.932700, 0] ../../source3/winbindd/winbindd_cache.c:3203(initialize_winbindd_cache)
initialize_winbindd_cache: clearing cache and re-creating with version number 2
[2020/12/09 06:42:12.951638, 0] ../../lib/util/become_daemon.c:135(daemon_ready)
daemon_ready: daemon 'winbindd' finished starting up and ready to serve connections
From /var/log/samba4/log.smbd:
[2020/12/09 06:42:12.768970, 0] ../../source3/smbd/server.c:1784(main)
smbd version 4.13.0-TrueNAS started.
Copyright Andrew Tridgell and the Samba Team 1992-2020
[2020/12/09 06:42:12.789496, 1] ../../source3/profile/profile.c:54(set_profile_level)
INFO: Profiling turned OFF from pid 30496
[2020/12/09 06:42:12.870139, 0] ../../lib/util/become_daemon.c:135(daemon_ready)
daemon_ready: daemon 'smbd' finished starting up and ready to serve connections
[2020/12/09 06:42:15.294419, 0] ../../source3/modules/smb_libzfs.c:795(zhandle_get_dataset)
zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [share/.system]: No such file or directory
[2020/12/09 06:42:15.297175, 0] ../../source3/modules/smb_libzfs.c:795(zhandle_get_dataset)
zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [share/.system]: No such file or directory
[2020/12/09 06:42:59.069800, 1] ../../source3/printing/printer_list.c:234(printer_list_get_last_refresh)
Failed to fetch record!
[2020/12/09 06:42:59.069891, 1] ../../source3/smbd/server_reload.c:66(delete_and_reload_printers)
pcap cache not loaded
[2020/12/09 06:42:59.096596, 0] ../../source3/modules/smb_libzfs.c:795(zhandle_get_dataset)
zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [share/.system]: No such file or directory
[2020/12/09 06:42:59.267556, 1] ../../source3/modules/vfs_fruit.c:3481(fruit_streaminfo_meta_netatalk)
fruit_streaminfo_meta_netatalk: Unexpected AFPINFO_STREAM on [.DS_Store]
[2020/12/09 06:42:59.268320, 1] ../../source3/modules/vfs_fruit.c:3481(fruit_streaminfo_meta_netatalk)
fruit_streaminfo_meta_netatalk: Unexpected AFPINFO_STREAM on [.DS_Store]
[2020/12/09 06:42:59.571757, 1] ../../source3/rpc_server/mdssvc/srv_mdssvc_nt.c:103(create_mdssvc_policy_handle)
error in mds_init_ctx for: /mnt/share
[2020/12/09 06:42:59.571800, 0] ../../source3/rpc_server/mdssvc/srv_mdssvc_nt.c:151(_mdssvc_open)
_mdssvc_open: Couldn't create policy handle for share
[2020/12/09 06:43:52.249924, 0] ../../source3/modules/smb_libzfs.c:795(zhandle_get_dataset)
zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [share/.system]: No such file or directory
[2020/12/09 06:43:52.250134, 0] ../../source3/modules/smb_libzfs.c:795(zhandle_get_dataset)
zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [share/.system]: No such file or directory
[2020/12/09 06:43:52.257527, 0] ../../source3/modules/smb_libzfs.c:795(zhandle_get_dataset)
zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [share/.system]: No such file or directory
[2020/12/09 06:43:52.257732, 0] ../../source3/modules/smb_libzfs.c:795(zhandle_get_dataset)
zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [share/.system]: No such file or directory
[2020/12/09 07:40:23.964161, 1] ../../source3/printing/printer_list.c:234(printer_list_get_last_refresh)
Failed to fetch record!
[2020/12/09 07:40:23.964305, 1] ../../source3/smbd/server_reload.c:66(delete_and_reload_printers)
pcap cache not loaded
After boot if I go to services I can manually start SMB without issue. Is this related to some boot dependencies not being setup and initialized properly prior to smb starting?
Unfortunately for #2 I don't have any concrete info on what might be causing these disconnections. If logs are needed please let me know what I should capture.
Also I see hundreds of these error messages every second that look like:
Dec 7 16:09:02 truenas collectd[4987]: rrdcached plugin: Failed to connect to RRDCacheD at unix:/var/run/rrdcached.sock: Unable to connect to rrdcached: No such file or directory (status=2)
Are these something I should be worried about?