Bug 14789 - winbind panic when trying to parse expired wcache entry
Summary: winbind panic when trying to parse expired wcache entry
Status: NEW
Alias: None
Product: Samba 4.1 and newer
Classification: Unclassified
Component: Winbind (show other bugs)
Version: 4.12.14
Hardware: All All
: P5 normal (vote)
Target Milestone: ---
Assignee: Samba QA Contact
QA Contact: Samba QA Contact
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-08-08 15:39 UTC by Lev
Modified: 2021-08-08 15:39 UTC (History)
0 users

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Lev 2021-08-08 15:39:27 UTC
winbind_cache.tdb contains very old entry, created yet by samba 4.6:

# tdbdump -k "U/S-1-5-21-1546016247-1299368408-480117447-6366" winbindd_cache.tdb
\00\00\00\00\EA<\94\04\AF\D8\F5^\00\00\00\00\11<username>\FF\0B/home/%D/%U\0A/bin/false\FF\FF\FF\FF-S-1-5-21-1546016247-1299368408-480117447-6366,S-1-5-21-1546016247-1299368408-480117447-513

In https://github.com/samba-team/samba/commit/d0f1d761b5765df8525f991554ffd333d4a247d6 format of the "U/<SID>" entries has changed, new fields were added.

Normally this cache entry is expired after winbind cache time (default = 5min), so usually this is not a problem.

However, if domain->sequence_number is DOM_SEQUENCE_NONE, centry_expired() returns True, and wcache_query_user() tries to parse old entry using new format, and fails.

(gdb) bt
#0  0x00007fe495775f47 in __nptl_clear_internal_signals (set=0x7ffcb996ab50) at ../sysdeps/unix/sysv/linux/nptl-signals.h:49
#1  __libc_signal_block_app (set=0x7ffcb996ab50) at ../sysdeps/unix/sysv/linux/nptl-signals.h:69
#2  __GI_raise (sig=0) at ../sysdeps/unix/sysv/linux/raise.c:40
#3  0x00007fe4957778b1 in __GI_abort () at abort.c:104
#4  0x00007fe49a6eeb58 in dump_core () at ../../source3/lib/dumpcore.c:338
#5  0x00007fe49a6de449 in smb_panic_s3 (why=0x555e6e57472c "centry_string") at ../../source3/lib/util.c:861
#6  0x00007fe49e3cda31 in smb_panic (why=0x555e6e57472c "centry_string") at ../../lib/util/fault.c:174
#7  0x0000555e6e4ba99a in centry_string (centry=0x7fe4844c1260, mem_ctx=0x7fe4844c58e0) at ../../source3/winbindd/winbindd_cache.c:321
#8  0x0000555e6e4bab6a in centry_sid (centry=0x7fe4844c1260, sid=0x7ffcb996b020) at ../../source3/winbindd/winbindd_cache.c:371
#9  0x0000555e6e4c0418 in wcache_query_user (domain=0x7fe484441260, mem_ctx=0x7fe484465860, user_sid=0x7ffcb996b180, info=0x7ffcb996afe0) at ../../source3/winbindd/winbindd_cache.c:2305
#10 0x0000555e6e4c0527 in wcache_query_user_fullname (domain=0x7fe484441260, mem_ctx=0x7fe484465860, user_sid=0x7ffcb996b180, full_name=0x7fe4844658a8) at ../../source3/winbindd/winbindd_cache.c:2335
#11 0x0000555e6e4cf2ca in winbind_dual_SamLogon (domain=0x7fe484441260, mem_ctx=0x7fe4844c58e0, interactive=false, logon_parameters=2080, name_user=0x7ffcb996b754 "juliano.schneiker", name_domain=0x7ffcb996b854 "LILIUM", 
    workstation=0x7ffcb996bb5c "DE-C-W25", logon_id=9431387616283419405, client_name=0x7ffcb996b728 "nss_winbind", client_pid=32467, chal=0x7ffcb996b748 "\251Y\266\202cM\274G \b", lm_response=..., nt_response=..., remote=0x7fe48448a6e0, 
    local=0x7fe48448aa60, authoritative=0x7ffcb996b285 "\001\006", skip_sam=false, flags=0x7ffcb996b28c, _validation_level=0x7ffcb996b286, _validation=0x7ffcb996b290) at ../../source3/winbindd/winbindd_pam.c:2618
