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

SOLVED Sudden Terrible SMB performance

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

Constantin

Vampire Pig
Joined
May 19, 2017
Messages
1,380
Good evening,

I recently switched to TrueNAS 12 and am running TrueNAS-12.0-U2.1. As I mentioned before, I have tried to take advantage of special vdevs (via 3 mirrored S3610 SSDs), etc. by nuking the pool and rebuilding it from the ground up, then restoring from backup. Along the way, I learned a thing or two about ACLs because the new pool only uses SMB instead of AFP. I have been slowly inching my way towards getting the pool fully set up when I ran into serious performance issues starting yesterday.

I started seeing the telltale signs of a bad SMB process while trying to delete empty files. File renames and deletes would take very long time instead of being instantaneous as I had gotten used to with the new SSD metadata.
Screen Shot 2021-04-07 at 2.13.32 PM.png

Screen Shot 2021-04-07 at 1.53.46 PM.png


SMBD is taking up all the thread capacity. Gstat shows no activity to speak of, ditto our network interface.
Screen Shot 2021-04-07 at 2.09.38 PM.png


Cat the SMB Error logs though and there is a torrent of error messages. Here is a selection of messages but each message literally has lots of instances each.

Code:
[2021/04/07 00:17:24.532299,  1] ../../source3/rpc_server/srv_pipe_hnd.c:103(np_open)
  np_open: 'mdssvc' is not a registered pipe!
 
 ....
 
[2021/04/07 00:39:42.350377,  1] ../../source3/smbd/scavenger.c:486(scavenger_timer)
  scavenger_timer: Failed to cleanup share modes and byte range locks for file 4758002284915082683:390:0 open 1183922632
 
  ...
 
  [2021/04/07 07:58:41.358773,  0] ../../source3/modules/vfs_ixnas.c:2300(ixnas_ntimes)
  ixnas_ntimes: utimensat failed: No such file or directory
 
  ...
 
  [2021/04/07 09:10:39.011705,  1] ../../source3/smbd/scavenger.c:486(scavenger_timer)
  scavenger_timer: Failed to cleanup share modes and byte range locks for file 4758002284915082683:2924:0 open 3686271052
 
  ...
 
 
  [2021/04/07 09:10:39.022767, 1] ../../source3/smbd/scavenger.c:486(scavenger_timer)
scavenger_timer: Failed to cleanup share modes and byte range locks for file 4758002284915082683:25467:0 open 3332239265

...

[2021/04/07 10:13:39.191945, 0] ../../source3/modules/vfs_ixnas.c:2300(ixnas_ntimes)
ixnas_ntimes: utimensat failed: No such file or directory
[2021/04/07 10:13:49.773403, 0] ../../source3/smbd/server.c:1782(main)
smbd version 4.12.9 started.
Copyright Andrew Tridgell and the Samba Team 1992-2020
[2021/04/07 10:13:49.780627, 1] ../../source3/profile/profile.c:55(set_profile_level)
INFO: Profiling turned OFF from pid 59797
[2021/04/07 10:13:50.046111, 1] ../../source3/smbd/files.c:223(file_init_global)
file_init_global: Information only: requested 3770496 open files, 59392 are available.
[2021/04/07 10:13:50.050138, 0] ../../lib/util/become_daemon.c:136(daemon_ready)
daemon_ready: daemon 'smbd' finished starting up and ready to serve connections
[2021/04/07 10:14:29.344871, 0] ../../source3/smbd/server.c:1782(main)
smbd version 4.12.9 started.
Copyright Andrew Tridgell and the Samba Team 1992-2020
[2021/04/07 10:14:29.351094, 1] ../../source3/profile/profile.c:55(set_profile_level)
INFO: Profiling turned OFF from pid 59989
[2021/04/07 10:14:29.599776, 1] ../../source3/smbd/files.c:223(file_init_global)
file_init_global: Information only: requested 3770496 open files, 59392 are available.
[2021/04/07 10:14:29.603268, 0] ../../lib/util/become_daemon.c:136(daemon_ready)
daemon_ready: daemon 'smbd' finished starting up and ready to serve connections
[2021/04/07 10:45:25.500328, 1] ../../source3/printing/printer_list.c:234(printer_list_get_last_refresh)
Failed to fetch record!
[2021/04/07 10:45:25.500385, 1] ../../source3/smbd/server_reload.c:66(delete_and_reload_printers)
pcap cache not loaded
[2021/04/07 10:45:26.992197, 1] ../../source3/rpc_server/srv_pipe_hnd.c:103(np_open)
np_open: 'mdssvc' is not a registered pipe!

...

