Upgrade to Samba 4.16.11: cannot login as local user when joined to AD

I Recently upgraded from Samba 4.13 to 4.16.11 on a FreeBSD stable 13.2 platform.
When I join a domain there is a brief period in which I can log on as myself as a local unix user via ssh, but after an indeterminate period all such attempts fail.
When the login attempts fail, a prompt does not appear for over 60 seconds by which time it is too late to enter the password (ssh gives up).
My pam configuration has not changed; my basic samba installation/configuration has not changed since before 4.13

I have noticed that when I can login there are 2 rpcd_lsad processes running:
Then something goes wrong and the number of rpcd_lsad processes keeps slowly increasing (seemingly topping out at 9) and I can no longer login.

The logs show (with increased verbosity):
Code:
winbindd[27192]: [2023/08/25 17:24:48.625595,  0] ../../source3/winbindd/winbindd.c:1061(winbind_client_processed)
winbindd[27192]:   winbind_client_processed: request took 61.112610 seconds
winbindd[27192]:   [struct process_request_state] ../../source3/winbindd/winbindd.c:675 [2023/08/25 17:23:47.512964] ../../source3/winbindd/winbindd.c:856 [2023/08/25 17:24
:48.625574] [61.112610] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:    [struct winbindd_getpwnam_state] ../../source3/winbindd/winbindd_getpwnam.c:50 [2023/08/25 17:23:47.512967] ../../source3/winbindd/winbindd_getpwnam.c:107 [2023/08/25 17:24:48.625525] [61.112558] -> TEVENT_REQ_USER_ERROR (3 10483072397370982581))
winbindd[27192]:     [struct wb_lookupname_state] ../../source3/winbindd/wb_lookupname.c:47 [2023/08/25 17:23:47.512972] ../../source3/winbindd/wb_lookupname.c:95 [2023/08/25 17:24:48.625523] [61.112551] -> TEVENT_REQ_USER_ERROR (3 10483072397370982581))
winbindd[27192]:      [struct dcerpc_wbint_LookupName_state] librpc/gen_ndr/ndr_winbind_c.c:781 [2023/08/25 17:23:47.512978] librpc/gen_ndr/ndr_winbind_c.c:847 [2023/08/25 17:24:48.625521] [61.112543] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:       [struct dcerpc_wbint_LookupName_r_state] librpc/gen_ndr/ndr_winbind_c.c:693 [2023/08/25 17:23:47.512979] librpc/gen_ndr/ndr_winbind_c.c:727 [2023/08/25 17:24:48.625519] [61.112540] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:        [struct dcerpc_binding_handle_call_state] ../../librpc/rpc/binding_handle.c:371 [2023/08/25 17:23:47.512981] ../../librpc/rpc/binding_handle.c:520 [2023/08/25 17:24:48.625516] [61.112535] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:         [struct dcerpc_binding_handle_raw_call_state] ../../librpc/rpc/binding_handle.c:149 [2023/08/25 17:23:47.512986] ../../librpc/rpc/binding_handle.c:203 [2023/08/25 17:24:48.625506] [61.112520] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:          [struct wbint_bh_raw_call_state] ../../source3/winbindd/winbindd_dual_ndr.c:93 [2023/08/25 17:23:47.512988] ../../source3/winbindd/winbindd_dual_ndr.c:208 [2023/08/25 17:24:48.625503] [61.112515] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:           [struct wb_domain_request_state] ../../source3/winbindd/winbindd_dual.c:499 [2023/08/25 17:23:47.512991] ../../source3/winbindd/winbindd_dual.c:734 [2023/08/25 17:24:48.625486] [61.112495] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:            [struct wb_child_request_state] ../../source3/winbindd/winbindd_dual.c:198 [2023/08/25 17:24:28.171657] ../../source3/winbindd/winbindd_dual.c:298 [2023/08/25 17:24:48.625484] [20.453827] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:             [struct tevent_queue_wait_state] ../../tevent_queue.c:350 [2023/08/25 17:24:28.171660] ../../tevent_queue.c:369 [2023/08/25 17:24:28.171683] [0.000023] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:             [struct wb_simple_trans_state] ../../nsswitch/wb_reqtrans.c:375 [2023/08/25 17:24:28.171684] ../../nsswitch/wb_reqtrans.c:432 [2023/08/25 17:24:48.625479] [20.453795] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:              [struct req_write_state] ../../nsswitch/wb_reqtrans.c:158 [2023/08/25 17:24:28.171685] ../../nsswitch/wb_reqtrans.c:194 [2023/08/25 17:24:28.171706] [0.000021] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:               [struct writev_state] ../../lib/async_req/async_sock.c:267 [2023/08/25 17:24:28.171685] ../../lib/async_req/async_sock.c:373 [2023/08/25 17:24:28.171704] [0.000019] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:              [struct resp_read_state] ../../nsswitch/wb_reqtrans.c:222 [2023/08/25 17:24:28.171707] ../../nsswitch/wb_reqtrans.c:275 [2023/08/25 17:24:48.625478] [20.453771] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:               [struct read_packet_state] ../../lib/async_req/async_sock.c:480 [2023/08/25 17:24:28.171707] ../../lib/async_req/async_sock.c:568 [2023/08/25 17:24:48.625474] [20.453767] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:    [struct resp_write_state] ../../nsswitch/wb_reqtrans.c:307 [2023/08/25 17:24:48.625531] ../../nsswitch/wb_reqtrans.c:344 [2023/08/25 17:24:48.625572] [0.000041] -> TEVENT_REQ_DONE (2 0))
winbindd[27192]:     [struct writev_state] ../../lib/async_req/async_sock.c:267 [2023/08/25 17:24:48.625550] ../../lib/async_req/async_sock.c:373 [2023/08/25 17:24:48.625562] [0.000012] -> TEVENT_REQ_DONE (2 0))

When I am able to login, pam_winbind shows the following and pam_unix lets me login:

sshd[30355]: pam_winbind(sshd): request wbcLogonUser failed: WBC_ERR_AUTH_ERROR, PAM error: PAM_USER_UNKNOWN (13), NTSTATUS: NT_STATUS_NO_SUCH_USER, Error message was: The specified account does not exist.


I am at a loss; any hints or clues are appreciated
 
Last edited by a moderator:
Yes, I have tried the latest samba 4.16.11 that includes PR 272514. Unfortunately, no difference.
 
Back
Top