#12 0x0000555e6e4cf8de in winbindd_dual_pam_auth_crap (domain=0x7fe484441260, state=0x7ffcb996b578) at ../../source3/winbindd/winbindd_pam.c:2720
#13 0x0000555e6e4edf4d in child_process_request (child=0x7fe48452c660, state=0x7ffcb996b578) at ../../source3/winbindd/winbindd_dual.c:771
#14 0x0000555e6e4f0878 in child_handler (ev=0x7fe48446e560, fde=0x7fe4844c9200, flags=1, private_data=0x7ffcb996b570) at ../../source3/winbindd/winbindd_dual.c:1664
#15 0x00007fe49cf8d085 in tevent_common_invoke_fd_handler (fde=0x7fe4844c9200, flags=1, removed=0x0) at ../../lib/tevent/tevent_fd.c:138
#16 0x00007fe49cf97aec in epoll_event_loop (epoll_ev=0x7fe48442c580, tvalp=0x7ffcb996b460) at ../../lib/tevent/tevent_epoll.c:736
#17 0x00007fe49cf981cf in epoll_event_loop_once (ev=0x7fe48446e560, location=0x555e6e58a078 "../../source3/winbindd/winbindd_dual.c:1883") at ../../lib/tevent/tevent_epoll.c:937
#18 0x00007fe49cf94931 in std_event_loop_once (ev=0x7fe48446e560, location=0x555e6e58a078 "../../source3/winbindd/winbindd_dual.c:1883") at ../../lib/tevent/tevent_standard.c:110
#19 0x00007fe49cf8c2a4 in _tevent_loop_once (ev=0x7fe48446e560, location=0x555e6e58a078 "../../source3/winbindd/winbindd_dual.c:1883") at ../../lib/tevent/tevent.c:772
#20 0x0000555e6e4f1440 in fork_domain_child (child=0x7fe48452c660) at ../../source3/winbindd/winbindd_dual.c:1883
#21 0x0000555e6e4eca86 in wb_child_request_waited (subreq=0x0) at ../../source3/winbindd/winbindd_dual.c:263
#22 0x00007fe49cf8e91e in _tevent_req_notify_callback (req=0x7fe4844d6200, location=0x7fe49cf98868 "../../lib/tevent/tevent_queue.c:355") at ../../lib/tevent/tevent_req.c:141
#23 0x00007fe49cf8ea7f in tevent_req_finish (req=0x7fe4844d6200, state=TEVENT_REQ_DONE, location=0x7fe49cf98868 "../../lib/tevent/tevent_queue.c:355") at ../../lib/tevent/tevent_req.c:193
#24 0x00007fe49cf8eaac in _tevent_req_done (req=0x7fe4844d6200, location=0x7fe49cf98868 "../../lib/tevent/tevent_queue.c:355") at ../../lib/tevent/tevent_req.c:199
#25 0x00007fe49cf8e2af in tevent_queue_wait_trigger (req=0x7fe4844d6200, private_data=0x0) at ../../lib/tevent/tevent_queue.c:355
#26 0x00007fe49cf8dcbd in tevent_queue_immediate_trigger (ev=0x7fe48446e560, im=0x7fe48452c7e0, private_data=0x7fe48442dde0) at ../../lib/tevent/tevent_queue.c:149
#27 0x00007fe49cf8d812 in tevent_common_invoke_immediate_handler (im=0x7fe48452c7e0, removed=0x0) at ../../lib/tevent/tevent_immediate.c:166
#28 0x00007fe49cf8d918 in tevent_common_loop_immediate (ev=0x7fe48446e560) at ../../lib/tevent/tevent_immediate.c:203
#29 0x00007fe49cf98135 in epoll_event_loop_once (ev=0x7fe48446e560, location=0x555e6e56a9d0 "../../source3/winbindd/winbindd.c:1949") at ../../lib/tevent/tevent_epoll.c:918
#30 0x00007fe49cf94931 in std_event_loop_once (ev=0x7fe48446e560, location=0x555e6e56a9d0 "../../source3/winbindd/winbindd.c:1949") at ../../lib/tevent/tevent_standard.c:110
#31 0x00007fe49cf8c2a4 in _tevent_loop_once (ev=0x7fe48446e560, location=0x555e6e56a9d0 "../../source3/winbindd/winbindd.c:1949") at ../../lib/tevent/tevent.c:772
#32 0x0000555e6e4a4122 in main (argc=3, argv=0x7ffcb996d448) at ../../source3/winbindd/winbindd.c:1949

