Our samba server in ap-east-1 is running very slow today
I noticed three things in log.smb, and I don't understand any of them
----------
#1 roughly every 80 seconds what appears to be a reconnect loop
[2020/11/19 17:35:46.283315, 2]
../../source3/lib/tallocmsg.c:87(register_msg_pool_usage)
Registered MSG_REQ_POOL_USAGE
[2020/11/19 17:35:46.287132, 1] ../../source3/lib/util.c:1694(name_to_fqdn)
getaddrinfo: Name or service not known
[2020/11/19 17:35:46.800224, 2]
../../source3/param/loadparm.c:2862(lp_do_section)
Processing section "[DC]"
[2020/11/19 17:35:46.802682, 2]
../../source3/auth/auth.c:329(auth_check_ntlm_password)
check_ntlm_password: authentication for user [srv-acct] -> [srv-acct]
->
[DEVAD\srv-acct] succeeded
[2020/11/19 17:36:06.483196, 2]
../../source3/smbd/service.c:1152(close_cnum)
somdev-or-cdc-1 (ipv4:10.7.3.228:58542) closed connection to service DC
[2020/11/19 17:36:06.851891, 2]
../../source3/modules/vfs_acl_xattr.c:234(connect_acl_xattr)
connect_acl_xattr: setting 'inherit acls = true' 'dos filemode =
true'
and 'force unknown acl user = true' for service NY
[2020/11/19 17:36:06.852223, 2]
../../source3/smbd/service.c:877(make_connection_snum)
devad-or-cdc-1 (ipv4:10.7.3.228:58544) connect to service DC initially as
user DEVAD\srv-acct (uid=12187, gid=10513) (pid 3881171)
notes:
- hitting the or-cdc even though `net ads lookup dc` returns the ap-cdc
- uid and gid remain the same, pid changes
google search all I can find is hostname issues. hostname is set in
/etc/hosts correctly
----------
#2 close attempt and PANIC
[2020/11/19 17:37:45.156495, 0] ../../source3/lib/util.c:830(smb_panic_s3)
PANIC (pid 3881171): can not close with outstanding aio requests
[2020/11/19 17:37:45.156965, 0] ../../lib/util/fault.c:265(log_stack_trace)
BACKTRACE: 34 stack frames:
#0 /lib64/libsamba-util.so.0(log_stack_trace+0x34) [0x7f1d05f0e264]
#1 /lib64/libsmbconf.so.0(smb_panic_s3+0x29) [0x7f1d05969639]
#2 /lib64/libsamba-util.so.0(smb_panic+0x31) [0x7f1d05f0e361]
#3 /usr/lib64/samba/libsmbd-base-samba4.so(+0x1d9fff) [0x7f1d05b7ffff]
#4 /usr/lib64/samba/libsmbd-base-samba4.so(close_file+0x240)
[0x7f1d05b80b10]
#5 /usr/lib64/samba/libsmbd-base-samba4.so(file_close_user+0x3d)
[0x7f1d05b1bacd]
#6 /usr/lib64/samba/libsmbd-base-samba4.so(smbXsrv_session_logoff+0x51)
[0x7f1d05bca1e1]
#7 /usr/lib64/samba/libsmbd-base-samba4.so(+0x22458a) [0x7f1d05bca58a]
#8 /usr/lib64/samba/libdbwrap-samba4.so(+0x50c4) [0x7f1d03a8e0c4]
#9 /usr/lib64/samba/libdbwrap-samba4.so(+0x52fe) [0x7f1d03a8e2fe]
#10 /usr/lib64/samba/libdbwrap-samba4.so(dbwrap_traverse+0xb)
[0x7f1d03a8c85b]
#11
/usr/lib64/samba/libsmbd-base-samba4.so(smbXsrv_session_logoff_all+0x5b)
[0x7f1d05bca74b]
#12 /usr/lib64/samba/libsmbd-base-samba4.so(+0x229e5e) [0x7f1d05bcfe5e]
#13 /usr/lib64/samba/libsmbd-base-samba4.so(+0x22a3c4) [0x7f1d05bd03c4]
#14 /usr/lib64/samba/libsmbd-shim-samba4.so(exit_server_cleanly+0x18)
[0x7f1d0536ea38]
#15
/usr/lib64/samba/libsmbd-base-samba4.so(smbd_server_connection_terminate_ex+0x162)
[0x7f1d05baad12]
#16 /usr/lib64/samba/libsmbd-base-samba4.so(+0x208d19) [0x7f1d05baed19]
#17 /lib64/libtevent.so.0(tevent_common_invoke_fd_handler+0x83)
[0x7f1d04cf4533]
#18 /lib64/libtevent.so.0(+0xdacf) [0x7f1d04cfaacf]
#19 /lib64/libtevent.so.0(+0xbadb) [0x7f1d04cf8adb]
#20 /lib64/libtevent.so.0(_tevent_loop_once+0x95) [0x7f1d04cf3c05]
#21 /lib64/libtevent.so.0(tevent_common_loop_wait+0x1b) [0x7f1d04cf3eab]
#22 /lib64/libtevent.so.0(+0xba6b) [0x7f1d04cf8a6b]
#23 /usr/lib64/samba/libsmbd-base-samba4.so(smbd_process+0x7bf)
[0x7f1d05b9d0ef]
#24 /usr/sbin/smbd(+0xdd20) [0x55b693cd7d20]
#25 /lib64/libtevent.so.0(tevent_common_invoke_fd_handler+0x83)
[0x7f1d04cf4533]
#26 /lib64/libtevent.so.0(+0xdacf) [0x7f1d04cfaacf]
#27 /lib64/libtevent.so.0(+0xbadb) [0x7f1d04cf8adb]
#28 /lib64/libtevent.so.0(_tevent_loop_once+0x95) [0x7f1d04cf3c05]
#29 /lib64/libtevent.so.0(tevent_common_loop_wait+0x1b) [0x7f1d04cf3eab]
#30 /lib64/libtevent.so.0(+0xba6b) [0x7f1d04cf8a6b]
#31 /usr/sbin/smbd(main+0x1bd2) [0x55b693cd22c2]
#32 /lib64/libc.so.6(__libc_start_main+0xf3) [0x7f1d0472d7b3]
#33 /usr/sbin/smbd(_start+0x2e) [0x55b693cd267e]
[2020/11/19 17:37:45.157318, 0] ../../source3/lib/dumpcore.c:318(dump_core)
coredump is handled by helper binary specified at
/proc/sys/kernel/core_pattern
[2020/11/19 17:38:09.237006, 2]
../../source3/smbd/process.c:2888(deadtime_fn)
Closing idle connection
then directly back into the same loop as #1
----------
#3 verify record
shortly after the PANIC above
[2020/11/19 17:38:10.206414, 2]
../../source3/auth/auth.c:329(auth_check_ntlm_password)
check_ntlm_password: authentication for user [srv-acct] -> [srv-acct]
->
[DEVAD\srv-acct] succeeded
[2020/11/19 17:38:10.207772, 2]
../../source3/smbd/smbXsrv_session.c:881(smbXsrv_session_global_verify_record)
smbXsrv_session_global_verify_record: key '65EB71F1' server_id
0:3881171
does not exist.
[2020/11/19 17:38:10.207802, 2]
../../source3/smbd/smbXsrv_session.c:882(smbXsrv_session_global_verify_record)
[2020/11/19 17:38:10.207809, 1] ../../librpc/ndr/ndr.c:433(ndr_print_debug)
&global_blob: struct smbXsrv_session_globalB
version : SMBXSRV_VERSION_0 (0)
seqnum : 0x00000006 (6)
info : union smbXsrv_session_globalU(case 0)
info0 : *
info0: struct smbXsrv_session_global0
db_rec : NULL
session_global_id : 0x65eb71f1 (1709928945)
session_wire_id : 0x0000000065eb71f1 (1709928945)
creation_time : Thu Nov 19 05:35:46 PM 2020 UTC
expiration_time : Thu Sep 14 02:48:05 AM 30828
UTC
auth_time : Thu Nov 19 05:35:47 PM 2020 UTC
auth_session_info_seqnum : 0x00000001 (1)
auth_session_info : *
auth_session_info: struct auth_session_info
security_token : *
security_token: struct security_token
num_sids : 0x00000017 (23)
sids: ARRAY(23)
sids [ ... ]
privilege_mask :
0x000000001ffffff0 (536870896)
1: SEC_PRIV_MACHINE_ACCOUNT_BIT
1: SEC_PRIV_PRINT_OPERATOR_BIT
1: SEC_PRIV_ADD_USERS_BIT
1: SEC_PRIV_DISK_OPERATOR_BIT
1: SEC_PRIV_REMOTE_SHUTDOWN_BIT
1: SEC_PRIV_BACKUP_BIT
1: SEC_PRIV_RESTORE_BIT
1: SEC_PRIV_TAKE_OWNERSHIP_BIT
1: SEC_PRIV_INCREASE_QUOTA_BIT
1: SEC_PRIV_SECURITY_BIT
1: SEC_PRIV_LOAD_DRIVER_BIT
1: SEC_PRIV_SYSTEM_PROFILE_BIT
1: SEC_PRIV_SYSTEMTIME_BIT
1:
SEC_PRIV_PROFILE_SINGLE_PROCESS_BIT
1:
SEC_PRIV_INCREASE_BASE_PRIORITY_BIT
1: SEC_PRIV_CREATE_PAGEFILE_BIT
1: SEC_PRIV_SHUTDOWN_BIT
1: SEC_PRIV_DEBUG_BIT
1: SEC_PRIV_SYSTEM_ENVIRONMENT_BIT
1: SEC_PRIV_CHANGE_NOTIFY_BIT
1: SEC_PRIV_UNDOCK_BIT
1: SEC_PRIV_ENABLE_DELEGATION_BIT
1: SEC_PRIV_MANAGE_VOLUME_BIT
1: SEC_PRIV_IMPERSONATE_BIT
1: SEC_PRIV_CREATE_GLOBAL_BIT
rights_mask : 0x00000000 (0)
0: LSA_POLICY_MODE_INTERACTIVE
0: LSA_POLICY_MODE_NETWORK
0: LSA_POLICY_MODE_BATCH
0: LSA_POLICY_MODE_SERVICE
0: LSA_POLICY_MODE_PROXY
0: LSA_POLICY_MODE_DENY_INTERACTIVE
0: LSA_POLICY_MODE_DENY_NETWORK
0: LSA_POLICY_MODE_DENY_BATCH
0: LSA_POLICY_MODE_DENY_SERVICE
0:
LSA_POLICY_MODE_REMOTE_INTERACTIVE
0:
LSA_POLICY_MODE_DENY_REMOTE_INTERACTIVE
0x00: LSA_POLICY_MODE_ALL (0)
0x00: LSA_POLICY_MODE_ALL_NT4 (0)
unix_token : *
unix_token: struct security_unix_token
uid :
0x0000000000002f9b (12187)
gid :
0x0000000000002911 (10513)
ngroups : 0x0000000b (11)
groups: ARRAY(11)
groups [ ... ]
info : *
info: struct auth_user_info
account_name : *
account_name :
'srv-acct'
user_principal_name : NULL
user_principal_constructed: 0x00 (0)
domain_name : *
domain_name : 'DEVAD'
dns_domain_name : NULL
full_name : *
full_name : ''
logon_script : *
logon_script : ''
profile_path : *
profile_path : ''
home_directory : *
home_directory : ''
home_drive : *
home_drive : ''
logon_server : *
logon_server :
'DEVAD-AP-CDC-1'
last_logon : Thu Nov 12
04:06:15 PM 2020 UTC
last_logoff : Thu Sep 14
02:48:05 AM 30828 UTC
acct_expiry : Thu Sep 14
02:48:05 AM 30828 UTC
last_password_change : Tue Sep 8
07:44:38 PM 2020 UTC
allow_password_change : Wed Sep 9
07:44:38 PM 2020 UTC
force_password_change : Thu Sep 14
02:48:05 AM 30828 UTC
logon_count : 0x0104 (260)
bad_password_count : 0x0000 (0)
acct_flags : 0x00000210
(528)
authenticated : 0x01 (1)
unix_info : *
unix_info: struct auth_user_info_unix
unix_name : *
unix_name :
'DEVAD\srv-acct'
sanitized_username : *
sanitized_username :
'srv-acct'
torture : NULL
credentials : NULL
unique_session_token :
26addcdb-1953-4652-a7de-8c12952e525c
connection_dialect : 0x0311 (785)
signing_flags : 0x06 (6)
0: SMBXSRV_SIGNING_REQUIRED
1: SMBXSRV_PROCESSED_SIGNED_PACKET
1: SMBXSRV_PROCESSED_UNSIGNED_PACKET
encryption_flags : 0x08 (8)
0: SMBXSRV_ENCRYPTION_REQUIRED
0: SMBXSRV_ENCRYPTION_DESIRED
0: SMBXSRV_PROCESSED_ENCRYPTED_PACKET
1: SMBXSRV_PROCESSED_UNENCRYPTED_PACKET
signing_key : NULL
encryption_key : NULL
decryption_key : NULL
num_channels : 0x00000001 (1)
channels: ARRAY(1)
channels: struct smbXsrv_channel_global0
server_id: struct server_id
pid : 0x00000000003b38d3
(3881171)
task_id : 0x00000000 (0)
vnn : 0x00000000 (0)
unique_id : 0xb2fe48f46a0cc1c4
(-5548917476285431356)
local_address :
'ipv4:10.15.22.214:445'
remote_address :
'ipv4:10.7.3.228:58544'
remote_name : '10.7.3.228'
signing_key : NULL
auth_session_info_seqnum : 0x00000001 (1)
connection : NULL
encryption_cipher : 0x0002 (2)
[2020/11/19 17:38:10.576763, 2]
../../source3/modules/vfs_acl_xattr.c:234(connect_acl_xattr)
connect_acl_xattr: setting 'inherit acls = true' 'dos filemode =
true'
and 'force unknown acl user = true' for service DC
[2020/11/19 17:38:11.818899, 2]
../../source3/smbd/service.c:877(make_connection_snum)
somdev-or-cdc-1 (ipv4:10.7.3.228:58549) connect to service DC initially
as user DEVAD\srv-acct (uid=12187, gid=10513) (pid 3883266)
then continuing as before.
I cannot find information about the PANIC or
smbXsrv_session_global_verify_record
--------
Samba version 4.12.3
---------
#======================= Global Settings
====================================[global]
netbios name = OFS-C25-USE1
realm = DEVAD.LOCAL
workgroup = DEVAD
security = ads
clustering = yes
fake oplocks = no
log level = 2
idmap config * : backend = tdb
idmap config * : range = 3000-7999
idmap config DEVAD: backend = rid
idmap config DEVAD: range = 10000-999999
dedicated keytab file = /etc/krb5.keytab
kerberos method = secrets and keytab
map acl inherit = yes
winbind refresh tickets = yes
# disables printing:
load printers = no
printing = bsd
printcap name = /dev/null
disable spoolss = yes
bind interfaces only = yes
interfaces = lo eth0
#============================ Share Definitions
=============================[DC]
path = "/mnt/use1/DC"
writeable = yes
browsable = yes
fileid:algorithm = fsname_norootdir
vfs objects = fileid shadow_copy2 acl_xattr
acl_xattr:ignore system acls = yes
shadow:mountpoint = /mnt/use1
shadow:snapdir = /snapshots/use1
shadow:snapsharepath = DC
shadow:format = %Y-%m-%dT%H:%M:%SZ
----------
servers with the same configuration are running in four regions. I am
suspicious of some kind of timeout happening. The us-west-2 is noticeably
slow as well but still functional. ap-east-1 is taking 20 minutes just to
list the root directory from Windows Explorer, and failing more often than
not.
Possibly related, there is a very large copy job going on in us-east-1. We
are running a global filesystem using ctdb to synchronize locks. Last I
checked there were more than 200 locks held and it took nearly three
minutes to run `smbstatus -L`
Any advice is appreciated.
- isaac
