Attachment 12323 Details for Bug 12127 – child winbindd log.

child winbindd log.

log.wb-TESTDOM1.rtf (text/rtf), 72.58 KB, created by Hemanth on 2016-08-08 06:26:45 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Hemanth

Created: 2016-08-08 06:26:45 UTC

Size: 72.58 KB

patch

obsolete

>{\rtf1\ansi\ansicpg1252\cocoartf1404\cocoasubrtf470
>{\fonttbl\f0\fnil\fcharset0 Menlo-Regular;}
>{\colortbl;\red255\green255\blue255;}
>\margl1440\margr1440\vieww23440\viewh11420\viewkind0
>\pard\tx560\tx1120\tx1680\tx2240\tx2800\tx3360\tx3920\tx4480\tx5040\tx5600\tx6160\tx6720\pardirnatural\partightenfactor0
>
>\f0\fs22 \cf0 \CocoaLigature0 [2016/08/07 22:49:55.982474,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:493(messaging_deregister)\
>  Deregistering messaging pointer for type 33 - private_data=(nil)\
>[2016/08/07 22:49:55.982494,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:493(messaging_deregister)\
>  Deregistering messaging pointer for type 13 - private_data=(nil)\
>[2016/08/07 22:49:55.982502,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:493(messaging_deregister)\
>  Deregistering messaging pointer for type 1028 - private_data=(nil)\
>[2016/08/07 22:49:55.982510,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:493(messaging_deregister)\
>  Deregistering messaging pointer for type 1027 - private_data=(nil)\
>[2016/08/07 22:49:55.982517,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:493(messaging_deregister)\
>  Deregistering messaging pointer for type 1029 - private_data=(nil)\
>[2016/08/07 22:49:55.982523,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:493(messaging_deregister)\
>  Deregistering messaging pointer for type 1280 - private_data=(nil)\
>[2016/08/07 22:49:55.982530,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:493(messaging_deregister)\
>  Deregistering messaging pointer for type 1033 - private_data=(nil)\
>[2016/08/07 22:49:55.982536,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:493(messaging_deregister)\
>  Deregistering messaging pointer for type 1 - private_data=(nil)\
>[2016/08/07 22:49:55.982543,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:493(messaging_deregister)\
>  Deregistering messaging pointer for type 1036 - private_data=(nil)\
>[2016/08/07 22:49:55.982549,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:493(messaging_deregister)\
>  Deregistering messaging pointer for type 1035 - private_data=(nil)\
>[2016/08/07 22:49:55.982580,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:446(messaging_register)\
>  Registering messaging pointer for type 1028 - private_data=(nil)\
>[2016/08/07 22:49:55.982589,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:446(messaging_register)\
>  Registering messaging pointer for type 1027 - private_data=(nil)\
>[2016/08/07 22:49:55.982597,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:446(messaging_register)\
>  Registering messaging pointer for type 1280 - private_data=(nil)\
>[2016/08/07 22:49:55.982603,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:446(messaging_register)\
>  Registering messaging pointer for type 1 - private_data=(nil)\
>[2016/08/07 22:49:55.982610,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:446(messaging_register)\
>  Registering messaging pointer for type 1034 - private_data=(nil)\
>[2016/08/07 22:49:55.982616,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/lib/messages.c:461(messaging_register)\
>  Overriding messaging pointer for type 1034 - private_data=(nil)\
>[2016/08/07 22:49:55.982628, 10, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_cm.c:566(set_domain_online_request)\
>  set_domain_online_request: called for domain testdom1\
>[2016/08/07 22:49:55.982655, 10, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_cm.c:601(set_domain_online_request)\
>  set_domain_online_request: domain testdom1 was globally offline.\
>\
>[2016/08/07 22:49:55.990031, 10, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_dual.c:1018(calculate_next_machine_pwd_change)\
>  password last changed 2016/08/07 17:54:28\
>  password valid until 2016/08/14 17:54:28\
>[2016/08/07 22:49:55.990069, 10, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_dual.c:1026(calculate_next_machine_pwd_change)\
>  machine password still valid until: Sun, 14 Aug 2016 17:54:28 PDT\
>[2016/08/07 22:49:55.990114, 10, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_dual.c:74(child_read_request)\
>  Need to read 48 extra bytes\
>[2016/08/07 22:49:55.990127,  4, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_dual.c:1406(child_handler)\
>  child daemon request 59\
>[2016/08/07 22:49:55.990138, 10, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_dual.c:517(child_process_request)\
>  child_process_request: request fn NDRCMD\
>[2016/08/07 22:49:55.990154, 10, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_dual_ndr.c:315(winbindd_dual_ndrcmd)\
>  winbindd_dual_ndrcmd: Running command WBINT_LOOKUPNAME (testdom1)\
>[2016/08/07 22:49:55.990196,  1, pid=10391, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:439(ndr_print_function_debug)\
>       wbint_LookupName: struct wbint_LookupName\
>          in: struct wbint_LookupName\
>              domain                   : *\
>                  domain                   : 'testdom1'\
>              name                     : *\
>                  name                     : 'ROOT'\
>              flags                    : 0x00000008 (8)\
>\
>[2016/08/07 22:49:55.990244,  5, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_cache.c:170(get_cache)\
>  get_cache: Setting ADS methods for domain testdom1\
>[2016/08/07 22:49:55.990297, 10, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_cache.c:467(fetch_cache_seqnum)\
>  fetch_cache_seqnum: success [testdom1][4294967295 @ 1470635395]\
>[2016/08/07 22:49:55.990309,  3, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_ads.c:1488(sequence_number)\
>  ads: fetch sequence_number for testdom1\
>[2016/08/07 22:49:55.990317, 10, pid=10391, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_ads.c:230(ads_cached_connection)\
>  ads_cached_connection\
>\
>[2016/08/07 22:49:55.995548,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:55.995566,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery_dc.c:77(ads_dc_name)\
>  ads_dc_name: domain=testdom1\
>[2016/08/07 22:49:55.995585,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:55.995593,  6, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:409(resolve_and_ping_dns)\
>  resolve_and_ping_dns: (cldap) looking for realm 'testdom1.test.exp.domain.com'\
>[2016/08/07 22:49:55.995600,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3346(get_sorted_dc_list)\
>  get_sorted_dc_list: attempting lookup for name testdom1.test.exp.domain.com (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:55.995623,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:213(saf_fetch)\
>  saf_fetch: Returning "DRTNASDCPROD01.testdom1.test.exp.domain.com" for "testdom1.test.exp.domain.com" domain\
>[2016/08/07 22:49:55.995635,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3151(get_dc_list)\
>  get_dc_list: preferred server list: "DRTNASDCPROD01.testdom1.test.exp.domain.com, *"\
>[2016/08/07 22:49:55.995647, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up testdom1.test.exp.domain.com#1c (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:55.995662,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name testdom1.test.exp.domain.com#1C found.\
>[2016/08/07 22:49:55.995726, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:55.995742,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3173(get_dc_list)\
>  Adding 1 DC's from auto lookup\
>[2016/08/07 22:49:55.995763,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:55.995772, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up DRTNASDCPROD01.testdom1.test.exp.domain.com#20 (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:55.995815,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name DRTNASDCPROD01.testdom1.test.exp.domain.com#20 found.\
>[2016/08/07 22:49:55.995861, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:55.995900,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:55.995916,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:55.995924, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:55.995932,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3296(get_dc_list)\
>  get_dc_list: returning 1 ip addresses in an ordered list\
>[2016/08/07 22:49:55.995939,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3297(get_dc_list)\
>  get_dc_list: 10.x.y.z:389 \
>[2016/08/07 22:49:55.995952,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:55.995961,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:254(ads_try_connect)\
>  ads_try_connect: sending CLDAP request to 10.x.y.z (realm: testdom1.test.exp.domain.com)\
>[2016/08/07 22:49:56.007107,  1, pid=10391, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug)\
>       &response->data.nt5_ex: struct NETLOGON_SAM_LOGON_RESPONSE_EX\
>          command                  : LOGON_SAM_LOGON_RESPONSE_EX (23)\
>          sbz                      : 0x0000 (0)\
>          server_type              : 0x000033fd (13309)\
>                 1: NBT_SERVER_PDC\
>                 1: NBT_SERVER_GC\
>                 1: NBT_SERVER_LDAP\
>                 1: NBT_SERVER_DS\
>                 1: NBT_SERVER_KDC\
>                 1: NBT_SERVER_TIMESERV\
>                 1: NBT_SERVER_CLOSEST\
>                 1: NBT_SERVER_WRITABLE\
>                 1: NBT_SERVER_GOOD_TIMESERV\
>                 0: NBT_SERVER_NDNC\
>                 0: NBT_SERVER_SELECT_SECRET_DOMAIN_6\
>                 1: NBT_SERVER_FULL_SECRET_DOMAIN_6\
>                 1: NBT_SERVER_ADS_WEB_SERVICE\
>                 0: NBT_SERVER_DS_8\
>                 0: NBT_SERVER_HAS_DNS_NAME\
>                 0: NBT_SERVER_IS_DEFAULT_NC\
>                 0: NBT_SERVER_FOREST_ROOT\
>          domain_uuid              : d5f2a508-0806-4f0c-abc3-b63a3ce9ca42\
>          forest                   : 'testdom1.test.exp.domain.com'\
>          dns_domain               : 'testdom1.test.exp.domain.com'\
>          pdc_dns_name             : 'DRTNASDCPROD01.testdom1.test.exp.domain.com'\
>          domain_name              : 'testdom1'\
>          pdc_name                 : 'DRTNASDCPROD01'\
>          user_name                : ''\
>          server_site              : 'Default-First-Site-Name'\
>          client_site              : 'Default-First-Site-Name'\
>          sockaddr_size            : 0x00 (0)\
>          sockaddr: struct nbt_sockaddr\
>              sockaddr_family          : 0x00000000 (0)\
>              pdc_ip                   : (null)\
>              remaining                : DATA_BLOB length=0\
>          next_closest_site        : NULL\
>          nt_version               : 0x00000005 (5)\
>                 1: NETLOGON_NT_VERSION_1\
>                 0: NETLOGON_NT_VERSION_5\
>                 1: NETLOGON_NT_VERSION_5EX\
>                 0: NETLOGON_NT_VERSION_5EX_WITH_IP\
>                 0: NETLOGON_NT_VERSION_WITH_CLOSEST_SITE\
>                 0: NETLOGON_NT_VERSION_AVOID_NT4EMUL\
>                 0: NETLOGON_NT_VERSION_PDC\
>                 0: NETLOGON_NT_VERSION_IP\
>                 0: NETLOGON_NT_VERSION_LOCAL\
>                 0: NETLOGON_NT_VERSION_GC\
>          lmnt_token               : 0xffff (65535)\
>          lm20_token               : 0xffff (65535)\
>\
>[2016/08/07 22:49:56.007327, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store)\
>  sitename_store: realm = [testdom1], sitename = [Default-First-Site-Name], expire = [2085923199]\
>[2016/08/07 22:49:56.007350, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for AD_SITENAME/DOMAIN/testdom1, we already got it\
>[2016/08/07 22:49:56.007372, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store)\
>  sitename_store: realm = [testdom1.test.exp.domain.com], sitename = [Default-First-Site-Name], expire = [2085923199]\
>[2016/08/07 22:49:56.007384, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for AD_SITENAME/DOMAIN/testdom1.test.exp.domain.com, we already got it\
>[2016/08/07 22:49:56.007396,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:618(ads_connect)\
>  Successfully contacted LDAP server 10.x.y.z\
>[2016/08/07 22:49:56.007411,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:56.007421, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:212(ads_closest_dc)\
>  ads_closest_dc: NBT_SERVER_CLOSEST flag set\
>[2016/08/07 22:49:56.007442, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:874(create_local_private_krb5_conf_for_domain)\
>  create_local_private_krb5_conf_for_domain: fname = /home/samba/lock/smb_krb5/krb5.conf.testdom1, realm = testdom1.test.exp.domain.com, domain = testdom1\
>[2016/08/07 22:49:56.007461,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:213(saf_fetch)\
>  saf_fetch: Returning "DRTNASDCPROD01.testdom1.test.exp.domain.com" for "testdom1.test.exp.domain.com" domain\
>[2016/08/07 22:49:56.007473,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3151(get_dc_list)\
>  get_dc_list: preferred server list: "DRTNASDCPROD01.testdom1.test.exp.domain.com, *"\
>[2016/08/07 22:49:56.007484, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up testdom1.test.exp.domain.com#dcdc (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:56.007495,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2464(resolve_ads)\
>  resolve_ads: Attempting to resolve KDCs for testdom1.test.exp.domain.com using DNS\
>[2016/08/07 22:49:56.018351,  4, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)\
>  ads_dns_lookup_srv: 1 records returned in the answer section.\
>[2016/08/07 22:49:56.018409, 10, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:216(ads_dns_parse_rr_srv)\
>  ads_dns_parse_rr_srv: Parsed drtnasdcprod01.testdom1.test.exp.domain.com [0, 100, 88]\
>[2016/08/07 22:49:56.018440, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.018459, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2823(internal_resolve_name)\
>  internal_resolve_name: returning 1 addresses: 10.x.y.z:88 \
>[2016/08/07 22:49:56.018481,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3173(get_dc_list)\
>  Adding 1 DC's from auto lookup\
>[2016/08/07 22:49:56.018533,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:56.018553, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up DRTNASDCPROD01.testdom1.test.exp.domain.com#20 (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:56.018609,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name DRTNASDCPROD01.testdom1.test.exp.domain.com#20 found.\
>[2016/08/07 22:49:56.018685, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.018704,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.018716,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.018723, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.018730,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3296(get_dc_list)\
>  get_dc_list: returning 1 ip addresses in an ordered list\
>[2016/08/07 22:49:56.018736,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3297(get_dc_list)\
>  get_dc_list: 10.x.y.z:88 \
>[2016/08/07 22:49:56.018744, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:706(get_kdc_ip_string)\
>  got 1 addresses from site Default-First-Site-Name search\
>[2016/08/07 22:49:56.018757,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:213(saf_fetch)\
>  saf_fetch: Returning "DRTNASDCPROD01.testdom1.test.exp.domain.com" for "testdom1.test.exp.domain.com" domain\
>[2016/08/07 22:49:56.018766,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3151(get_dc_list)\
>  get_dc_list: preferred server list: "DRTNASDCPROD01.testdom1.test.exp.domain.com, *"\
>[2016/08/07 22:49:56.018775, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up testdom1.test.exp.domain.com#dcdc (sitename (null))\
>[2016/08/07 22:49:56.018800,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2464(resolve_ads)\
>  resolve_ads: Attempting to resolve KDCs for testdom1.test.exp.domain.com using DNS\
>[2016/08/07 22:49:56.028686,  4, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)\
>  ads_dns_lookup_srv: 1 records returned in the answer section.\
>[2016/08/07 22:49:56.028722, 10, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:216(ads_dns_parse_rr_srv)\
>  ads_dns_parse_rr_srv: Parsed drtnasdcprod01.testdom1.test.exp.domain.com [0, 100, 88]\
>[2016/08/07 22:49:56.028746, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.028759, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2823(internal_resolve_name)\
>  internal_resolve_name: returning 1 addresses: 10.x.y.z:88 \
>[2016/08/07 22:49:56.028773,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3173(get_dc_list)\
>  Adding 1 DC's from auto lookup\
>[2016/08/07 22:49:56.028831,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:56.028851, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up DRTNASDCPROD01.testdom1.test.exp.domain.com#20 (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:56.028876,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name DRTNASDCPROD01.testdom1.test.exp.domain.com#20 found.\
>[2016/08/07 22:49:56.028959, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.028992,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.029023,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.029064, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.029083,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3296(get_dc_list)\
>  get_dc_list: returning 1 ip addresses in an ordered list\
>[2016/08/07 22:49:56.029095,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3297(get_dc_list)\
>  get_dc_list: 10.x.y.z:88 \
>[2016/08/07 22:49:56.029110, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:712(get_kdc_ip_string)\
>  got 1 addresses from site-less search\
>[2016/08/07 22:49:56.029123, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:744(get_kdc_ip_string)\
>  0 additional KDCs to test\
>[2016/08/07 22:49:56.029135, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:804(get_kdc_ip_string)\
>  get_kdc_ip_string: Returning 		kdc = 10.x.y.z\
>  \
>[2016/08/07 22:49:56.029313,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:966(create_local_private_krb5_conf_for_domain)\
>  create_local_private_krb5_conf_for_domain: wrote file /home/samba/lock/smb_krb5/krb5.conf.testdom1 with realm testdom1.test.exp.domain.com KDC list = 		kdc = 10.x.y.z\
>  \
>[2016/08/07 22:49:56.029346,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery_dc.c:151(ads_dc_name)\
>  ads_dc_name: using server='DRTNASDCPROD01.testdom1.test.exp.domain.com' IP=10.x.y.z\
>[2016/08/07 22:49:56.029359,  6, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:486(ads_find_dc)\
>  ads_find_dc: (ldap) looking for realm 'testdom1.test.exp.domain.com' and falling back to domain 'testdom1'\
>[2016/08/07 22:49:56.029380,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:56.029392,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery_dc.c:77(ads_dc_name)\
>  ads_dc_name: domain=testdom1\
>[2016/08/07 22:49:56.029404,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:56.029413,  6, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:409(resolve_and_ping_dns)\
>  resolve_and_ping_dns: (cldap) looking for realm 'testdom1.test.exp.domain.com'\
>[2016/08/07 22:49:56.029421,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3346(get_sorted_dc_list)\
>  get_sorted_dc_list: attempting lookup for name testdom1.test.exp.domain.com (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:56.029437,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:213(saf_fetch)\
>  saf_fetch: Returning "DRTNASDCPROD01.testdom1.test.exp.domain.com" for "testdom1.test.exp.domain.com" domain\
>[2016/08/07 22:49:56.029448,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3151(get_dc_list)\
>  get_dc_list: preferred server list: "DRTNASDCPROD01.testdom1.test.exp.domain.com, *"\
>[2016/08/07 22:49:56.029459, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up testdom1.test.exp.domain.com#1c (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:56.029485,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name testdom1.test.exp.domain.com#1C found.\
>[2016/08/07 22:49:56.029527, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.029539,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3173(get_dc_list)\
>  Adding 1 DC's from auto lookup\
>[2016/08/07 22:49:56.029558,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:56.029566, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up DRTNASDCPROD01.testdom1.test.exp.domain.com#20 (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:56.029578,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name DRTNASDCPROD01.testdom1.test.exp.domain.com#20 found.\
>[2016/08/07 22:49:56.029611, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.029629,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.029642,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.029650, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.029658,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3296(get_dc_list)\
>  get_dc_list: returning 1 ip addresses in an ordered list\
>[2016/08/07 22:49:56.029665,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3297(get_dc_list)\
>  get_dc_list: 10.x.y.z:389 \
>[2016/08/07 22:49:56.029677,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.029686,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:254(ads_try_connect)\
>  ads_try_connect: sending CLDAP request to 10.x.y.z (realm: testdom1.test.exp.domain.com)\
>[2016/08/07 22:49:56.039653,  1, pid=10391, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug)\
>       &response->data.nt5_ex: struct NETLOGON_SAM_LOGON_RESPONSE_EX\
>          command                  : LOGON_SAM_LOGON_RESPONSE_EX (23)\
>          sbz                      : 0x0000 (0)\
>          server_type              : 0x000033fd (13309)\
>                 1: NBT_SERVER_PDC\
>                 1: NBT_SERVER_GC\
>                 1: NBT_SERVER_LDAP\
>                 1: NBT_SERVER_DS\
>                 1: NBT_SERVER_KDC\
>                 1: NBT_SERVER_TIMESERV\
>                 1: NBT_SERVER_CLOSEST\
>                 1: NBT_SERVER_WRITABLE\
>                 1: NBT_SERVER_GOOD_TIMESERV\
>                 0: NBT_SERVER_NDNC\
>                 0: NBT_SERVER_SELECT_SECRET_DOMAIN_6\
>                 1: NBT_SERVER_FULL_SECRET_DOMAIN_6\
>                 1: NBT_SERVER_ADS_WEB_SERVICE\
>                 0: NBT_SERVER_DS_8\
>                 0: NBT_SERVER_HAS_DNS_NAME\
>                 0: NBT_SERVER_IS_DEFAULT_NC\
>                 0: NBT_SERVER_FOREST_ROOT\
>          domain_uuid              : d5f2a508-0806-4f0c-abc3-b63a3ce9ca42\
>          forest                   : 'testdom1.test.exp.domain.com'\
>          dns_domain               : 'testdom1.test.exp.domain.com'\
>          pdc_dns_name             : 'DRTNASDCPROD01.testdom1.test.exp.domain.com'\
>          domain_name              : 'testdom1'\
>          pdc_name                 : 'DRTNASDCPROD01'\
>          user_name                : ''\
>          server_site              : 'Default-First-Site-Name'\
>          client_site              : 'Default-First-Site-Name'\
>          sockaddr_size            : 0x00 (0)\
>          sockaddr: struct nbt_sockaddr\
>              sockaddr_family          : 0x00000000 (0)\
>              pdc_ip                   : (null)\
>              remaining                : DATA_BLOB length=0\
>          next_closest_site        : NULL\
>          nt_version               : 0x00000005 (5)\
>                 1: NETLOGON_NT_VERSION_1\
>                 0: NETLOGON_NT_VERSION_5\
>                 1: NETLOGON_NT_VERSION_5EX\
>                 0: NETLOGON_NT_VERSION_5EX_WITH_IP\
>                 0: NETLOGON_NT_VERSION_WITH_CLOSEST_SITE\
>                 0: NETLOGON_NT_VERSION_AVOID_NT4EMUL\
>                 0: NETLOGON_NT_VERSION_PDC\
>                 0: NETLOGON_NT_VERSION_IP\
>                 0: NETLOGON_NT_VERSION_LOCAL\
>                 0: NETLOGON_NT_VERSION_GC\
>          lmnt_token               : 0xffff (65535)\
>          lm20_token               : 0xffff (65535)\
>[2016/08/07 22:49:56.039845, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store)\
>  sitename_store: realm = [testdom1], sitename = [Default-First-Site-Name], expire = [2085923199]\
>[2016/08/07 22:49:56.039869, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for AD_SITENAME/DOMAIN/testdom1, we already got it\
>[2016/08/07 22:49:56.039878, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store)\
>  sitename_store: realm = [testdom1.test.exp.domain.com], sitename = [Default-First-Site-Name], expire = [2085923199]\
>[2016/08/07 22:49:56.039889, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for AD_SITENAME/DOMAIN/testdom1.test.exp.domain.com, we already got it\
>[2016/08/07 22:49:56.039899,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:618(ads_connect)\
>  Successfully contacted LDAP server 10.x.y.z\
>[2016/08/07 22:49:56.039912,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:56.039922, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:212(ads_closest_dc)\
>  ads_closest_dc: NBT_SERVER_CLOSEST flag set\
>[2016/08/07 22:49:56.039938, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:874(create_local_private_krb5_conf_for_domain)\
>  create_local_private_krb5_conf_for_domain: fname = /home/samba/lock/smb_krb5/krb5.conf.testdom1, realm = testdom1.test.exp.domain.com, domain = testdom1\
>[2016/08/07 22:49:56.039955,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:213(saf_fetch)\
>  saf_fetch: Returning "DRTNASDCPROD01.testdom1.test.exp.domain.com" for "testdom1.test.exp.domain.com" domain\
>[2016/08/07 22:49:56.039964,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3151(get_dc_list)\
>  get_dc_list: preferred server list: "DRTNASDCPROD01.testdom1.test.exp.domain.com, *"\
>[2016/08/07 22:49:56.039975, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up testdom1.test.exp.domain.com#dcdc (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:56.039984,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2464(resolve_ads)\
>  resolve_ads: Attempting to resolve KDCs for testdom1.test.exp.domain.com using DNS\
>[2016/08/07 22:49:56.050981,  4, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)\
>  ads_dns_lookup_srv: 1 records returned in the answer section.\
>[2016/08/07 22:49:56.051055, 10, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:216(ads_dns_parse_rr_srv)\
>  ads_dns_parse_rr_srv: Parsed drtnasdcprod01.testdom1.test.exp.domain.com [0, 100, 88]\
>[2016/08/07 22:49:56.051088, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.051107, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2823(internal_resolve_name)\
>  internal_resolve_name: returning 1 addresses: 10.x.y.z:88 \
>[2016/08/07 22:49:56.051129,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3173(get_dc_list)\
>  Adding 1 DC's from auto lookup\
>[2016/08/07 22:49:56.051181,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:56.051202, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up DRTNASDCPROD01.testdom1.test.exp.domain.com#20 (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:56.051232,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name DRTNASDCPROD01.testdom1.test.exp.domain.com#20 found.\
>[2016/08/07 22:49:56.051321, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.051358,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.051370,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.051377, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.051384,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3296(get_dc_list)\
>  get_dc_list: returning 1 ip addresses in an ordered list\
>[2016/08/07 22:49:56.051390,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3297(get_dc_list)\
>  get_dc_list: 10.x.y.z:88 \
>[2016/08/07 22:49:56.051398, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:706(get_kdc_ip_string)\
>  got 1 addresses from site Default-First-Site-Name search\
>[2016/08/07 22:49:56.051411,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:213(saf_fetch)\
>  saf_fetch: Returning "DRTNASDCPROD01.testdom1.test.exp.domain.com" for "testdom1.test.exp.domain.com" domain\
>[2016/08/07 22:49:56.051420,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3151(get_dc_list)\
>  get_dc_list: preferred server list: "DRTNASDCPROD01.testdom1.test.exp.domain.com, *"\
>[2016/08/07 22:49:56.051429, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up testdom1.test.exp.domain.com#dcdc (sitename (null))\
>[2016/08/07 22:49:56.051438,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2464(resolve_ads)\
>  resolve_ads: Attempting to resolve KDCs for testdom1.test.exp.domain.com using DNS\
>[2016/08/07 22:49:56.060962,  4, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)\
>  ads_dns_lookup_srv: 1 records returned in the answer section.\
>[2016/08/07 22:49:56.061062, 10, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:216(ads_dns_parse_rr_srv)\
>  ads_dns_parse_rr_srv: Parsed drtnasdcprod01.testdom1.test.exp.domain.com [0, 100, 88]\
>[2016/08/07 22:49:56.061097, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.061117, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2823(internal_resolve_name)\
>  internal_resolve_name: returning 1 addresses: 10.x.y.z:88 \
>[2016/08/07 22:49:56.061138,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3173(get_dc_list)\
>  Adding 1 DC's from auto lookup\
>[2016/08/07 22:49:56.061190,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:49:56.061211, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up DRTNASDCPROD01.testdom1.test.exp.domain.com#20 (sitename Default-First-Site-Name)\
>[2016/08/07 22:49:56.061241,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name DRTNASDCPROD01.testdom1.test.exp.domain.com#20 found.\
>[2016/08/07 22:49:56.061308, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.061327,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.061339,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:49:56.061346, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:49:56.061353,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3296(get_dc_list)\
>  get_dc_list: returning 1 ip addresses in an ordered list\
>[2016/08/07 22:49:56.061360,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3297(get_dc_list)\
>  get_dc_list: 10.x.y.z:88 \
>[2016/08/07 22:49:56.061367, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:712(get_kdc_ip_string)\
>  got 1 addresses from site-less search\
>[2016/08/07 22:49:56.061374, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:744(get_kdc_ip_string)\
>  0 additional KDCs to test\
>[2016/08/07 22:49:56.061380, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:804(get_kdc_ip_string)\
>  get_kdc_ip_string: Returning 		kdc = 10.x.y.z\
>  \
>[2016/08/07 22:49:56.061460,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:966(create_local_private_krb5_conf_for_domain)\
>  create_local_private_krb5_conf_for_domain: wrote file /home/samba/lock/smb_krb5/krb5.conf.testdom1 with realm testdom1.test.exp.domain.com KDC list = 		kdc = 10.x.y.z\
>  \
>[2016/08/07 22:49:56.061480,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery_dc.c:151(ads_dc_name)\
>  ads_dc_name: using server='DRTNASDCPROD01.testdom1.test.exp.domain.com' IP=10.x.y.z\
>[2016/08/07 22:49:56.061489,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:254(ads_try_connect)\
>  ads_try_connect: sending CLDAP request to 10.x.y.z (realm: testdom1.test.exp.domain.com)\
>[2016/08/07 22:49:56.070918,  1, pid=10391, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug)\
>       &response->data.nt5_ex: struct NETLOGON_SAM_LOGON_RESPONSE_EX\
>          command                  : LOGON_SAM_LOGON_RESPONSE_EX (23)\
>          sbz                      : 0x0000 (0)\
>          server_type              : 0x000033fd (13309)\
>                 1: NBT_SERVER_PDC\
>                 1: NBT_SERVER_GC\
>                 1: NBT_SERVER_LDAP\
>                 1: NBT_SERVER_DS\
>                 1: NBT_SERVER_KDC\
>                 1: NBT_SERVER_TIMESERV\
>                 1: NBT_SERVER_CLOSEST\
>                 1: NBT_SERVER_WRITABLE\
>                 1: NBT_SERVER_GOOD_TIMESERV\
>                 0: NBT_SERVER_NDNC\
>                 0: NBT_SERVER_SELECT_SECRET_DOMAIN_6\
>                 1: NBT_SERVER_FULL_SECRET_DOMAIN_6\
>                 1: NBT_SERVER_ADS_WEB_SERVICE\
>                 0: NBT_SERVER_DS_8\
>                 0: NBT_SERVER_HAS_DNS_NAME\
>                 0: NBT_SERVER_IS_DEFAULT_NC\
>                 0: NBT_SERVER_FOREST_ROOT\
>          domain_uuid              : d5f2a508-0806-4f0c-abc3-b63a3ce9ca42\
>          forest                   : 'testdom1.test.exp.domain.com'\
>          dns_domain               : 'testdom1.test.exp.domain.com'\
>          pdc_dns_name             : 'DRTNASDCPROD01.testdom1.test.exp.domain.com'\
>          domain_name              : 'testdom1'\
>          pdc_name                 : 'DRTNASDCPROD01'\
>          user_name                : ''\
>          server_site              : 'Default-First-Site-Name'\
>          client_site              : 'Default-First-Site-Name'\
>          sockaddr_size            : 0x00 (0)\
>          sockaddr: struct nbt_sockaddr\
>              sockaddr_family          : 0x00000000 (0)\
>              pdc_ip                   : (null)\
>              remaining                : DATA_BLOB length=0\
>          next_closest_site        : NULL\
>          nt_version               : 0x00000005 (5)\
>                 1: NETLOGON_NT_VERSION_1\
>                 0: NETLOGON_NT_VERSION_5\
>                 1: NETLOGON_NT_VERSION_5EX\
>                 0: NETLOGON_NT_VERSION_5EX_WITH_IP\
>                 0: NETLOGON_NT_VERSION_WITH_CLOSEST_SITE\
>                 0: NETLOGON_NT_VERSION_AVOID_NT4EMUL\
>                 0: NETLOGON_NT_VERSION_PDC\
>                 0: NETLOGON_NT_VERSION_IP\
>                 0: NETLOGON_NT_VERSION_LOCAL\
>                 0: NETLOGON_NT_VERSION_GC\
>          lmnt_token               : 0xffff (65535)\
>          lm20_token               : 0xffff (65535)\
>\
>\
>[2016/08/07 22:49:56.071105, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store)\
>  sitename_store: realm = [testdom1], sitename = [Default-First-Site-Name], expire = [2085923199]\
>[2016/08/07 22:49:56.071128, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for AD_SITENAME/DOMAIN/testdom1, we already got it\
>[2016/08/07 22:49:56.071137, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store)\
>  sitename_store: realm = [testdom1.test.exp.domain.com], sitename = [Default-First-Site-Name], expire = [2085923199]\
>[2016/08/07 22:49:56.071148, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for AD_SITENAME/DOMAIN/testdom1.test.exp.domain.com, we already got it\
>[2016/08/07 22:49:56.071160,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:618(ads_connect)\
>  Successfully contacted LDAP server 10.x.y.z\
>[2016/08/07 22:49:56.071169, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:73(ldap_open_with_timeout)\
>  Opening connection to LDAP server '10.x.y.z:389', timeout 15 seconds\
>[2016/08/07 22:49:56.071842, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:108(ldap_open_with_timeout)\
>  Initialized connection for LDAP server 'ldap://10.x.y.z:389'\
>[2016/08/07 22:49:56.071862,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:661(ads_connect)\
>  Connected to LDAP server DRTNASDCPROD01.testdom1.test.exp.domain.com\
>[2016/08/07 22:49:56.071879, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:212(ads_closest_dc)\
>  ads_closest_dc: NBT_SERVER_CLOSEST flag set\
>[2016/08/07 22:49:56.071893, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:88(saf_store)\
>  saf_store: domain = [testdom1], server = [DRTNASDCPROD01.testdom1.test.exp.domain.com], expire = [1470636296]\
>[2016/08/07 22:49:56.071906, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for SAF/DOMAIN/testdom1, we already got it\
>[2016/08/07 22:49:56.071915, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:88(saf_store)\
>  saf_store: domain = [testdom1.test.exp.domain.com], server = [DRTNASDCPROD01.testdom1.test.exp.domain.com], expire = [1470636296]\
>[2016/08/07 22:49:56.071924, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for SAF/DOMAIN/testdom1.test.exp.domain.com, we already got it\
>[2016/08/07 22:49:56.090672,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:2970(ads_current_time)\
>  KDC time offset is 0 seconds\
>[2016/08/07 22:49:56.100318,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:1082(ads_sasl_bind)\
>  Found SASL mechanism GSS-SPNEGO\
>[2016/08/07 22:49:56.110235,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:732(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.30\
>[2016/08/07 22:49:56.110279,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:732(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2\
>[2016/08/07 22:49:56.110287,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:732(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2\
>[2016/08/07 22:49:56.110293,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:732(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2.3\
>[2016/08/07 22:49:56.110299,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:732(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10\
>[2016/08/07 22:49:56.110366,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'gssapi_spnego' registered\
>[2016/08/07 22:49:56.110382,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'gssapi_krb5' registered\
>[2016/08/07 22:49:56.110390,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'gssapi_krb5_sasl' registered\
>[2016/08/07 22:49:56.110397,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'spnego' registered\
>[2016/08/07 22:49:56.110404,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'schannel' registered\
>[2016/08/07 22:49:56.110411,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'naclrpc_as_system' registered\
>[2016/08/07 22:49:56.110418,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'sasl-EXTERNAL' registered\
>[2016/08/07 22:49:56.110427,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'ntlmssp' registered\
>[2016/08/07 22:49:56.110434,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'ntlmssp_resume_ccache' registered\
>[2016/08/07 22:49:56.110441,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'http_basic' registered\
>[2016/08/07 22:49:56.110447,  3, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:907(gensec_register)\
>  GENSEC backend 'http_ntlm' registered\
>[2016/08/07 22:49:56.110840,  5, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:680(gensec_start_mech)\
>  Starting GENSEC mechanism spnego\
>[2016/08/07 22:49:56.110873,  5, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:680(gensec_start_mech)\
>  Starting GENSEC submechanism gse_krb5\
>[2016/08/07 22:49:56.110992,  3, pid=10391, effective(0, 0), real(0, 0)] ../lib/krb5_wrap/krb5_samba.c:2502(kerberos_get_principal_from_service_hostname)\
>  kerberos_get_principal_from_service_hostname: cannot get realm from, desthost drtnasdcprod01.testdom1.test.exp.domain.com or default ccache. Using default smb.conf realm testdom1.test.exp.domain.com\
>[2016/08/07 22:49:56.111391,  0, pid=10391, effective(0, 0), real(0, 0)] ../source3/librpc/crypto/gse.c:341(gse_get_client_auth_token)\
>  gss_init_sec_context failed with [Unspecified GSS failure.  Minor code may provide more information: No credentials cache found]\
>[2016/08/07 22:49:56.111550,  1, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/spnego.c:619(gensec_spnego_create_negTokenInit)\
>  SPNEGO(gse_krb5) creating NEG_TOKEN_INIT failed: NT_STATUS_INTERNAL_ERROR\
>[2016/08/07 22:49:56.111626, 10, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/spnego.c:672(gensec_spnego_create_negTokenInit)\
>  Failed to setup SPNEGO negTokenInit request: NT_STATUS_INTERNAL_ERROR\
>[2016/08/07 22:49:56.111650, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:761(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_gensec_bind(KRB5) failed with: An internal error occurred., calling kinit\
>[2016/08/07 22:49:56.111725, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:217(kerberos_kinit_password_ext)\
>  kerberos_kinit_password: as H435$@testdom1.test.exp.domain.com using [MEMORY:winbind_ccache] as ccache and config [/home/samba/lock/smb_krb5/krb5.conf.testdom1]\
>[2016/08/07 22:49:56.225879,  5, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:680(gensec_start_mech)\
>  Starting GENSEC mechanism spnego\
>[2016/08/07 22:49:56.225921,  5, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:680(gensec_start_mech)\
>  Starting GENSEC submechanism gse_krb5\
>[2016/08/07 22:49:56.226012,  3, pid=10391, effective(0, 0), real(0, 0)] ../lib/krb5_wrap/krb5_samba.c:2502(kerberos_get_principal_from_service_hostname)\
>  kerberos_get_principal_from_service_hostname: cannot get realm from, desthost drtnasdcprod01.testdom1.test.exp.domain.com or default ccache. Using default smb.conf realm testdom1.test.exp.domain.com\
>\
>\'97\'97\
>\'97\
>[2016/08/07 22:50:11.324867,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:981(ads_do_paged_search_args)\
>  ads_do_paged_search_args: ldap_search_with_timeout((objectclass=*)) -> Time limit exceeded\
>[2016/08/07 22:50:11.324938,  1, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap_utils.c:91(ads_do_search_retry_internal)\
>  Reducing LDAP page size from 1000 to 500 due to IO_TIMEOUT\
>[2016/08/07 22:50:11.324949,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap_utils.c:100(ads_do_search_retry_internal)\
>  Reopening ads connection to realm 'testdom1.test.exp.domain.com' after error Time limit exceeded\
>[2016/08/07 22:50:11.325056,  6, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:486(ads_find_dc)\
>  ads_find_dc: (ldap) looking for realm 'testdom1.test.exp.domain.com' and falling back to domain 'testdom1'\
>[2016/08/07 22:50:11.325120,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:50:11.325136,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery_dc.c:77(ads_dc_name)\
>  ads_dc_name: domain=testdom1\
>[2016/08/07 22:50:11.325149,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:50:11.325156,  6, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:409(resolve_and_ping_dns)\
>  resolve_and_ping_dns: (cldap) looking for realm 'testdom1.test.exp.domain.com'\
>[2016/08/07 22:50:11.325163,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3346(get_sorted_dc_list)\
>  get_sorted_dc_list: attempting lookup for name testdom1.test.exp.domain.com (sitename Default-First-Site-Name)\
>[2016/08/07 22:50:11.325184,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:213(saf_fetch)\
>  saf_fetch: Returning "DRTNASDCPROD01.testdom1.test.exp.domain.com" for "testdom1.test.exp.domain.com" domain\
>[2016/08/07 22:50:11.325196,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3151(get_dc_list)\
>  get_dc_list: preferred server list: "DRTNASDCPROD01.testdom1.test.exp.domain.com, *"\
>[2016/08/07 22:50:11.325208, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up testdom1.test.exp.domain.com#1c (sitename Default-First-Site-Name)\
>[2016/08/07 22:50:11.325224,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name testdom1.test.exp.domain.com#1C found.\
>[2016/08/07 22:50:11.325301, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:50:11.325315,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3173(get_dc_list)\
>  Adding 1 DC's from auto lookup\
>[2016/08/07 22:50:11.325335,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:50:11.325343, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up DRTNASDCPROD01.testdom1.test.exp.domain.com#20 (sitename Default-First-Site-Name)\
>[2016/08/07 22:50:11.325383,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name DRTNASDCPROD01.testdom1.test.exp.domain.com#20 found.\
>[2016/08/07 22:50:11.325424, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:50:11.325447,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:50:11.325459,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:50:11.325467, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:50:11.325474,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3296(get_dc_list)\
>  get_dc_list: returning 1 ip addresses in an ordered list\
>[2016/08/07 22:50:11.325481,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3297(get_dc_list)\
>  get_dc_list: 10.x.y.z:389 \
>[2016/08/07 22:50:11.325493,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:50:11.325501,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:254(ads_try_connect)\
>  ads_try_connect: sending CLDAP request to 10.x.y.z (realm: testdom1.test.exp.domain.com)\
>[2016/08/07 22:50:11.333921,  1, pid=10391, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug)\
>       &response->data.nt5_ex: struct NETLOGON_SAM_LOGON_RESPONSE_EX\
>          command                  : LOGON_SAM_LOGON_RESPONSE_EX (23)\
>--\
>[2016/08/07 22:50:11.334133, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store)\
>  sitename_store: realm = [testdom1], sitename = [Default-First-Site-Name], expire = [2085923199]\
>[2016/08/07 22:50:11.334161, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for AD_SITENAME/DOMAIN/testdom1, we already got it\
>[2016/08/07 22:50:11.334171, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store)\
>  sitename_store: realm = [testdom1.test.exp.domain.com], sitename = [Default-First-Site-Name], expire = [2085923199]\
>[2016/08/07 22:50:11.334182, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for AD_SITENAME/DOMAIN/testdom1.test.exp.domain.com, we already got it\
>[2016/08/07 22:50:11.334194,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:618(ads_connect)\
>  Successfully contacted LDAP server 10.x.y.z\
>[2016/08/07 22:50:11.334208,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:50:11.334220, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:212(ads_closest_dc)\
>  ads_closest_dc: NBT_SERVER_CLOSEST flag set\
>[2016/08/07 22:50:11.334243, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:874(create_local_private_krb5_conf_for_domain)\
>  create_local_private_krb5_conf_for_domain: fname = /home/samba/lock/smb_krb5/krb5.conf.testdom1, realm = testdom1.test.exp.domain.com, domain = testdom1\
>[2016/08/07 22:50:11.334262,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:213(saf_fetch)\
>  saf_fetch: Returning "DRTNASDCPROD01.testdom1.test.exp.domain.com" for "testdom1.test.exp.domain.com" domain\
>[2016/08/07 22:50:11.334273,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3151(get_dc_list)\
>  get_dc_list: preferred server list: "DRTNASDCPROD01.testdom1.test.exp.domain.com, *"\
>[2016/08/07 22:50:11.334282, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up testdom1.test.exp.domain.com#dcdc (sitename Default-First-Site-Name)\
>[2016/08/07 22:50:11.334293,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2464(resolve_ads)\
>  resolve_ads: Attempting to resolve KDCs for testdom1.test.exp.domain.com using DNS\
>[2016/08/07 22:50:11.342387,  4, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)\
>  ads_dns_lookup_srv: 1 records returned in the answer section.\
>[2016/08/07 22:50:11.342417, 10, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:216(ads_dns_parse_rr_srv)\
>  ads_dns_parse_rr_srv: Parsed drtnasdcprod01.testdom1.test.exp.domain.com [0, 100, 88]\
>[2016/08/07 22:50:11.342432, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:50:11.342439, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2823(internal_resolve_name)\
>  internal_resolve_name: returning 1 addresses: 10.x.y.z:88 \
>[2016/08/07 22:50:11.342448,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3173(get_dc_list)\
>  Adding 1 DC's from auto lookup\
>[2016/08/07 22:50:11.342486,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:50:11.342499, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up DRTNASDCPROD01.testdom1.test.exp.domain.com#20 (sitename Default-First-Site-Name)\
>[2016/08/07 22:50:11.342512,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name DRTNASDCPROD01.testdom1.test.exp.domain.com#20 found.\
>[2016/08/07 22:50:11.342556, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:50:11.342578,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:50:11.342591,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:50:11.342598, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:50:11.342605,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3296(get_dc_list)\
>  get_dc_list: returning 1 ip addresses in an ordered list\
>[2016/08/07 22:50:11.342612,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3297(get_dc_list)\
>  get_dc_list: 10.x.y.z:88 \
>[2016/08/07 22:50:11.342620, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:706(get_kdc_ip_string)\
>  got 1 addresses from site Default-First-Site-Name search\
>[2016/08/07 22:50:11.342633,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:213(saf_fetch)\
>  saf_fetch: Returning "DRTNASDCPROD01.testdom1.test.exp.domain.com" for "testdom1.test.exp.domain.com" domain\
>[2016/08/07 22:50:11.342643,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3151(get_dc_list)\
>  get_dc_list: preferred server list: "DRTNASDCPROD01.testdom1.test.exp.domain.com, *"\
>[2016/08/07 22:50:11.342652, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up testdom1.test.exp.domain.com#dcdc (sitename (null))\
>[2016/08/07 22:50:11.342661,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2464(resolve_ads)\
>  resolve_ads: Attempting to resolve KDCs for testdom1.test.exp.domain.com using DNS\
>[2016/08/07 22:50:11.351504,  4, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:435(ads_dns_lookup_srv)\
>  ads_dns_lookup_srv: 1 records returned in the answer section.\
>[2016/08/07 22:50:11.351533, 10, pid=10391, effective(0, 0), real(0, 0)] ../lib/addns/dnsquery.c:216(ads_dns_parse_rr_srv)\
>  ads_dns_parse_rr_srv: Parsed drtnasdcprod01.testdom1.test.exp.domain.com [0, 100, 88]\
>[2016/08/07 22:50:11.351547, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:50:11.351555, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2823(internal_resolve_name)\
>  internal_resolve_name: returning 1 addresses: 10.x.y.z:88 \
>[2016/08/07 22:50:11.351564,  8, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3173(get_dc_list)\
>  Adding 1 DC's from auto lookup\
>[2016/08/07 22:50:11.351588,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:105(sitename_fetch)\
>  sitename_fetch: Returning sitename for testdom1.test.exp.domain.com: "Default-First-Site-Name"\
>[2016/08/07 22:50:11.351611, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:2644(internal_resolve_name)\
>  internal_resolve_name: looking up DRTNASDCPROD01.testdom1.test.exp.domain.com#20 (sitename Default-First-Site-Name)\
>[2016/08/07 22:50:11.351628,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namecache.c:165(namecache_fetch)\
>  name DRTNASDCPROD01.testdom1.test.exp.domain.com#20 found.\
>[2016/08/07 22:50:11.351673, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:50:11.351695,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:50:11.351708,  9, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/conncache.c:150(check_negative_conn_cache)\
>  check_negative_conn_cache returning result 0 for domain testdom1.test.exp.domain.com server 10.x.y.z\
>[2016/08/07 22:50:11.351715, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:1141(remove_duplicate_addrs2)\
>  remove_duplicate_addrs2: looking for duplicate address/port pairs\
>[2016/08/07 22:50:11.351723,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3296(get_dc_list)\
>  get_dc_list: returning 1 ip addresses in an ordered list\
>[2016/08/07 22:50:11.351729,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:3297(get_dc_list)\
>  get_dc_list: 10.x.y.z:88 \
>[2016/08/07 22:50:11.351737, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:712(get_kdc_ip_string)\
>  got 1 addresses from site-less search\
>[2016/08/07 22:50:11.351743, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:744(get_kdc_ip_string)\
>  0 additional KDCs to test\
>[2016/08/07 22:50:11.351750, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:804(get_kdc_ip_string)\
>  get_kdc_ip_string: Returning 		kdc = 10.x.y.z\
>  \
>[2016/08/07 22:50:11.351898,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:966(create_local_private_krb5_conf_for_domain)\
>  create_local_private_krb5_conf_for_domain: wrote file /home/samba/lock/smb_krb5/krb5.conf.testdom1 with realm testdom1.test.exp.domain.com KDC list = 		kdc = 10.x.y.z\
>  \
>[2016/08/07 22:50:11.351934,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery_dc.c:151(ads_dc_name)\
>  ads_dc_name: using server='DRTNASDCPROD01.testdom1.test.exp.domain.com' IP=10.x.y.z\
>[2016/08/07 22:50:11.351944,  5, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:254(ads_try_connect)\
>  ads_try_connect: sending CLDAP request to 10.x.y.z (realm: testdom1.test.exp.domain.com)\
>[2016/08/07 22:50:11.359873,  1, pid=10391, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:402(ndr_print_debug)\
>       &response->data.nt5_ex: struct NETLOGON_SAM_LOGON_RESPONSE_EX\
>          command                  : LOGON_SAM_LOGON_RESPONSE_EX (23)\
>--\
>[2016/08/07 22:50:11.360089, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store)\
>  sitename_store: realm = [testdom1], sitename = [Default-First-Site-Name], expire = [2085923199]\
>[2016/08/07 22:50:11.360117, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for AD_SITENAME/DOMAIN/testdom1, we already got it\
>[2016/08/07 22:50:11.360128, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store)\
>  sitename_store: realm = [testdom1.test.exp.domain.com], sitename = [Default-First-Site-Name], expire = [2085923199]\
>[2016/08/07 22:50:11.360140, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for AD_SITENAME/DOMAIN/testdom1.test.exp.domain.com, we already got it\
>[2016/08/07 22:50:11.360153,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:618(ads_connect)\
>  Successfully contacted LDAP server 10.x.y.z\
>[2016/08/07 22:50:11.360161, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:73(ldap_open_with_timeout)\
>  Opening connection to LDAP server '10.x.y.z:389', timeout 15 seconds\
>[2016/08/07 22:50:11.360196, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:108(ldap_open_with_timeout)\
>  Initialized connection for LDAP server 'ldap://10.x.y.z:389'\
>[2016/08/07 22:50:11.360208,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:661(ads_connect)\
>  Connected to LDAP server DRTNASDCPROD01.testdom1.test.exp.domain.com\
>[2016/08/07 22:50:11.360215, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:212(ads_closest_dc)\
>  ads_closest_dc: NBT_SERVER_CLOSEST flag set\
>[2016/08/07 22:50:11.360228, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:88(saf_store)\
>  saf_store: domain = [testdom1], server = [DRTNASDCPROD01.testdom1.test.exp.domain.com], expire = [1470636311]\
>[2016/08/07 22:50:11.360240, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for SAF/DOMAIN/testdom1, we already got it\
>[2016/08/07 22:50:11.360249, 10, pid=10391, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:88(saf_store)\
>  saf_store: domain = [testdom1.test.exp.domain.com], server = [DRTNASDCPROD01.testdom1.test.exp.domain.com], expire = [1470636311]\
>[2016/08/07 22:50:11.360258, 10, pid=10391, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:302(gencache_set_data_blob)\
>  Did not store value for SAF/DOMAIN/testdom1.test.exp.domain.com, we already got it\
>[2016/08/07 22:50:11.375089,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:2970(ads_current_time)\
>  KDC time offset is 0 seconds\
>[2016/08/07 22:50:11.382838,  4, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:1082(ads_sasl_bind)\
>  Found SASL mechanism GSS-SPNEGO\
>[2016/08/07 22:50:11.390103,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:732(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.30\
>[2016/08/07 22:50:11.390127,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:732(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2\
>[2016/08/07 22:50:11.390135,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:732(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2\
>[2016/08/07 22:50:11.390142,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:732(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2.3\
>[2016/08/07 22:50:11.390149,  3, pid=10391, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:732(ads_sasl_spnego_bind)\
>  ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10\
>[2016/08/07 22:50:11.390342,  5, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:680(gensec_start_mech)\
>  Starting GENSEC mechanism spnego\
>[2016/08/07 22:50:11.390390,  5, pid=10391, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:680(gensec_start_mech)\
>  Starting GENSEC submechanism gse_krb5\
>[2016/08/07 22:50:11.390503,  3, pid=10391, effective(0, 0), real(0, 0)] ../lib/krb5_wrap/krb5_samba.c:2502(kerberos_get_principal_from_service_hostname)\
>  kerberos_get_principal_from_service_hostname: cannot get realm from, desthost drtnasdcprod01.testdom1.test.exp.domain.com or default ccache. Using default smb.conf realm testdom1.test.exp.domain.com\
>\
>}

Actions: View

Attachments on bug 12127: 12323 | 12326 | 12327