(gdb) f 9
#9  0x0000555e6e4c0418 in wcache_query_user (domain=0x7fe484441260, mem_ctx=0x7fe484465860, user_sid=0x7ffcb996b180, info=0x7ffcb996afe0) at ../../source3/winbindd/winbindd_cache.c:2305
2305    ../../source3/winbindd/winbindd_cache.c: No such file or directory.

(gdb) p domain->online
$3 = true
(gdb) p domain->sequence_number
$4 = 4294967295

(gdb) p *centry
$5 = {
  status = {
    v = 0
  }, 
  sequence_number = 76823786, 
  timeout = 1593170095,            <---- Fri, 26 Jun 2020 11:14:55 GMT
  data = 0x7fe4845862e0 "", 
  len = 153, 
  ofs = 122
}

(gdb) p *info
$6 = {
  domain_name = 0x7fe48448ab60 "<username>", 
  acct_name = 0x0, 
  full_name = 0x7fe484489a40 "/home/%D/%U", 
  homedir = 0x7fe484489ab0 "/bin/false", 
  shell = 0x0, 
  uid = 771751935, 
  primary_gid = 758197587, 
  primary_group_name = 0x7fe4845863e0 "-21-1546016247-1299368408-480117447-6366,S-1-5-21-154", 
  user_sid = {
    sid_rev_num = 224 '\340', 
    num_auths = -45 '\323', 
    id_auth = "R\204\344\177\000", 
    sub_auths = {2336, 0, 0, 0, 0, 2961362203, 1441812, 32764, 2220271360, 32740, 917516, 32764, 2220382208, 32740, 2220023776}
  }, 
  group_sid = {
    sid_rev_num = 228 '\344', 
    num_auths = 127 '\177', 
    id_auth = "\000\000\000\000\000", 
    sub_auths = {0, 16, 0, 0, 0, 0, 0, 0, 0, 6, 0, 2220025696, 32740, 2220026272, 32740}
  }
}


[2021/08/04 05:45:00.444649,  1, pid=17348] ../../source3/libads/ldap.c:565(ads_find_dc)
  ads_find_dc: name resolution for realm '<realm>' (domain '<DOMAIN>') failed: NT_STATUS_NO_LOGON_SERVERS
[2021/08/04 05:45:00.463066,  1, pid=17348] ../../source3/libads/ldap.c:565(ads_find_dc)
  ads_find_dc: name resolution for realm '<realm>' (domain '<DOMAIN>') failed: NT_STATUS_NO_LOGON_SERVERS
[2021/08/04 05:45:00.463125,  1, pid=17348, class=winbind] ../../source3/winbindd/winbindd_ads.c:152(ads_cached_connection_connect)
  ads_connect for domain <DOMAIN> failed: No logon servers are currently available to service the logon request.
[2021/08/04 05:45:00.463158,  0, pid=17348, class=winbind] ../../source3/winbindd/winbindd_cache.c:217(centry_check_bytes)
  centry corruption? needed 54 bytes, have 31
[2021/08/04 05:45:00.463187,  0, pid=17348] ../../source3/lib/util.c:830(smb_panic_s3)
  PANIC (pid 17348): centry_string