Register for the iXsystems Community to get an ad-free experience and exclusive discounts in our eBay Store.

TrueNAS Scale SMB Issues

Western Digital Drives - The Preferred Drives of FreeNAS and TrueNAS CORE

dalnew

Junior Member
Joined
Dec 9, 2020
Messages
16
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
[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?
 

tstyopin

Newbie
Joined
Dec 5, 2020
Messages
2
same problem with my setup, after upgrade from 11.3

freenas.local smbd 94115 - - [2020/12/18 15:06:49.110020, 0] ../../lib/util/fault.c:79(fault_report)
freenas.local smbd 94115 - - ===============================================================
freenas.local smbd 94115 - - [2020/12/18 15:06:49.110489, 0] ../../lib/util/fault.c:80(fault_report)
freenas.local smbd 94115 - - [B]INTERNAL ERROR[/B]: Signal 11 in pid 94115 ([B]4.12.9[/B])
freenas.local smbd 94115 - - If you are running a recent Samba version, and if you think this problem is not yet fixed in the latest versions, please consider reporting this bug, see https://wiki.samba.org/index.php/Bug_Reporting
freenas.local smbd 94115 - - [2020/12/18 15:06:49.110618, 0] ../../lib/util/fault.c:86(fault_report)
freenas.local smbd 94115 - - ===============================================================
freenas.local smbd 94115 - - [2020/12/18 15:06:49.110703, 0] ../../source3/lib/util.c:830(smb_panic_s3)
freenas.local smbd 94115 - - PANIC (pid 94115): internal error
freenas.local smbd 94115 - - [2020/12/18 15:06:49.113464, 0] ../../lib/util/fault.c:265(log_stack_trace)
freenas.local smbd 94115 - - BACKTRACE: 6 stack frames:
freenas.local smbd 94115 - - #0 0x801296217 <log_stack_trace+0x37> at /usr/local/lib/samba4/libsamba-util.so.0
freenas.local smbd 94115 - - #1 0x802f9b656 <smb_panic_s3+0x56> at /usr/local/lib/samba4/libsmbconf.so.0
freenas.local smbd 94115 - - #2 0x801296007 <smb_panic+0x17> at /usr/local/lib/samba4/libsamba-util.so.0
freenas.local smbd 94115 - - #3 0x8012963ee <log_stack_trace+0x20e> at /usr/local/lib/samba4/libsamba-util.so.0
freenas.local smbd 94115 - - #4 0x801295fe9 <fault_setup+0x59> at /usr/local/lib/samba4/libsamba-util.so.0
freenas.local smbd 94115 - - #5 0x8099dbc20 <_pthread_sigmask+0x530> at /lib/libthr.so.3
freenas.local smbd 94115 - - [2020/12/18 15:06:49.113999, 0] ../../source3/lib/dumpcore.c:315(dump_core)
freenas.local smbd 94115 - - dumping core in /var/db/system/cores
freenas.local smbd 94115 - -
freenas.local kernel: pid 94115 (smbd), jid 0, uid 0: exited on signal 6
freenas.local smbd 95340 - - [2020/12/18 15:06:49.243572, 0] ../../source3/modules/smb_libzfs.c:916(zhandle_get_dataset)
freenas.local smbd 95340 - - zhandle_get_dataset: [B]Failed to stat dataset[/B] mounpoint [legacy] for dataset [Mpool/.system]: No such file or directory


Settings are default, no extra options added to config
 

anodos

Sambassador
iXsystems
Joined
Mar 6, 2014
Messages
7,177
same problem with my setup, after upgrade from 11.3

freenas.local smbd 94115 - - [2020/12/18 15:06:49.110020, 0] ../../lib/util/fault.c:79(fault_report)
freenas.local smbd 94115 - - ===============================================================
freenas.local smbd 94115 - - [2020/12/18 15:06:49.110489, 0] ../../lib/util/fault.c:80(fault_report)
freenas.local smbd 94115 - - [B]INTERNAL ERROR[/B]: Signal 11 in pid 94115 ([B]4.12.9[/B])
freenas.local smbd 94115 - - If you are running a recent Samba version, and if you think this problem is not yet fixed in the latest versions, please consider reporting this bug, see https://wiki.samba.org/index.php/Bug_Reporting
freenas.local smbd 94115 - - [2020/12/18 15:06:49.110618, 0] ../../lib/util/fault.c:86(fault_report)
freenas.local smbd 94115 - - ===============================================================
freenas.local smbd 94115 - - [2020/12/18 15:06:49.110703, 0] ../../source3/lib/util.c:830(smb_panic_s3)
freenas.local smbd 94115 - - PANIC (pid 94115): internal error
freenas.local smbd 94115 - - [2020/12/18 15:06:49.113464, 0] ../../lib/util/fault.c:265(log_stack_trace)
freenas.local smbd 94115 - - BACKTRACE: 6 stack frames:
freenas.local smbd 94115 - - #0 0x801296217 <log_stack_trace+0x37> at /usr/local/lib/samba4/libsamba-util.so.0
freenas.local smbd 94115 - - #1 0x802f9b656 <smb_panic_s3+0x56> at /usr/local/lib/samba4/libsmbconf.so.0
freenas.local smbd 94115 - - #2 0x801296007 <smb_panic+0x17> at /usr/local/lib/samba4/libsamba-util.so.0
freenas.local smbd 94115 - - #3 0x8012963ee <log_stack_trace+0x20e> at /usr/local/lib/samba4/libsamba-util.so.0
freenas.local smbd 94115 - - #4 0x801295fe9 <fault_setup+0x59> at /usr/local/lib/samba4/libsamba-util.so.0
freenas.local smbd 94115 - - #5 0x8099dbc20 <_pthread_sigmask+0x530> at /lib/libthr.so.3
freenas.local smbd 94115 - - [2020/12/18 15:06:49.113999, 0] ../../source3/lib/dumpcore.c:315(dump_core)
freenas.local smbd 94115 - - dumping core in /var/db/system/cores
freenas.local smbd 94115 - -
freenas.local kernel: pid 94115 (smbd), jid 0, uid 0: exited on signal 6
freenas.local smbd 95340 - - [2020/12/18 15:06:49.243572, 0] ../../source3/modules/smb_libzfs.c:916(zhandle_get_dataset)
freenas.local smbd 95340 - - zhandle_get_dataset: [B]Failed to stat dataset[/B] mounpoint [legacy] for dataset [Mpool/.system]: No such file or directory


Settings are default, no extra options added to config
Upgrade from 11.3 -> SCALE? How was this done? There are quite a few SMB settings that are incompatible between the two versions (as well as dataset ACL types).
 

kauedg

Neophyte
Joined
Jan 13, 2021
Messages
5
I'm having the same issues with SMB Shares. The client hangs for some seconds and the server's log file
/var/log/samba4/log.smbd shows this:


Code:
[2021/02/04 14:01:23.144926,  0] ../../lib/util/fault.c:79(fault_report)
  ===============================================================
[2021/02/04 14:01:23.145053,  0] ../../lib/util/fault.c:80(fault_report)
  INTERNAL ERROR: Signal 10 in pid 7174 (4.12.9)
  If you are running a recent Samba version, and if you think this problem is not yet fixed in the latest versions, please consider reporting this bug, see https://wiki.samba.org/index.php/Bug_Reporting
[2021/02/04 14:01:23.145172,  0] ../../lib/util/fault.c:86(fault_report)
  ===============================================================
[2021/02/04 14:01:23.145271,  0] ../../source3/lib/util.c:830(smb_panic_s3)
  PANIC (pid 7174): internal error
[2021/02/04 14:01:23.148585,  0] ../../lib/util/fault.c:265(log_stack_trace)
  BACKTRACE: 6 stack frames:
   #0 0x801952d17 <log_stack_trace+0x37> at /usr/local/lib/samba4/libsamba-util.so.0
   #1 0x802ccfb86 <smb_panic_s3+0x56> at /usr/local/lib/samba4/libsmbconf.so.0
   #2 0x801952b07 <smb_panic+0x17> at /usr/local/lib/samba4/libsamba-util.so.0
   #3 0x801952eee <log_stack_trace+0x20e> at /usr/local/lib/samba4/libsamba-util.so.0
   #4 0x801952ae9 <fault_setup+0x59> at /usr/local/lib/samba4/libsamba-util.so.0
   #5 0x80fd48c20 <_pthread_sigmask+0x530> at /lib/libthr.so.3
[2021/02/04 14:01:23.148963,  0] ../../source3/lib/dumpcore.c:315(dump_core)
  dumping core in /var/db/system/cores
[2021/02/04 14:01:23.252417,  0] ../../source3/modules/smb_libzfs.c:916(zhandle_get_dataset)
  zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [Pool_raidz/.system]: No such file or directory
[2021/02/04 14:01:23.260511,  0] ../../source3/modules/smb_libzfs.c:916(zhandle_get_dataset)
  zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [Pool_raidz/.system]: No such file or directory
[2021/02/04 14:01:23.270629,  0] ../../source3/modules/smb_libzfs.c:916(zhandle_get_dataset)
  zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [Pool_raidz/.system]: No such file or directory
[2021/02/04 14:01:51.063054,  0] ../../lib/util/fault.c:79(fault_report)
  ===============================================================
[2021/02/04 14:01:51.063161,  0] ../../lib/util/fault.c:80(fault_report)
  INTERNAL ERROR: Signal 10 in pid 7175 (4.12.9)
  If you are running a recent Samba version, and if you think this problem is not yet fixed in the latest versions, please consider reporting this bug, see https://wiki.samba.org/index.php/Bug_Reporting
[2021/02/04 14:01:51.063279,  0] ../../lib/util/fault.c:86(fault_report)
  ===============================================================
[2021/02/04 14:01:51.063356,  0] ../../source3/lib/util.c:830(smb_panic_s3)
  PANIC (pid 7175): internal error
[2021/02/04 14:01:51.066684,  0] ../../lib/util/fault.c:265(log_stack_trace)
  BACKTRACE: 6 stack frames:
   #0 0x801952d17 <log_stack_trace+0x37> at /usr/local/lib/samba4/libsamba-util.so.0
   #1 0x802ccfb86 <smb_panic_s3+0x56> at /usr/local/lib/samba4/libsmbconf.so.0
   #2 0x801952b07 <smb_panic+0x17> at /usr/local/lib/samba4/libsamba-util.so.0
   #3 0x801952eee <log_stack_trace+0x20e> at /usr/local/lib/samba4/libsamba-util.so.0
   #4 0x801952ae9 <fault_setup+0x59> at /usr/local/lib/samba4/libsamba-util.so.0
   #5 0x80fd48c20 <_pthread_sigmask+0x530> at /lib/libthr.so.3
[2021/02/04 14:01:51.067058,  0] ../../source3/lib/dumpcore.c:315(dump_core)
  dumping core in /var/db/system/cores
[2021/02/04 14:01:51.170541,  0] ../../source3/modules/smb_libzfs.c:916(zhandle_get_dataset)
  zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [Pool_raidz/.system]: No such file or directory
[2021/02/04 14:01:51.178744,  0] ../../source3/modules/smb_libzfs.c:916(zhandle_get_dataset)
  zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [Pool_raidz/.system]: No such file or directory
[2021/02/04 14:01:51.191303,  0] ../../source3/modules/smb_libzfs.c:916(zhandle_get_dataset)
  zhandle_get_dataset: Failed to stat dataset mounpoint [legacy] for dataset [Pool_raidz/.system]: No such file or directory


The client Linux's journalctl with the shares mounted show this:
Code:
fev 04 14:00:42 localhost kernel: Status code returned 0xc0000128 STATUS_FILE_CLOSED
fev 04 14:00:42 localhost kernel: CIFS VFS: Send error in read = -9
fev 04 14:00:52 localhost kernel: Status code returned 0xc0000128 STATUS_FILE_CLOSED
fev 04 14:00:52 localhost kernel: CIFS VFS: Send error in read = -9
fev 04 14:01:02 localhost kernel: Status code returned 0xc0000128 STATUS_FILE_CLOSED
fev 04 14:01:02 localhost kernel: CIFS VFS: Send error in read = -9
fev 04 14:02:01 localhost kernel: Status code returned 0xc0000128 STATUS_FILE_CLOSED
fev 04 14:02:01 localhost kernel: CIFS VFS: Send error in read = -9
 

kauedg

Neophyte
Joined
Jan 13, 2021
Messages
5
Hmmm. which version is this? This is a bug smb_libzfs that I believe I fixed recently-ish (maybe forgot to backport from FreeBSD to SCALE).
Sorry, forgot to paste and couldn't edit it before being approved. It's running on

Version:
TrueNAS-12.0-U1.1


The issue has appeared in the last 2-3 days. While using Atom editor on Kubuntu 20.04 (Kernel 5.4.0-65-generic), when switching to another window and then back, it hangs, the logs appear and after some seconds I can work on the files again.

FYI the mount options of the share, on the client (all default):
Code:
//192.168.0.5/homes on /home/myuser/home@truenas.mydomain.lan type cifs (rw,relatime,vers=3.1.1,cache=strict,username=myuser,uid=1000,forceuid,gid=1000,forcegid,addr=192.168.0.5,file_mode=0775,dir_mode=0755,soft,nounix,serverino,mapposix,rsize=4194304,wsize=4194304,bsize=1048576,echo_interval=60,actimeo=1)
 

kauedg

Neophyte
Joined
Jan 13, 2021
Messages
5
Oh. This is a known issue that will be fixed in U2. You can PM me if you want to test the fix (otherwise you can wait till around Feb 9th for the next release).
Thanks. I'd like to test the fix and PMed.
 
Top