[2019/02/28 10:31:52.827255, 3] ../../lib/util/debug_s3.c:75(debug_message) INFO: Remote set of debug to `10' (pid 18451 from pid 18439) [2019/02/28 10:31:52.827297, 5, pid=18451, effective(0, 0), real(0, 0)] ../../lib/util/debug.c:804(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 [2019/02/28 10:32:22.837321, 10, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1828(fork_domain_child) fork_domain_child: domain CENTOS7DEV64 no longer in 'startup' mode. [2019/02/28 10:32:52.906306, 10, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:119(child_read_request) Need to read 36 extra bytes [2019/02/28 10:32:52.906359, 4, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1597(child_handler) child daemon request 56 [2019/02/28 10:32:52.906389, 10, pid=18451, 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/28 10:32:52.906419, 10, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual_ndr.c:362(winbindd_dual_ndrcmd) winbindd_dual_ndrcmd: Running command WBINT_LOOKUPNAME (CENTOS7DEV64) [2019/02/28 10:32:52.906474, 1, pid=18451, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug) wbint_LookupName: struct wbint_LookupName in: struct wbint_LookupName domain : * domain : '' name : * name : 'FOO' flags : 0x00000008 (8) [2019/02/28 10:32:52.906640, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/namemap_cache.c:324(namemap_cache_find_name) namemap_cache_find_name: gencache_parse(NAME2SID/\FOO) failed [2019/02/28 10:32:52.906679, 10, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cache.c:1772(wcache_name_to_sid) wcache_name_to_sid: namemap_cache_find_name failed [2019/02/28 10:32:52.906709, 10, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_cache.c:1819(wb_cache_name_to_sid) name_to_sid: [Cached] - doing backend query for name for domain CENTOS7DEV64 [2019/02/28 10:32:52.906738, 3, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_samr.c:595(sam_name_to_sid) sam_name_to_sid [2019/02/28 10:32:52.906771, 3, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_rpc.c:280(rpc_name_to_sid) name_to_sid: FOO for domain [2019/02/28 10:32:52.906848, 1, pid=18451, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug) lsa_LookupNames: struct lsa_LookupNames in: struct lsa_LookupNames handle : * handle: struct policy_handle handle_type : 0x00000000 (0) uuid : 00000020-0000-0000-775c-e8fe13480000 num_names : 0x00000001 (1) names: ARRAY(1) names: struct lsa_String length : 0x0006 (6) size : 0x0006 (6) string : * string : 'FOO' sids : * sids: struct lsa_TransSidArray count : 0x00000000 (0) sids : NULL level : LSA_LOOKUP_NAMES_ALL (1) count : * count : 0x00000000 (0) [2019/02/28 10:32:52.907160, 6, pid=18451, 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 20 00 00 00 00 00 00 00 77 5C E8 FE .... ... ....w\.. [0010] 13 48 00 00 .H.. [2019/02/28 10:32:52.907228, 5, pid=18451, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/lsa/srv_lsa_nt.c:163(lookup_lsa_rids) lookup_lsa_rids: looking up name FOO [2019/02/28 10:32:52.907259, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:113(lookup_name) lookup_name: FOO => domain=[], name=[FOO] [2019/02/28 10:32:52.907284, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:114(lookup_name) lookup_name: flags = 0x073 [2019/02/28 10:32:52.907317, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/util_wellknown.c:165(lookup_wellknown_name) map_name_to_wellknown_sid: looking up \FOO [2019/02/28 10:32:52.907386, 5, pid=18451, effective(0, 0), real(0, 0), class=passdb] ../../source3/passdb/pdb_tdb.c:600(tdbsam_getsampwnam) pdb_getsampwnam (TDB): error fetching database. Key: USER_foo [2019/02/28 10:32:52.907444, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/groupdb/mapping_tdb.c:279(find_map) failed to unpack map [2019/02/28 10:32:52.907532, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/groupdb/mapping_tdb.c:279(find_map) failed to unpack map [2019/02/28 10:32:52.907624, 5, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/username.c:181(Get_Pwnam_alloc) Finding user FOO [2019/02/28 10:32:52.907660, 5, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/username.c:120(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is foo [2019/02/28 10:33:02.388357, 5, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/username.c:128(Get_Pwnam_internals) Trying _Get_Pwnam(), username as given is FOO [2019/02/28 10:33:12.388229, 5, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/username.c:153(Get_Pwnam_internals) Checking combinations of 0 uppercase letters in foo [2019/02/28 10:33:12.388269, 5, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/username.c:159(Get_Pwnam_internals) Get_Pwnam_internals didn't find user [FOO]! [2019/02/28 10:33:22.388268, 5, pid=18451, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/lsa/srv_lsa_nt.c:181(lookup_lsa_rids) init_lsa_rids: FOO not found [2019/02/28 10:33:22.388308, 1, pid=18451, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug) lsa_LookupNames: struct lsa_LookupNames out: struct lsa_LookupNames domains : * domains : * domains: struct lsa_RefDomainList count : 0x00000000 (0) domains : NULL max_size : 0x00000000 (0) sids : * sids: struct lsa_TransSidArray count : 0x00000001 (1) sids : * sids: ARRAY(1) sids: struct lsa_TranslatedSid sid_type : SID_NAME_UNKNOWN (8) rid : 0x00000000 (0) sid_index : 0xffffffff (4294967295) count : * count : 0x00000000 (0) result : NT_STATUS_NONE_MAPPED [2019/02/28 10:33:22.388547, 2, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_rpc.c:299(rpc_name_to_sid) name_to_sid: failed to lookup name: NT_STATUS_NONE_MAPPED [2019/02/28 10:33:22.388593, 10, pid=18451, 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/28 10:33:22.388664, 4, pid=18451, 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/28 10:33:22.388699, 10, pid=18451, 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/28 10:33:22.388724, 10, pid=18451, 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/28 10:33:22.388787, 4, pid=18451, 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/28 10:33:22.388838, 1, pid=18451, 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/28 10:33:22.388966, 5, pid=18451, 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/28 10:33:22.389011, 10, pid=18451, 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/28 10:33:22.389047, 4, pid=18451, 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/28 10:33:22.389078, 4, pid=18451, 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/28 10:33:22.389105, 6, pid=18451, 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 21 00 00 00 00 00 00 00 77 5C 42 FF ....!... ....w\B. [0010] 13 48 00 00 .H.. [2019/02/28 10:33:22.389180, 5, pid=18451, 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/28 10:33:22.389207, 1, pid=18451, 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 : 00000021-0000-0000-775c-42ff13480000 result : NT_STATUS_OK [2019/02/28 10:33:22.389319, 1, pid=18451, 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 : 00000021-0000-0000-775c-42ff13480000 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-21-2661641715-394499615-2988108416 [2019/02/28 10:33:22.389519, 6, pid=18451, 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 21 00 00 00 00 00 00 00 77 5C 42 FF ....!... ....w\B. [0010] 13 48 00 00 .H.. [2019/02/28 10:33:22.389571, 10, pid=18451, 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/28 10:33:22.389599, 10, pid=18451, 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/28 10:33:22.389626, 4, pid=18451, 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/28 10:33:22.389651, 4, pid=18451, 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/28 10:33:22.389681, 4, pid=18451, 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/28 10:33:22.389708, 6, pid=18451, 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 22 00 00 00 00 00 00 00 77 5C 42 FF ...."... ....w\B. [0010] 13 48 00 00 .H.. [2019/02/28 10:33:22.389757, 5, pid=18451, 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/28 10:33:22.389786, 1, pid=18451, 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 : 00000022-0000-0000-775c-42ff13480000 result : NT_STATUS_OK [2019/02/28 10:33:22.389976, 4, pid=18451, 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/28 10:33:22.390011, 10, pid=18451, 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/28 10:33:22.390064, 4, pid=18451, 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/28 10:33:22.390112, 1, pid=18451, 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/28 10:33:22.390415, 10, pid=18451, 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/28 10:33:22.390449, 4, pid=18451, 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/28 10:33:22.390481, 4, pid=18451, 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/28 10:33:22.390508, 6, pid=18451, 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 23 00 00 00 00 00 00 00 77 5C 42 FF ....#... ....w\B. [0010] 13 48 00 00 .H.. [2019/02/28 10:33:22.390558, 1, pid=18451, 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 : 00000023-0000-0000-775c-42ff13480000 result : NT_STATUS_OK [2019/02/28 10:33:22.390650, 3, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_rpc.c:280(rpc_name_to_sid) name_to_sid: FOO for domain [2019/02/28 10:33:22.390700, 1, pid=18451, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug) lsa_LookupNames: struct lsa_LookupNames in: struct lsa_LookupNames handle : * handle: struct policy_handle handle_type : 0x00000000 (0) uuid : 00000023-0000-0000-775c-42ff13480000 num_names : 0x00000001 (1) names: ARRAY(1) names: struct lsa_String length : 0x0006 (6) size : 0x0006 (6) string : * string : 'FOO' sids : * sids: struct lsa_TransSidArray count : 0x00000000 (0) sids : NULL level : LSA_LOOKUP_NAMES_ALL (1) count : * count : 0x00000000 (0) [2019/02/28 10:33:22.390878, 6, pid=18451, 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 23 00 00 00 00 00 00 00 77 5C 42 FF ....#... ....w\B. [0010] 13 48 00 00 .H.. [2019/02/28 10:33:22.390929, 5, pid=18451, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/lsa/srv_lsa_nt.c:163(lookup_lsa_rids) lookup_lsa_rids: looking up name FOO [2019/02/28 10:33:22.390955, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:113(lookup_name) lookup_name: FOO => domain=[], name=[FOO] [2019/02/28 10:33:22.390980, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/passdb/lookup_sid.c:114(lookup_name) lookup_name: flags = 0x073 [2019/02/28 10:33:22.391007, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/util_wellknown.c:165(lookup_wellknown_name) map_name_to_wellknown_sid: looking up \FOO [2019/02/28 10:33:22.391059, 5, pid=18451, effective(0, 0), real(0, 0), class=passdb] ../../source3/passdb/pdb_tdb.c:600(tdbsam_getsampwnam) pdb_getsampwnam (TDB): error fetching database. Key: USER_foo [2019/02/28 10:33:22.391109, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/groupdb/mapping_tdb.c:279(find_map) failed to unpack map [2019/02/28 10:33:22.391208, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/groupdb/mapping_tdb.c:279(find_map) failed to unpack map [2019/02/28 10:33:22.391249, 5, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/username.c:181(Get_Pwnam_alloc) Finding user FOO [2019/02/28 10:33:22.391276, 5, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/username.c:120(Get_Pwnam_internals) Trying _Get_Pwnam(), username as lowercase is foo [2019/02/28 10:33:32.388219, 5, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/username.c:128(Get_Pwnam_internals) Trying _Get_Pwnam(), username as given is FOO [2019/02/28 10:33:42.388344, 5, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/username.c:153(Get_Pwnam_internals) Checking combinations of 0 uppercase letters in foo [2019/02/28 10:33:42.388397, 5, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/username.c:159(Get_Pwnam_internals) Get_Pwnam_internals didn't find user [FOO]! [2019/02/28 10:33:52.388680, 5, pid=18451, effective(0, 0), real(0, 0), class=rpc_srv] ../../source3/rpc_server/lsa/srv_lsa_nt.c:181(lookup_lsa_rids) init_lsa_rids: FOO not found [2019/02/28 10:33:52.388736, 1, pid=18451, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug) lsa_LookupNames: struct lsa_LookupNames out: struct lsa_LookupNames domains : * domains : * domains: struct lsa_RefDomainList count : 0x00000000 (0) domains : NULL max_size : 0x00000000 (0) sids : * sids: struct lsa_TransSidArray count : 0x00000001 (1) sids : * sids: ARRAY(1) sids: struct lsa_TranslatedSid sid_type : SID_NAME_UNKNOWN (8) rid : 0x00000000 (0) sid_index : 0xffffffff (4294967295) count : * count : 0x00000000 (0) result : NT_STATUS_NONE_MAPPED [2019/02/28 10:33:52.389015, 2, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_rpc.c:299(rpc_name_to_sid) name_to_sid: failed to lookup name: NT_STATUS_NONE_MAPPED [2019/02/28 10:33:52.389084, 10, pid=18451, 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/\FOO] and timeout=[Thu Feb 28 10:38:52 AM 2019 EST] (300 seconds ahead) [2019/02/28 10:33:52.389286, 1, pid=18451, effective(0, 0), real(0, 0), class=rpc_parse] ../../librpc/ndr/ndr.c:471(ndr_print_function_debug) wbint_LookupName: struct wbint_LookupName out: struct wbint_LookupName type : * type : SID_NAME_USE_NONE (0) sid : * sid : S-0-0 result : NT_STATUS_NONE_MAPPED [2019/02/28 10:33:52.389388, 4, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:1605(child_handler) Finished processing child request 56 [2019/02/28 10:33:52.389419, 10, pid=18451, effective(0, 0), real(0, 0), class=winbind] ../../source3/winbindd/winbindd_dual.c:154(child_write_response) Writing 4024 bytes to parent [2019/02/28 10:33:52.530329, 10, pid=18451, effective(0, 0), real(0, 0)] ../../source3/lib/messages.c:429(messaging_recv_cb) messaging_recv_cb: Received message 0x1 len 2 (num_fds:0) from 18439 [2019/02/28 10:33:52.530374, 3, pid=18451, effective(0, 0), real(0, 0)] ../../lib/util/debug_s3.c:75(debug_message) INFO: Remote set of debug to `3' (pid 18451 from pid 18439)