- Joined
- May 19, 2017
- Messages
- 1,829
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.
SMBD is taking up all the thread capacity. Gstat shows no activity to speak of, ditto our network interface.
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.
Does anyone know what might be going on?
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.
SMBD is taking up all the thread capacity. Gstat shows no activity to speak of, ditto our network interface.
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?