Attachment 9983 Details for Bug 45840 – debug-bug45840.log

debug-bug45840.log

debug-bug45840.log (text/x-log), 68.42 KB, created by Arvid Requate on 2019-04-18 13:05:02 CEST

(hide)

Description:

Filename:

MIME Type:

Creator: Arvid Requate

Created: 2019-04-18 13:05:02 CEST

Size: 68.42 KB

patch

obsolete

>root@member13:~# net rpc testjoin 
>Join to 'AR41I1' is OK
>root@member13:~# ucr set samba/debug/level='10'
>Setting samba/debug/level
>Multifile: /etc/samba/smb.conf
>root@member13:~# net cache flush; /etc/init.d/winbind restart
>[ ok ] Restarting winbind (via systemctl): winbind.service.
>root@member13:~# tail -f /var/log/samba/log.w* &
>[1] 27726
>root@member13:~# ==> /var/log/samba/log.wb-AR41I1 <==
>[2019/02/27 16:12:55.132094, 10, pid=27724, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cache.c:4396(pack_tdc_domains)
>  pack_tdc_domains: Packing domain BUILTIN (UNKNOWN)
>[2019/02/27 16:12:55.132112, 10, pid=27724, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cache.c:4396(pack_tdc_domains)
>  pack_tdc_domains: Packing domain MEMBER13 (UNKNOWN)
>[2019/02/27 16:12:55.132129, 10, pid=27724, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cache.c:4396(pack_tdc_domains)
>  pack_tdc_domains: Packing domain AR41I1 (ar41i1.qa)
>[2019/02/27 16:12:55.132166,  4, pid=27724, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1605(child_handler)
>  Finished processing child request 20
>[2019/02/27 16:12:55.132184, 10, pid=27724, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:154(child_write_response)
>  Writing 4074 bytes to parent
>
>==> /var/log/samba/log.wb-BUILTIN <==
>
>==> /var/log/samba/log.wb-MEMBER13 <==
>[2015/11/25 02:41:22.659256,  0] ../source3/winbindd/winbindd.c:271(winbindd_sig_term_handler)
>  Got sig[15] terminate (is_parent=0)
>
>==> /var/log/samba/log.winbindd <==
>[2019/02/27 16:12:58.563621, 10, pid=27706, effective(0, 0), real(0, 0)] ../../source4/lib/messaging/messaging.c:684(imessaging_dgm_recv)
>  imessaging_dgm_recv: dst 27706 matches my id: 27706, type=0x406
>[2019/02/27 16:12:58.563659, 10, pid=27706, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:429(messaging_recv_cb)
>  messaging_recv_cb: Received message 0x406 len 7 (num_fds:0) from 27725
>[2019/02/27 16:12:58.563680,  5, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cm.c:163(msg_try_to_go_online)
>  msg_try_to_go_online: received for domain AR41I1.
>[2019/02/27 16:12:58.563701,  5, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cm.c:175(msg_try_to_go_online)
>  msg_try_to_go_online: domain AR41I1 already online.
>[2019/02/27 16:12:58.564388,  5, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:827(winbind_child_died)
>  Already reaped child 27725 died
>
>==> /var/log/samba/log.winbindd-dc-connect <==
>[2019/02/27 16:12:58.563457,  4, pid=27725, effective(0, 0), real(0, 0)] ../../source3/libsmb/namequery.c:3257(get_dc_list)
>  get_dc_list: returning 2 ip addresses in an ordered list
>[2019/02/27 16:12:58.563476,  4, pid=27725, effective(0, 0), real(0, 0)] ../../source3/libsmb/namequery.c:3258(get_dc_list)
>  get_dc_list: 10.200.8.10:389 10.200.8.11:389 
>[2019/02/27 16:12:58.563500,  9, pid=27725, effective(0, 0), real(0, 0)] ../../source3/libsmb/conncache.c:151(check_negative_conn_cache)
>  check_negative_conn_cache returning result 0 for domain AR41I1 server 10.200.8.10
>[2019/02/27 16:12:58.563524,  9, pid=27725, effective(0, 0), real(0, 0)] ../../source3/libsmb/conncache.c:151(check_negative_conn_cache)
>  check_negative_conn_cache returning result 0 for domain AR41I1 server 10.200.8.11
>[2019/02/27 16:12:58.563575, 10, pid=27725, effective(0, 0), real(0, 0)] ../../source3/lib/messages_dgm.c:1436(messaging_dgm_send)
>  messaging_dgm_send: Sending message to 27706
>
>==> /var/log/samba/log.winbindd-idmap <==
>
>root@member13:~# univention-ldapsearch -LLL sambasid=S-1-5-9 gidNumber
>dn: cn=Enterprise Domain Controllers,cn=groups,dc=ar41i1,dc=qa
>gidNumber: 5015
>
>root@member13:~# wbinfo --sid-to-gid S-1-5-9
>
>==> /var/log/samba/log.winbindd <==
>[2019/02/27 16:14:04.150340,  6, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd.c:920(new_connection)
>  accepted socket 22
>[2019/02/27 16:14:04.150794, 10, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd.c:768(process_request_send)
>  process_request_send: process_request: request fn INTERFACE_VERSION
>[2019/02/27 16:14:04.150825,  3, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_misc.c:432(winbindd_interface_version)
>  winbindd_interface_version: [wbinfo (27735)]: request interface version (version = 31)
>[2019/02/27 16:14:04.150893, 10, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd.c:854(process_request_written)
>  process_request_written: [wbinfo(27735):unknown request]: delivered response to client
>[2019/02/27 16:14:04.151169, 10, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd.c:744(process_request_send)
>  process_request_send: process_request: Handling async request wbinfo(27735):SIDS_TO_XIDS
>[2019/02/27 16:14:04.151209,  3, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_sids_to_xids.c:50(winbindd_sids_to_xids_send)
>  sids_to_xids
>[2019/02/27 16:14:04.151236, 10, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_sids_to_xids.c:68(winbindd_sids_to_xids_send)
>  num_sids: 1
>[2019/02/27 16:14:04.151258, 10, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/wb_sids2xids.c:114(wb_sids2xids_send)
>  SID 0: S-1-5-9
>[2019/02/27 16:14:04.151306,  5, pid=27706, effective(0, 0), real(0, 0), class=tdb] ../../source3/lib/gencache.c:85(gencache_init)
>  Opening cache file at /var/run/samba/gencache.tdb
>[2019/02/27 16:14:04.151403, 10, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/wb_lookupsids.c:263(wb_lookupsids_bulk)
>  wb_lookupsids_bulk: No bulk setup for SID S-1-5-9 with 1 subauths
>[2019/02/27 16:14:04.151428, 10, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_util.c:1462(find_lookup_domain_from_sid)
>  find_lookup_domain_from_sid: SID [S-1-5-9]
>[2019/02/27 16:14:04.151477,  1, pid=27706, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       wbint_LookupSid: struct wbint_LookupSid
>          in: struct wbint_LookupSid
>              sid                      : *
>                  sid                      : S-1-5-9
>[2019/02/27 16:14:04.151578, 10, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1628(fork_domain_child)
>  fork_domain_child called for domain 'BUILTIN'
>[2019/02/27 16:14:04.152523, 10, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1694(fork_domain_child)
>  Child process 27736
>[2019/02/27 16:14:04.153104, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages_dgm_ref.c:163(msg_dgm_ref_destructor)
>  msg_dgm_ref_destructor: refs=0x55771683f920
>[2019/02/27 16:14:04.153249, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages_dgm_ref.c:80(messaging_dgm_ref)
>  messaging_dgm_ref: messaging_dgm_init returned Erfolg
>[2019/02/27 16:14:04.153281, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages_dgm_ref.c:109(messaging_dgm_ref)
>  messaging_dgm_ref: unique = 16235266519524950486
>[2019/02/27 16:14:04.153314,  5, pid=27736, effective(0, 0), real(0, 0), class=passdb] ../../source3/passdb/pdb_interface.c:155(make_pdb_method_name)
>  Attempting to find a passdb backend to match tdbsam (tdbsam)
>[2019/02/27 16:14:04.153336,  5, pid=27736, effective(0, 0), real(0, 0), class=passdb] ../../source3/passdb/pdb_interface.c:176(make_pdb_method_name)
>  Found pdb backend tdbsam
>[2019/02/27 16:14:04.153371,  5, pid=27736, effective(0, 0), real(0, 0), class=passdb] ../../source3/passdb/pdb_interface.c:187(make_pdb_method_name)
>  pdb backend tdbsam has a valid init
>[2019/02/27 16:14:04.153436,  5, pid=27736, effective(0, 0), real(0, 0)] ../../lib/util/debug.c:800(debug_dump_status)
>  INFO: Current debug levels:
>    all: 10
>    tdb: 10
>    printdrivers: 10
>    lanman: 10
>    smb: 10
>    rpc_parse: 10
>    rpc_srv: 10
>    rpc_cli: 10
>    passdb: 10
>    sam: 10
>    auth: 10
>    winbind: 10
>    vfs: 10
>    idmap: 10
>    quota: 10
>    acls: 10
>    locking: 10
>    msdfs: 10
>    dmapi: 10
>    registry: 10
>    scavenger: 10
>    dns: 10
>    ldb: 10
>    tevent: 10
>    auth_audit: 10
>    auth_json_audit: 10
>    kerberos: 10
>    drs_repl: 10
>    smb2: 10
>    smb2_credits: 10
>    dsdb_audit: 10
>    dsdb_json_audit: 10
>    dsdb_password_audit: 10
>    dsdb_password_json_audit: 10
>    dsdb_transaction_audit: 10
>    dsdb_transaction_json_audit: 10
>    dsdb_group_audit: 10
>    dsdb_group_json_audit: 10
>
>==> /var/log/samba/log.wb-BUILTIN <==
>[2019/02/27 16:14:04.153701,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 33 - private_data=(nil)
>[2019/02/27 16:14:04.153732,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 13 - private_data=(nil)
>[2019/02/27 16:14:04.153750,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1028 - private_data=(nil)
>[2019/02/27 16:14:04.153768,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1027 - private_data=(nil)
>[2019/02/27 16:14:04.153798,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1029 - private_data=(nil)
>[2019/02/27 16:14:04.153815,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1033 - private_data=(nil)
>[2019/02/27 16:14:04.153831,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1 - private_data=(nil)
>[2019/02/27 16:14:04.153861,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1036 - private_data=(nil)
>[2019/02/27 16:14:04.153879,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1035 - private_data=(nil)
>[2019/02/27 16:14:04.153994,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:698(messaging_register)
>  Registering messaging pointer for type 1028 - private_data=(nil)
>[2019/02/27 16:14:04.154018,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:698(messaging_register)
>  Registering messaging pointer for type 1027 - private_data=(nil)
>[2019/02/27 16:14:04.154036,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:698(messaging_register)
>  Registering messaging pointer for type 1 - private_data=(nil)
>[2019/02/27 16:14:04.154054,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:698(messaging_register)
>  Registering messaging pointer for type 1034 - private_data=(nil)
>[2019/02/27 16:14:04.154071,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:713(messaging_register)
>  Overriding messaging pointer for type 1034 - private_data=(nil)
>[2019/02/27 16:14:04.154088,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:698(messaging_register)
>  Registering messaging pointer for type 1038 - private_data=(nil)
>[2019/02/27 16:14:04.154105,  5, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:713(messaging_register)
>  Overriding messaging pointer for type 1038 - private_data=(nil)
>[2019/02/27 16:14:04.154148,  4, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1597(child_handler)
>  child daemon request 48
>[2019/02/27 16:14:04.154172, 10, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:744(child_process_request)
>  child_process_request: request fn INIT_CONNECTION
>[2019/02/27 16:14:04.154194,  5, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_util.c:806(winbindd_dual_init_connection)
>  winbindd_dual_init_connection: BUILTIN returning without initialization online = 1
>[2019/02/27 16:14:04.154220,  4, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1605(child_handler)
>  Finished processing child request 48
>[2019/02/27 16:14:04.154238, 10, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:154(child_write_response)
>  Writing 4008 bytes to parent
>[2019/02/27 16:14:04.154368, 10, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:119(child_read_request)
>  Need to read 12 extra bytes
>[2019/02/27 16:14:04.154393,  4, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1597(child_handler)
>  child daemon request 56
>[2019/02/27 16:14:04.154410, 10, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:744(child_process_request)
>  child_process_request: request fn NDRCMD
>[2019/02/27 16:14:04.154427, 10, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual_ndr.c:362(winbindd_dual_ndrcmd)
>  winbindd_dual_ndrcmd: Running command WBINT_LOOKUPSID (BUILTIN)
>[2019/02/27 16:14:04.154461,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       wbint_LookupSid: struct wbint_LookupSid
>          in: struct wbint_LookupSid
>              sid                      : *
>                  sid                      : S-1-5-9
>[2019/02/27 16:14:04.154554, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/lib/namemap_cache.c:163(namemap_cache_find_sid)
>  namemap_cache_find_sid: gencache_parse(SID2NAME/S-1-5-9) failed
>[2019/02/27 16:14:04.154574, 10, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cache.c:1910(wcache_sid_to_name)
>  wcache_sid_to_name: namemap_cache_find_name failed
>[2019/02/27 16:14:04.154592, 10, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cache.c:1958(wb_cache_sid_to_name)
>  sid_to_name: [Cached] - doing backend query for name for domain BUILTIN
>[2019/02/27 16:14:04.154612,  3, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_samr.c:659(sam_sid_to_name)
>  sam_sid_to_name
>[2019/02/27 16:14:04.154734,  4, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_ncacn_np.c:221(make_internal_rpc_pipe_p)
>  Create pipe requested samr
>[2019/02/27 16:14:04.154761, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:223(init_pipe_handles)
>  init_pipe_handle_list: created handle list for pipe samr
>[2019/02/27 16:14:04.154780, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:240(init_pipe_handles)
>  init_pipe_handle_list: pipe_handles ref count = 1 for pipe samr
>[2019/02/27 16:14:04.154871,  4, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_ncacn_np.c:261(make_internal_rpc_pipe_p)
>  Created internal pipe samr
>[2019/02/27 16:14:04.154948,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       samr_Connect2: struct samr_Connect2
>          in: struct samr_Connect2
>              system_name              : NULL
>              access_mask              : 0x02000000 (33554432)
>                     0: SAMR_ACCESS_CONNECT_TO_SERVER
>                     0: SAMR_ACCESS_SHUTDOWN_SERVER
>                     0: SAMR_ACCESS_INITIALIZE_SERVER
>                     0: SAMR_ACCESS_CREATE_DOMAIN
>                     0: SAMR_ACCESS_ENUM_DOMAINS 
>                     0: SAMR_ACCESS_LOOKUP_DOMAIN
>[2019/02/27 16:14:04.155037,  5, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/samr/srv_samr_nt.c:3889(_samr_Connect2)
>  _samr_Connect2: 3889
>[2019/02/27 16:14:04.155063, 10, pid=27736, effective(0, 0), real(0, 0)] ../../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0xb0000000 to 0x000f003f
>[2019/02/27 16:14:04.155085,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:95(access_check_object)
>  _samr_Connect2: ACCESS should be DENIED  (requested: 0x000f003f)
>  but overritten by euid == initial uid
>[2019/02/27 16:14:04.155108,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:117(access_check_object)
>  _samr_Connect2: access GRANTED (requested: 0x000f003f, granted: 0x000f003f)
>[2019/02/27 16:14:04.155136,  6, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:304(create_rpc_handle_internal)
>  Opened policy hnd[1] [0000] 00 00 00 00 01 00 00 00   00 00 00 00 76 5C 3C A9   ........ ....v\<.
>  [0010] 58 6C 00 00                                        Xl.. 
>[2019/02/27 16:14:04.155173,  5, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/samr/srv_samr_nt.c:3918(_samr_Connect2)
>  _samr_Connect2: 3918
>[2019/02/27 16:14:04.155191,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       samr_Connect2: struct samr_Connect2
>          out: struct samr_Connect2
>              connect_handle           : *
>                  connect_handle: struct policy_handle
>                      handle_type              : 0x00000000 (0)
>                      uuid                     : 00000001-0000-0000-765c-3ca9586c0000
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.155312,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       samr_OpenDomain: struct samr_OpenDomain
>          in: struct samr_OpenDomain
>              connect_handle           : *
>                  connect_handle: struct policy_handle
>                      handle_type              : 0x00000000 (0)
>                      uuid                     : 00000001-0000-0000-765c-3ca9586c0000
>              access_mask              : 0x02000000 (33554432)
>                     0: SAMR_DOMAIN_ACCESS_LOOKUP_INFO_1
>                     0: SAMR_DOMAIN_ACCESS_SET_INFO_1
>                     0: SAMR_DOMAIN_ACCESS_LOOKUP_INFO_2
>                     0: SAMR_DOMAIN_ACCESS_SET_INFO_2
>                     0: SAMR_DOMAIN_ACCESS_CREATE_USER
>                     0: SAMR_DOMAIN_ACCESS_CREATE_GROUP
>                     0: SAMR_DOMAIN_ACCESS_CREATE_ALIAS
>                     0: SAMR_DOMAIN_ACCESS_LOOKUP_ALIAS
>                     0: SAMR_DOMAIN_ACCESS_ENUM_ACCOUNTS
>                     0: SAMR_DOMAIN_ACCESS_OPEN_ACCOUNT
>                     0: SAMR_DOMAIN_ACCESS_SET_INFO_3
>              sid                      : *
>                  sid                      : S-1-5-32
>[2019/02/27 16:14:04.155432,  6, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:339(find_policy_by_hnd_internal)
>  Found policy hnd[0] [0000] 00 00 00 00 01 00 00 00   00 00 00 00 76 5C 3C A9   ........ ....v\<.
>  [0010] 58 6C 00 00                                        Xl.. 
>[2019/02/27 16:14:04.155466, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:523(_policy_handle_find)
>  found handle of type struct samr_connect_info
>[2019/02/27 16:14:04.155485, 10, pid=27736, effective(0, 0), real(0, 0)] ../../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0xb0000000 to 0x000f07ff
>[2019/02/27 16:14:04.155503,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:84(access_check_object)
>  access_check_object: user rights access mask [0x3f0]
>[2019/02/27 16:14:04.155520,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:95(access_check_object)
>  _samr_OpenDomain: ACCESS should be DENIED  (requested: 0x000f040f)
>  but overritten by euid == initial uid
>[2019/02/27 16:14:04.155540,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:117(access_check_object)
>  _samr_OpenDomain: access GRANTED (requested: 0x000f040f, granted: 0x000f07ff)
>[2019/02/27 16:14:04.155573,  6, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:304(create_rpc_handle_internal)
>  Opened policy hnd[2] [0000] 00 00 00 00 02 00 00 00   00 00 00 00 76 5C 3C A9   ........ ....v\<.
>  [0010] 58 6C 00 00                                        Xl.. 
>[2019/02/27 16:14:04.155607,  5, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/samr/srv_samr_nt.c:506(_samr_OpenDomain)
>  _samr_OpenDomain: 506
>[2019/02/27 16:14:04.155643,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       samr_OpenDomain: struct samr_OpenDomain
>          out: struct samr_OpenDomain
>              domain_handle            : *
>                  domain_handle: struct policy_handle
>                      handle_type              : 0x00000000 (0)
>                      uuid                     : 00000002-0000-0000-765c-3ca9586c0000
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.155717,  4, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_ncacn_np.c:221(make_internal_rpc_pipe_p)
>  Create pipe requested lsarpc
>[2019/02/27 16:14:04.155741, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:240(init_pipe_handles)
>  init_pipe_handle_list: pipe_handles ref count = 2 for pipe lsarpc
>[2019/02/27 16:14:04.155777,  4, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_ncacn_np.c:261(make_internal_rpc_pipe_p)
>  Created internal pipe lsarpc
>[2019/02/27 16:14:04.155830,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       lsa_OpenPolicy: struct lsa_OpenPolicy
>          in: struct lsa_OpenPolicy
>              system_name              : *
>                  system_name              : 0x005c (92)
>              attr                     : *
>                  attr: struct lsa_ObjectAttribute
>                      len                      : 0x00000018 (24)
>                      root_dir                 : NULL
>                      object_name              : NULL
>                      attributes               : 0x00000000 (0)
>                      sec_desc                 : NULL
>                      sec_qos                  : *
>                          sec_qos: struct lsa_QosInfo
>                              len                      : 0x0000000c (12)
>                              impersonation_level      : 0x0002 (2)
>                              context_mode             : 0x01 (1)
>                              effective_only           : 0x00 (0)
>              access_mask              : 0x02000000 (33554432)
>                     0: LSA_POLICY_VIEW_LOCAL_INFORMATION
>                     0: LSA_POLICY_VIEW_AUDIT_INFORMATION
>                     0: LSA_POLICY_GET_PRIVATE_INFORMATION
>                     0: LSA_POLICY_TRUST_ADMIN   
>                     0: LSA_POLICY_CREATE_ACCOUNT
>                     0: LSA_POLICY_CREATE_SECRET 
>                     0: LSA_POLICY_CREATE_PRIVILEGE
>                     0: LSA_POLICY_SET_DEFAULT_QUOTA_LIMITS
>                     0: LSA_POLICY_SET_AUDIT_REQUIREMENTS
>                     0: LSA_POLICY_AUDIT_LOG_ADMIN
>                     0: LSA_POLICY_SERVER_ADMIN  
>                     0: LSA_POLICY_LOOKUP_NAMES  
>                     0: LSA_POLICY_NOTIFICATION  
>[2019/02/27 16:14:04.156026, 10, pid=27736, effective(0, 0), real(0, 0)] ../../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0xb0000000 to 0x000f1fff
>[2019/02/27 16:14:04.156051,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:95(access_check_object)
>  _lsa_OpenPolicy2: ACCESS should be DENIED  (requested: 0x000f1fff)
>  but overritten by euid == initial uid
>[2019/02/27 16:14:04.156075,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:117(access_check_object)
>  _lsa_OpenPolicy2: access GRANTED (requested: 0x000f1fff, granted: 0x000f1fff)
>[2019/02/27 16:14:04.156097,  6, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:304(create_rpc_handle_internal)
>  Opened policy hnd[3] [0000] 00 00 00 00 03 00 00 00   00 00 00 00 76 5C 3C A9   ........ ....v\<.
>  [0010] 58 6C 00 00                                        Xl.. 
>[2019/02/27 16:14:04.156132,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       lsa_OpenPolicy: struct lsa_OpenPolicy
>          out: struct lsa_OpenPolicy
>              handle                   : *
>                  handle: struct policy_handle
>                      handle_type              : 0x00000000 (0)
>                      uuid                     : 00000003-0000-0000-765c-3ca9586c0000
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.156203, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_client/cli_lsarpc.c:412(dcerpc_lsa_lookup_sids_generic)
>  rpccli_lsa_lookup_sids: processing items 0 -- 0 of 1.
>[2019/02/27 16:14:04.156250,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       lsa_LookupSids: struct lsa_LookupSids
>          in: struct lsa_LookupSids
>              handle                   : *
>                  handle: struct policy_handle
>                      handle_type              : 0x00000000 (0)
>                      uuid                     : 00000003-0000-0000-765c-3ca9586c0000
>              sids                     : *
>                  sids: struct lsa_SidArray
>                      num_sids                 : 0x00000001 (1)
>                      sids                     : *
>                          sids: ARRAY(1)
>                              sids: struct lsa_SidPtr
>                                  sid                      : *
>                                      sid                      : S-1-5-9
>              names                    : *
>                  names: struct lsa_TransNameArray
>                      count                    : 0x00000000 (0)
>                      names                    : NULL
>              level                    : LSA_LOOKUP_NAMES_ALL (1)
>              count                    : *
>                  count                    : 0x00000000 (0)
>[2019/02/27 16:14:04.156395,  6, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:339(find_policy_by_hnd_internal)
>  Found policy hnd[0] [0000] 00 00 00 00 03 00 00 00   00 00 00 00 76 5C 3C A9   ........ ....v\<.
>  [0010] 58 6C 00 00                                        Xl.. 
>[2019/02/27 16:14:04.156434, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:816(check_dom_sid_to_level)
>  Accepting SID S-1-5 in level 1
>[2019/02/27 16:14:04.156457, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:575(lookup_rids)
>  lookup_rids called for domain sid 'S-1-5'
>[2019/02/27 16:14:04.156479, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/lsa/srv_lsa_nt.c:896(_lsa_lookup_sids_internal)
>  num_sids 1, mapped_count 1, status NT_STATUS_OK
>[2019/02/27 16:14:04.156496,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       lsa_LookupSids: struct lsa_LookupSids
>          out: struct lsa_LookupSids
>              domains                  : *
>                  domains                  : *
>                      domains: struct lsa_RefDomainList
>                          count                    : 0x00000001 (1)
>                          domains                  : *
>                              domains: ARRAY(1)
>                                  domains: struct lsa_DomainInfo
>                                      name: struct lsa_StringLarge
>                                          length                   : 0x0018 (24)
>                                          size                     : 0x001a (26)
>                                          string                   : *
>                                              string                   : 'NT Authority'
>                                      sid                      : *
>                                          sid                      : S-1-5
>                          max_size                 : 0x00000020 (32)
>              names                    : *
>                  names: struct lsa_TransNameArray
>                      count                    : 0x00000001 (1)
>                      names                    : *
>                          names: ARRAY(1)
>                              names: struct lsa_TranslatedName
>                                  sid_type                 : SID_NAME_WKN_GRP (5)
>                                  name: struct lsa_String
>                                      length                   : 0x003a (58)
>                                      size                     : 0x003a (58)
>                                      string                   : *
>                                          string                   : 'Enterprise Domain Controllers'
>                                  sid_index                : 0x00000000 (0)
>              count                    : *
>                  count                    : 0x00000001 (1)
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.156748, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_client/cli_lsarpc.c:254(dcerpc_lsa_lookup_sids_noalloc)
>  LSA_LOOKUPSIDS returned status: 'NT_STATUS_OK', result: 'NT_STATUS_OK', mapped count = 1'
>[2019/02/27 16:14:04.156779, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:418(close_policy_by_pipe)
>  Deleted handle list for RPC connection samr
>[2019/02/27 16:14:04.156810,  4, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_ncacn_np.c:221(make_internal_rpc_pipe_p)
>  Create pipe requested samr
>[2019/02/27 16:14:04.156832, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:223(init_pipe_handles)
>  init_pipe_handle_list: created handle list for pipe samr
>[2019/02/27 16:14:04.156850, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:240(init_pipe_handles)
>  init_pipe_handle_list: pipe_handles ref count = 1 for pipe samr
>[2019/02/27 16:14:04.156887,  4, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_ncacn_np.c:261(make_internal_rpc_pipe_p)
>  Created internal pipe samr
>[2019/02/27 16:14:04.156919,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       samr_Connect2: struct samr_Connect2
>          in: struct samr_Connect2
>              system_name              : NULL
>              access_mask              : 0x02000000 (33554432)
>                     0: SAMR_ACCESS_CONNECT_TO_SERVER
>                     0: SAMR_ACCESS_SHUTDOWN_SERVER
>                     0: SAMR_ACCESS_INITIALIZE_SERVER
>                     0: SAMR_ACCESS_CREATE_DOMAIN
>                     0: SAMR_ACCESS_ENUM_DOMAINS 
>                     0: SAMR_ACCESS_LOOKUP_DOMAIN
>[2019/02/27 16:14:04.156988,  5, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/samr/srv_samr_nt.c:3889(_samr_Connect2)
>  _samr_Connect2: 3889
>[2019/02/27 16:14:04.157009, 10, pid=27736, effective(0, 0), real(0, 0)] ../../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0xb0000000 to 0x000f003f
>[2019/02/27 16:14:04.157029,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:95(access_check_object)
>  _samr_Connect2: ACCESS should be DENIED  (requested: 0x000f003f)
>  but overritten by euid == initial uid
>[2019/02/27 16:14:04.157051,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:117(access_check_object)
>  _samr_Connect2: access GRANTED (requested: 0x000f003f, granted: 0x000f003f)
>[2019/02/27 16:14:04.157073,  6, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:304(create_rpc_handle_internal)
>  Opened policy hnd[1] [0000] 00 00 00 00 04 00 00 00   00 00 00 00 76 5C 3C A9   ........ ....v\<.
>  [0010] 58 6C 00 00                                        Xl.. 
>[2019/02/27 16:14:04.157108,  5, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/samr/srv_samr_nt.c:3918(_samr_Connect2)
>  _samr_Connect2: 3918
>[2019/02/27 16:14:04.157130,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       samr_Connect2: struct samr_Connect2
>          out: struct samr_Connect2
>              connect_handle           : *
>                  connect_handle: struct policy_handle
>                      handle_type              : 0x00000000 (0)
>                      uuid                     : 00000004-0000-0000-765c-3ca9586c0000
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.157206,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       samr_OpenDomain: struct samr_OpenDomain
>          in: struct samr_OpenDomain
>              connect_handle           : *
>                  connect_handle: struct policy_handle
>                      handle_type              : 0x00000000 (0)
>                      uuid                     : 00000004-0000-0000-765c-3ca9586c0000
>              access_mask              : 0x02000000 (33554432)
>                     0: SAMR_DOMAIN_ACCESS_LOOKUP_INFO_1
>                     0: SAMR_DOMAIN_ACCESS_SET_INFO_1
>                     0: SAMR_DOMAIN_ACCESS_LOOKUP_INFO_2
>                     0: SAMR_DOMAIN_ACCESS_SET_INFO_2
>                     0: SAMR_DOMAIN_ACCESS_CREATE_USER
>                     0: SAMR_DOMAIN_ACCESS_CREATE_GROUP
>                     0: SAMR_DOMAIN_ACCESS_CREATE_ALIAS
>                     0: SAMR_DOMAIN_ACCESS_LOOKUP_ALIAS
>                     0: SAMR_DOMAIN_ACCESS_ENUM_ACCOUNTS
>                     0: SAMR_DOMAIN_ACCESS_OPEN_ACCOUNT
>                     0: SAMR_DOMAIN_ACCESS_SET_INFO_3
>              sid                      : *
>                  sid                      : S-1-5-32
>[2019/02/27 16:14:04.157354,  6, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:339(find_policy_by_hnd_internal)
>  Found policy hnd[0] [0000] 00 00 00 00 04 00 00 00   00 00 00 00 76 5C 3C A9   ........ ....v\<.
>  [0010] 58 6C 00 00                                        Xl.. 
>[2019/02/27 16:14:04.157387, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:523(_policy_handle_find)
>  found handle of type struct samr_connect_info
>[2019/02/27 16:14:04.157406, 10, pid=27736, effective(0, 0), real(0, 0)] ../../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0xb0000000 to 0x000f07ff
>[2019/02/27 16:14:04.157424,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:84(access_check_object)
>  access_check_object: user rights access mask [0x3f0]
>[2019/02/27 16:14:04.157440,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:95(access_check_object)
>  _samr_OpenDomain: ACCESS should be DENIED  (requested: 0x000f040f)
>  but overritten by euid == initial uid
>[2019/02/27 16:14:04.157461,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:117(access_check_object)
>  _samr_OpenDomain: access GRANTED (requested: 0x000f040f, granted: 0x000f07ff)
>[2019/02/27 16:14:04.157481,  6, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:304(create_rpc_handle_internal)
>  Opened policy hnd[2] [0000] 00 00 00 00 05 00 00 00   00 00 00 00 76 5C 3C A9   ........ ....v\<.
>  [0010] 58 6C 00 00                                        Xl.. 
>[2019/02/27 16:14:04.157514,  5, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/samr/srv_samr_nt.c:506(_samr_OpenDomain)
>  _samr_OpenDomain: 506
>[2019/02/27 16:14:04.157530,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       samr_OpenDomain: struct samr_OpenDomain
>          out: struct samr_OpenDomain
>              domain_handle            : *
>                  domain_handle: struct policy_handle
>                      handle_type              : 0x00000000 (0)
>                      uuid                     : 00000005-0000-0000-765c-3ca9586c0000
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.160588,  4, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_ncacn_np.c:221(make_internal_rpc_pipe_p)
>  Create pipe requested lsarpc
>[2019/02/27 16:14:04.160784, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:240(init_pipe_handles)
>  init_pipe_handle_list: pipe_handles ref count = 2 for pipe lsarpc
>[2019/02/27 16:14:04.161023,  4, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_ncacn_np.c:261(make_internal_rpc_pipe_p)
>  Created internal pipe lsarpc
>[2019/02/27 16:14:04.161216,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       lsa_OpenPolicy: struct lsa_OpenPolicy
>          in: struct lsa_OpenPolicy
>              system_name              : *
>                  system_name              : 0x005c (92)
>              attr                     : *
>                  attr: struct lsa_ObjectAttribute
>                      len                      : 0x00000018 (24)
>                      root_dir                 : NULL
>                      object_name              : NULL
>                      attributes               : 0x00000000 (0)
>                      sec_desc                 : NULL
>                      sec_qos                  : *
>                          sec_qos: struct lsa_QosInfo
>                              len                      : 0x0000000c (12)
>                              impersonation_level      : 0x0002 (2)
>                              context_mode             : 0x01 (1)
>                              effective_only           : 0x00 (0)
>              access_mask              : 0x02000000 (33554432)
>                     0: LSA_POLICY_VIEW_LOCAL_INFORMATION
>                     0: LSA_POLICY_VIEW_AUDIT_INFORMATION
>                     0: LSA_POLICY_GET_PRIVATE_INFORMATION
>                     0: LSA_POLICY_TRUST_ADMIN   
>                     0: LSA_POLICY_CREATE_ACCOUNT
>                     0: LSA_POLICY_CREATE_SECRET 
>                     0: LSA_POLICY_CREATE_PRIVILEGE
>                     0: LSA_POLICY_SET_DEFAULT_QUOTA_LIMITS
>                     0: LSA_POLICY_SET_AUDIT_REQUIREMENTS
>                     0: LSA_POLICY_AUDIT_LOG_ADMIN
>                     0: LSA_POLICY_SERVER_ADMIN  
>                     0: LSA_POLICY_LOOKUP_NAMES  
>                     0: LSA_POLICY_NOTIFICATION  
>[2019/02/27 16:14:04.161784, 10, pid=27736, effective(0, 0), real(0, 0)] ../../libcli/security/access_check.c:58(se_map_generic)
>  se_map_generic(): mapped mask 0xb0000000 to 0x000f1fff
>[2019/02/27 16:14:04.161809,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:95(access_check_object)
>  _lsa_OpenPolicy2: ACCESS should be DENIED  (requested: 0x000f1fff)
>  but overritten by euid == initial uid
>[2019/02/27 16:14:04.161831,  4, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_server/srv_access_check.c:117(access_check_object)
>  _lsa_OpenPolicy2: access GRANTED (requested: 0x000f1fff, granted: 0x000f1fff)
>[2019/02/27 16:14:04.161852,  6, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:304(create_rpc_handle_internal)
>  Opened policy hnd[3] [0000] 00 00 00 00 06 00 00 00   00 00 00 00 76 5C 3C A9   ........ ....v\<.
>  [0010] 58 6C 00 00                                        Xl.. 
>[2019/02/27 16:14:04.161886,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       lsa_OpenPolicy: struct lsa_OpenPolicy
>          out: struct lsa_OpenPolicy
>              handle                   : *
>                  handle: struct policy_handle
>                      handle_type              : 0x00000000 (0)
>                      uuid                     : 00000006-0000-0000-765c-3ca9586c0000
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.161990, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_client/cli_lsarpc.c:412(dcerpc_lsa_lookup_sids_generic)
>  rpccli_lsa_lookup_sids: processing items 0 -- 0 of 1.
>[2019/02/27 16:14:04.162042,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       lsa_LookupSids: struct lsa_LookupSids
>          in: struct lsa_LookupSids
>              handle                   : *
>                  handle: struct policy_handle
>                      handle_type              : 0x00000000 (0)
>                      uuid                     : 00000006-0000-0000-765c-3ca9586c0000
>              sids                     : *
>                  sids: struct lsa_SidArray
>                      num_sids                 : 0x00000001 (1)
>                      sids                     : *
>                          sids: ARRAY(1)
>                              sids: struct lsa_SidPtr
>                                  sid                      : *
>                                      sid                      : S-1-5-9
>              names                    : *
>                  names: struct lsa_TransNameArray
>                      count                    : 0x00000000 (0)
>                      names                    : NULL
>              level                    : LSA_LOOKUP_NAMES_ALL (1)
>              count                    : *
>                  count                    : 0x00000000 (0)
>[2019/02/27 16:14:04.162177,  6, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/rpc_handles.c:339(find_policy_by_hnd_internal)
>  Found policy hnd[0] [0000] 00 00 00 00 06 00 00 00   00 00 00 00 76 5C 3C A9   ........ ....v\<.
>  [0010] 58 6C 00 00                                        Xl.. 
>[2019/02/27 16:14:04.162222, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:816(check_dom_sid_to_level)
>  Accepting SID S-1-5 in level 1
>[2019/02/27 16:14:04.162243, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:575(lookup_rids)
>  lookup_rids called for domain sid 'S-1-5'
>[2019/02/27 16:14:04.162264, 10, pid=27736, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/lsa/srv_lsa_nt.c:896(_lsa_lookup_sids_internal)
>  num_sids 1, mapped_count 1, status NT_STATUS_OK
>[2019/02/27 16:14:04.162283,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       lsa_LookupSids: struct lsa_LookupSids
>          out: struct lsa_LookupSids
>              domains                  : *
>                  domains                  : *
>                      domains: struct lsa_RefDomainList
>                          count                    : 0x00000001 (1)
>                          domains                  : *
>                              domains: ARRAY(1)
>                                  domains: struct lsa_DomainInfo
>                                      name: struct lsa_StringLarge
>                                          length                   : 0x0018 (24)
>                                          size                     : 0x001a (26)
>                                          string                   : *
>                                              string                   : 'NT Authority'
>                                      sid                      : *
>                                          sid                      : S-1-5
>                          max_size                 : 0x00000020 (32)
>              names                    : *
>                  names: struct lsa_TransNameArray
>                      count                    : 0x00000001 (1)
>                      names                    : *
>                          names: ARRAY(1)
>                              names: struct lsa_TranslatedName
>                                  sid_type                 : SID_NAME_WKN_GRP (5)
>                                  name: struct lsa_String
>                                      length                   : 0x003a (58)
>                                      size                     : 0x003a (58)
>                                      string                   : *
>                                          string                   : 'Enterprise Domain Controllers'
>                                  sid_index                : 0x00000000 (0)
>              count                    : *
>                  count                    : 0x00000001 (1)
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.162554, 10, pid=27736, effective(0, 0), real(0, 0)] ../../source3/rpc_client/cli_lsarpc.c:254(dcerpc_lsa_lookup_sids_noalloc)
>  LSA_LOOKUPSIDS returned status: 'NT_STATUS_OK', result: 'NT_STATUS_OK', mapped count = 1'
>[2019/02/27 16:14:04.162594, 10, pid=27736, effective(0, 0), real(0, 0), class=tdb] ../../source3/lib/gencache.c:226(gencache_set_data_blob)
>  gencache_set_data_blob: Adding cache entry with key=[SID2NAME/S-1-5-9] and timeout=[Mi Feb 27 16:19:04 2019 CET] (300 seconds ahead)
>[2019/02/27 16:14:04.162665, 10, pid=27736, effective(0, 0), real(0, 0), class=tdb] ../../source3/lib/gencache.c:226(gencache_set_data_blob)
>  gencache_set_data_blob: Adding cache entry with key=[NAME2SID/NT AUTHORITY\ENTERPRISE DOMAIN CONTROLLERS] and timeout=[Mi Feb 27 16:19:04 2019 CET] (300 seconds ahead)
>[2019/02/27 16:14:04.162703,  1, pid=27736, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       wbint_LookupSid: struct wbint_LookupSid
>          out: struct wbint_LookupSid
>              type                     : *
>                  type                     : SID_NAME_WKN_GRP (5)
>              domain                   : *
>                  domain                   : *
>                      domain                   : 'NT Authority'
>              name                     : *
>                  name                     : *
>                      name                     : 'Enterprise Domain Controllers'
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.162805,  4, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1605(child_handler)
>  Finished processing child request 56
>[2019/02/27 16:14:04.162823, 10, pid=27736, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:154(child_write_response)
>  Writing 4096 bytes to parent
>
>==> /var/log/samba/log.winbindd <==
>[2019/02/27 16:14:04.163733,  1, pid=27706, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       wbint_LookupSid: struct wbint_LookupSid
>          out: struct wbint_LookupSid
>              type                     : *
>                  type                     : SID_NAME_WKN_GRP (5)
>              domain                   : *
>                  domain                   : *
>                      domain                   : 'NT Authority'
>              name                     : *
>                  name                     : *
>                      name                     : 'Enterprise Domain Controllers'
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.164754,  1, pid=27706, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       wbint_Sids2UnixIDs: struct wbint_Sids2UnixIDs
>          in: struct wbint_Sids2UnixIDs
>              domains                  : *
>                  domains: struct lsa_RefDomainList
>                      count                    : 0x00000001 (1)
>                      domains                  : *
>                          domains: ARRAY(1)
>                              domains: struct lsa_DomainInfo
>                                  name: struct lsa_StringLarge
>                                      length                   : 0x0000 (0)
>                                      size                     : 0x0002 (2)
>                                      string                   : *
>                                          string                   : ''
>                                  sid                      : *
>                                      sid                      : S-1-5
>                      max_size                 : 0x00000001 (1)
>              ids                      : *
>                  ids: struct wbint_TransIDArray
>                      num_ids                  : 0x00000001 (1)
>                      ids: ARRAY(1)
>                          ids: struct wbint_TransID
>                              type                     : ID_TYPE_GID (2)
>                              domain_index             : 0x00000000 (0)
>                              rid                      : 0x00000009 (9)
>                              xid: struct unixid
>                                  id                       : 0xffffffff (4294967295)
>                                  type                     : ID_TYPE_GID (2)
>[2019/02/27 16:14:04.165727, 10, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1630(fork_domain_child)
>  fork_domain_child called without domain.
>[2019/02/27 16:14:04.166902, 10, pid=27737, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1694(fork_domain_child)
>  Child process 27737
>[2019/02/27 16:14:04.167623, 10, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages_dgm_ref.c:163(msg_dgm_ref_destructor)
>  msg_dgm_ref_destructor: refs=0x55771683f920
>[2019/02/27 16:14:04.167961, 10, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages_dgm_ref.c:80(messaging_dgm_ref)
>  messaging_dgm_ref: messaging_dgm_init returned Erfolg
>[2019/02/27 16:14:04.168149, 10, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages_dgm_ref.c:109(messaging_dgm_ref)
>  messaging_dgm_ref: unique = 5012232535472713616
>[2019/02/27 16:14:04.168348,  5, pid=27737, effective(0, 0), real(0, 0), class=passdb] ../../source3/passdb/pdb_interface.c:155(make_pdb_method_name)
>  Attempting to find a passdb backend to match tdbsam (tdbsam)
>[2019/02/27 16:14:04.168524,  5, pid=27737, effective(0, 0), real(0, 0), class=passdb] ../../source3/passdb/pdb_interface.c:176(make_pdb_method_name)
>  Found pdb backend tdbsam
>[2019/02/27 16:14:04.168728,  5, pid=27737, effective(0, 0), real(0, 0), class=passdb] ../../source3/passdb/pdb_interface.c:187(make_pdb_method_name)
>  pdb backend tdbsam has a valid init
>[2019/02/27 16:14:04.168938,  5, pid=27737, effective(0, 0), real(0, 0)] ../../lib/util/debug.c:800(debug_dump_status)
>  INFO: Current debug levels:
>    all: 10
>    tdb: 10
>    printdrivers: 10
>    lanman: 10
>    smb: 10
>    rpc_parse: 10
>    rpc_srv: 10
>    rpc_cli: 10
>    passdb: 10
>    sam: 10
>    auth: 10
>    winbind: 10
>    vfs: 10
>    idmap: 10
>    quota: 10
>    acls: 10
>    locking: 10
>    msdfs: 10
>    dmapi: 10
>    registry: 10
>    scavenger: 10
>    dns: 10
>    ldb: 10
>    tevent: 10
>    auth_audit: 10
>    auth_json_audit: 10
>    kerberos: 10
>    drs_repl: 10
>    smb2: 10
>    smb2_credits: 10
>    dsdb_audit: 10
>    dsdb_json_audit: 10
>    dsdb_password_audit: 10
>    dsdb_password_json_audit: 10
>    dsdb_transaction_audit: 10
>    dsdb_transaction_json_audit: 10
>    dsdb_group_audit: 10
>    dsdb_group_json_audit: 10
>
>==> /var/log/samba/log.winbindd-idmap <==
>[2019/02/27 16:14:04.170991,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 33 - private_data=(nil)
>[2019/02/27 16:14:04.171024,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 13 - private_data=(nil)
>[2019/02/27 16:14:04.171042,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1028 - private_data=(nil)
>[2019/02/27 16:14:04.171072,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1027 - private_data=(nil)
>[2019/02/27 16:14:04.171090,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1029 - private_data=(nil)
>[2019/02/27 16:14:04.171107,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1033 - private_data=(nil)
>[2019/02/27 16:14:04.171123,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1 - private_data=(nil)
>[2019/02/27 16:14:04.171140,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1036 - private_data=(nil)
>[2019/02/27 16:14:04.171157,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:745(messaging_deregister)
>  Deregistering messaging pointer for type 1035 - private_data=(nil)
>[2019/02/27 16:14:04.171569,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:698(messaging_register)
>  Registering messaging pointer for type 1028 - private_data=(nil)
>[2019/02/27 16:14:04.171741,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:698(messaging_register)
>  Registering messaging pointer for type 1027 - private_data=(nil)
>[2019/02/27 16:14:04.171920,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:698(messaging_register)
>  Registering messaging pointer for type 1 - private_data=(nil)
>[2019/02/27 16:14:04.171944,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:698(messaging_register)
>  Registering messaging pointer for type 1034 - private_data=(nil)
>[2019/02/27 16:14:04.171961,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:713(messaging_register)
>  Overriding messaging pointer for type 1034 - private_data=(nil)
>[2019/02/27 16:14:04.171978,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:698(messaging_register)
>  Registering messaging pointer for type 1038 - private_data=(nil)
>[2019/02/27 16:14:04.171994,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:713(messaging_register)
>  Overriding messaging pointer for type 1038 - private_data=(nil)
>[2019/02/27 16:14:04.172011, 10, pid=27737, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cm.c:575(set_domain_online_request)
>  set_domain_online_request: called for domain AR41I1
>[2019/02/27 16:14:04.172034, 10, pid=27737, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cm.c:610(set_domain_online_request)
>  set_domain_online_request: domain AR41I1 was globally offline.
>[2019/02/27 16:14:04.172066, 10, pid=27737, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:119(child_read_request)
>  Need to read 78 extra bytes
>[2019/02/27 16:14:04.172087,  4, pid=27737, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1597(child_handler)
>  child daemon request 56
>[2019/02/27 16:14:04.172119, 10, pid=27737, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:744(child_process_request)
>  child_process_request: request fn NDRCMD
>[2019/02/27 16:14:04.172142, 10, pid=27737, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual_ndr.c:362(winbindd_dual_ndrcmd)
>  winbindd_dual_ndrcmd: Running command WBINT_SIDS2UNIXIDS (no domain)
>[2019/02/27 16:14:04.172206,  1, pid=27737, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       wbint_Sids2UnixIDs: struct wbint_Sids2UnixIDs
>          in: struct wbint_Sids2UnixIDs
>              domains                  : *
>                  domains: struct lsa_RefDomainList
>                      count                    : 0x00000001 (1)
>                      domains                  : *
>                          domains: ARRAY(1)
>                              domains: struct lsa_DomainInfo
>                                  name: struct lsa_StringLarge
>                                      length                   : 0x0000 (0)
>                                      size                     : 0x0002 (2)
>                                      string                   : *
>                                          string                   : ''
>                                  sid                      : *
>                                      sid                      : S-1-5
>                      max_size                 : 0x00000001 (1)
>              ids                      : *
>                  ids: struct wbint_TransIDArray
>                      num_ids                  : 0x00000001 (1)
>                      ids: ARRAY(1)
>                          ids: struct wbint_TransID
>                              type                     : ID_TYPE_GID (2)
>                              domain_index             : 0x00000000 (0)
>                              rid                      : 0x00000009 (9)
>                              xid: struct unixid
>                                  id                       : 0xffffffff (4294967295)
>                                  type                     : ID_TYPE_GID (2)
>[2019/02/27 16:14:04.172480, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:144(idmap_init)
>  idmap_init(): calling static_init_idmap
>[2019/02/27 16:14:04.172500, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap_tdb.c:438(idmap_tdb_init)
>  calling idmap_tdb_init
>[2019/02/27 16:14:04.172526,  5, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:355(smb_register_idmap)
>  Successfully added idmap backend 'tdb'
>[2019/02/27 16:14:04.172555,  5, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:355(smb_register_idmap)
>  Successfully added idmap backend 'passdb'
>[2019/02/27 16:14:04.172575,  5, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:355(smb_register_idmap)
>  Successfully added idmap backend 'nss'
>[2019/02/27 16:14:04.172602,  3, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:397(idmap_init_domain)
>  idmap backend ldap not found
>[2019/02/27 16:14:04.172624,  5, pid=27737, effective(0, 0), real(0, 0)] ../../lib/util/modules.c:160(load_module_absolute_path)
>  load_module_absolute_path: Probing module '/usr/lib/x86_64-linux-gnu/samba/idmap/ldap.so'
>[2019/02/27 16:14:04.180121,  3, pid=27737, effective(0, 0), real(0, 0)] ../../lib/util/modules.c:167(load_module_absolute_path)
>  load_module_absolute_path: Module '/usr/lib/x86_64-linux-gnu/samba/idmap/ldap.so' loaded
>[2019/02/27 16:14:04.180297,  5, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:355(smb_register_idmap)
>  Successfully added idmap backend 'ldap'
>[2019/02/27 16:14:04.180512,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:1308(smbldap_search_ext)
>  smbldap_search_ext: base => [cn=idmap,cn=univention,dc=ar41i1,dc=qa], filter => [(objectclass=sambaUnixIdPool)], scope => [2]
>[2019/02/27 16:14:04.180755,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:1173(smbldap_close)
>  The connection to the LDAP server was closed
>[2019/02/27 16:14:04.180946, 10, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:648(smb_ldap_setup_conn)
>  smb_ldap_setup_connection: ldap://master10.ar41i1.qa:7389
>[2019/02/27 16:14:04.230632,  3, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:632(smbldap_start_tls)
>  StartTLS issued: using a TLS connection
>[2019/02/27 16:14:04.230922,  2, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:847(smbldap_open_connection)
>  smbldap_open_connection: connection opened
>[2019/02/27 16:14:04.231105, 10, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:1007(smbldap_connect_system)
>  ldap_connect_system: Binding to ldap server ldap://master10.ar41i1.qa:7389 as "cn=member13,cn=memberserver,cn=computers,dc=ar41i1,dc=qa"
>[2019/02/27 16:14:04.243949,  3, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:1069(smbldap_connect_system)
>  ldap_connect_system: successful connection to the LDAP server
>  ldap_connect_system: LDAP server does support paged results
>[2019/02/27 16:14:04.244271,  4, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:1151(smbldap_open)
>  The LDAP server is successfully connected
>[2019/02/27 16:14:04.245232, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:124(lp_scan_idmap_found_domain)
>  lp_scan_idmap_found_domain: Found idmap domain "ar41i1"
>[2019/02/27 16:14:04.245413, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:262(idmap_found_domain_backend)
>  idmap_found_domain_backend: Found idmap domain "ar41i1"
>[2019/02/27 16:14:04.245616, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:124(lp_scan_idmap_found_domain)
>  lp_scan_idmap_found_domain: Found idmap domain "*"
>[2019/02/27 16:14:04.245787, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:262(idmap_found_domain_backend)
>  idmap_found_domain_backend: Found idmap domain "*"
>[2019/02/27 16:14:04.245971, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap.c:520(idmap_find_domain)
>  idmap_find_domain called for domain ''
>[2019/02/27 16:14:04.246160, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap_ldap.c:890(idmap_ldap_sids_to_unixids)
>  Filter: [(&(objectClass=sambaIdmapEntry)(sambaSID=S-1-5-9))]
>[2019/02/27 16:14:04.246347,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:1308(smbldap_search_ext)
>  smbldap_search_ext: base => [cn=idmap,cn=univention,dc=ar41i1,dc=qa], filter => [(&(objectClass=sambaIdmapEntry)(sambaSID=S-1-5-9))], scope => [2]
>[2019/02/27 16:14:04.247031, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap_ldap.c:939(idmap_ldap_sids_to_unixids)
>  NO SIDs found
>[2019/02/27 16:14:04.247214, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap_ldap.c:263(idmap_ldap_allocate_id_internal)
>  Search of the id pool (filter: (objectClass=sambaUnixIdPool))
>[2019/02/27 16:14:04.247382,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:1308(smbldap_search_ext)
>  smbldap_search_ext: base => [cn=idmap,cn=univention,dc=ar41i1,dc=qa], filter => [(objectClass=sambaUnixIdPool)], scope => [2]
>[2019/02/27 16:14:04.248127, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap_ldap.c:344(idmap_ldap_allocate_id_internal)
>  Try to atomically increment the id (55004 -> 55005)
>[2019/02/27 16:14:04.248303,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:1495(smbldap_modify)
>  smbldap_modify: dn => [cn=nextUnixId,cn=idmap,cn=univention,dc=ar41i1,dc=qa]
>[2019/02/27 16:14:04.297795, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap_rw.c:60(idmap_rw_new_mapping)
>  Setting mapping: S-1-5-9 <-> GID 55004
>[2019/02/27 16:14:04.298021, 10, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
>  smbldap_make_mod: adding attribute |gidNumber| value |55004|
>[2019/02/27 16:14:04.298219, 10, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:521(smbldap_make_mod_internal)
>  smbldap_make_mod: adding attribute |sambaSID| value |S-1-5-9|
>[2019/02/27 16:14:04.298426, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap_ldap.c:574(idmap_ldap_set_mapping)
>  Set DN sambaSID=S-1-5-9,cn=idmap,cn=univention,dc=ar41i1,dc=qa (S-1-5-9 -> 55004)
>[2019/02/27 16:14:04.298634,  5, pid=27737, effective(0, 0), real(0, 0)] ../../source3/lib/smbldap.c:1546(smbldap_add)
>  smbldap_add: dn => [sambaSID=S-1-5-9,cn=idmap,cn=univention,dc=ar41i1,dc=qa]
>[2019/02/27 16:14:04.359206, 10, pid=27737, effective(0, 0), real(0, 0), class=idmap] ../../source3/winbindd/idmap_ldap.c:596(idmap_ldap_set_mapping)
>  ldap_set_mapping: Successfully created mapping from S-1-5-9 to 55004 [gidNumber]
>[2019/02/27 16:14:04.359420,  1, pid=27737, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       wbint_Sids2UnixIDs: struct wbint_Sids2UnixIDs
>          out: struct wbint_Sids2UnixIDs
>              ids                      : *
>                  ids: struct wbint_TransIDArray
>                      num_ids                  : 0x00000001 (1)
>                      ids: ARRAY(1)
>                          ids: struct wbint_TransID
>                              type                     : ID_TYPE_GID (2)
>                              domain_index             : 0x00000000 (0)
>                              rid                      : 0x00000009 (9)
>                              xid: struct unixid
>                                  id                       : 0x0000d6dc (55004)
>                                  type                     : ID_TYPE_GID (2)
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.360879,  4, pid=27737, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1605(child_handler)
>  Finished processing child request 56
>[2019/02/27 16:14:04.361072, 10, pid=27737, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:154(child_write_response)
>  Writing 4040 bytes to parent
>
>==> /var/log/samba/log.winbindd <==
>[2019/02/27 16:14:04.361351,  1, pid=27706, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug)
>       wbint_Sids2UnixIDs: struct wbint_Sids2UnixIDs
>          out: struct wbint_Sids2UnixIDs
>              ids                      : *
>                  ids: struct wbint_TransIDArray
>                      num_ids                  : 0x00000001 (1)
>                      ids: ARRAY(1)
>                          ids: struct wbint_TransID
>                              type                     : ID_TYPE_GID (2)
>                              domain_index             : 0x00000000 (0)
>                              rid                      : 0x00000009 (9)
>                              xid: struct unixid
>                                  id                       : 0x0000d6dc (55004)
>                                  type                     : ID_TYPE_GID (2)
>              result                   : NT_STATUS_OK
>[2019/02/27 16:14:04.362193, 10, pid=27706, effective(0, 0), real(0, 0), class=tdb] ../../source3/lib/gencache.c:226(gencache_set_data_blob)
>  gencache_set_data_blob: Adding cache entry with key=[IDMAP/SID2XID/S-1-5-9] and timeout=[Mi MÃ¤r  6 16:14:04 2019 CET] (604800 seconds ahead)
>[2019/02/27 16:14:04.362301, 10, pid=27706, effective(0, 0), real(0, 0), class=tdb] ../../source3/lib/gencache.c:226(gencache_set_data_blob)
>  gencache_set_data_blob: Adding cache entry with key=[IDMAP/GID2SID/55004] and timeout=[Mi MÃ¤r  6 16:14:04 2019 CET] (604800 seconds ahead)
>[2019/02/27 16:14:04.362350, 10, pid=27706, effectiv55004
>root@member13:~# e(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd.c:810(process_request_done)
>  process_request_done: [wbinfo(27735):SIDS_TO_XIDS]: NT_STATUS_OK
>[2019/02/27 16:14:04.363494, 10, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd.c:854(process_request_written)
>  process_request_written: [wbinfo(27735):SIDS_TO_XIDS]: delivered response to client
>[2019/02/27 16:14:04.363551,  6, pid=27706, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd.c:969(winbind_client_request_read)
>  closing socket 22, client exited
>
>root@member13:~# univention-ldapsearch -LLL sambasid=S-1-5-9 gidNumber
>dn: cn=Enterprise Domain Controllers,cn=groups,dc=ar41i1,dc=qa
>gidNumber: 5015
>
>dn: sambaSID=S-1-5-9,cn=idmap,cn=univention,dc=ar41i1,dc=qa
>gidNumber: 55004
>

Actions: View

Attachments on bug 45840: 9983