[2021/04/07 11:13:40.775732, 1] ../../source3/printing/printer_list.c:234(printer_list_get_last_refresh)
Failed to fetch record!
[2021/04/07 11:13:40.775880, 1] ../../source3/smbd/server_reload.c:66(delete_and_reload_printers)
pcap cache not loaded
[2021/04/07 11:14:00.140837, 1] ../../source3/printing/printer_list.c:234(printer_list_get_last_refresh)
Failed to fetch record!
[2021/04/07 11:14:00.140880, 1] ../../source3/smbd/server_reload.c:66(delete_and_reload_printers)
pcap cache not loaded

...


2021/04/07 13:18:42.632283, 0] ../../source3/smbd/server.c:1782(main)
smbd version 4.12.9 started.
Copyright Andrew Tridgell and the Samba Team 1992-2020
[2021/04/07 13:18:42.647292, 1] ../../source3/profile/profile.c:55(set_profile_level)
INFO: Profiling turned OFF from pid 3606
[2021/04/07 13:18:42.930005, 0] ../../source3/smbd/server.c:1782(main)
smbd version 4.12.9 started.
Copyright Andrew Tridgell and the Samba Team 1992-2020
[2021/04/07 13:18:42.935044, 1] ../../source3/profile/profile.c:55(set_profile_level)
INFO: Profiling turned OFF from pid 3626
[2021/04/07 13:18:42.935860, 0] ../../lib/util/pidfile.c:197(pidfile_create)
ERROR: smbd is already running. File /var/run/samba4/smbd.pid exists and process id 3608 is running.
[2021/04/07 13:18:42.996190, 1] ../../source3/smbd/files.c:223(file_init_global)
file_init_global: Information only: requested 3770496 open files, 59392 are available.
[2021/04/07 13:18:43.004326, 0] ../../lib/util/become_daemon.c:136(daemon_ready)
daemon_ready: daemon 'smbd' finished starting up and ready to serve connections
[2021/04/07 13:20:11.004756, 1] ../../source3/printing/printer_list.c:234(printer_list_get_last_refresh)
Failed to fetch record!
[2021/04/07 13:20:11.004801, 1] ../../source3/smbd/server_reload.c:66(delete_and_reload_printers)
pcap cache not loaded

..

[2021/04/07 13:40:41.424242, 1] ../../source3/smbd/files.c:223(file_init_global)
file_init_global: Information only: requested 3770496 open files, 59392 are available.
[2021/04/07 13:40:41.427876, 0] ../../lib/util/become_daemon.c:136(daemon_ready)
daemon_ready: daemon 'smbd' finished starting up and ready to serve connections
[2021/04/07 13:51:22.605615, 1] ../../source3/rpc_server/srv_pipe_hnd.c:103(np_open)
np_open: 'mdssvc' is not a registered pipe!
[2021/04/07 14:21:44.276087, 0] ../../source3/smbd/server.c:1782(main)
smbd version 4.12.9 started.
Copyright Andrew Tridgell and the Samba Team 1992-2020
[2021/04/07 14:21:44.282156, 1] ../../source3/profile/profile.c:55(set_profile_level)
INFO: Profiling turned OFF from pid 6436
[2021/04/07 14:21:44.524169, 1] ../../source3/smbd/files.c:223(file_init_global)
file_init_global: Information only: requested 3770496 open files, 59392 are available.
[2021/04/07 14:21:44.527982, 0] ../../lib/util/become_daemon.c:136(daemon_ready)
daemon_ready: daemon 'smbd' finished starting up and ready to serve connections
[2021/04/07 14:22:12.740894, 1] ../../source3/printing/printer_list.c:234(printer_list_get_last_refresh)
Failed to fetch record!
[2021/04/07 14:22:12.740995, 1] ../../source3/smbd/server_reload.c:66(delete_and_reload_printers)
pcap cache not loaded
[2021/04/07 14:22:13.959709, 1] ../../source3/rpc_server/srv_pipe_hnd.c:103(np_open)
np_open: 'mdssvc' is not a registered pipe!


Does anyone know what might be going on?
 

Constantin

Vampire Pig
Joined
May 19, 2017
Messages
1,380
Kids, don't be stupid like Constantin and add a NTP server without knowing that it agrees with all the other NTP servers in the pool. For example, do not add a local gateway as a NTP server in addition to the pools that are in there by default. Bad things will happen.
 

rogerh

Neophyte Sage
Joined
Apr 18, 2014
Messages
1,089
Kids, don't be stupid like Constantin and add a NTP server without knowing that it agrees with all the other NTP servers in the pool. For example, do not add a local gateway as a NTP server in addition to the pools that are in there by default. Bad things will happen.
If your local gateway ntp server is properly synced with a pool of remote ntp servers, wouldn't it make sense to use it as the only ntp server for other machines on the local network?
 

Constantin

Vampire Pig
Joined
May 19, 2017
Messages
1,380
Top