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/06/09 13:55:33.592146, 1, pid=11847, 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 : 0x000013fd (5117) 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 0: NBT_SERVER_ADS_WEB_SERVICE 0: NBT_SERVER_HAS_DNS_NAME 0: NBT_SERVER_IS_DEFAULT_NC 0: NBT_SERVER_FOREST_ROOT domain_uuid : 19a72884-72af-48c6-a1ea-a31b55b4965d forest : 'cfs.uoguelph.ca' dns_domain : 'cfs.uoguelph.ca' pdc_dns_name : 'dc07.cfs.uoguelph.ca' domain_name : 'CFS' pdc_name : 'DC07' 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/06/09 13:55:33.592486, 1, pid=11847, 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 : 0x000011fc (4604) 0: 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 0: NBT_SERVER_GOOD_TIMESERV 0: NBT_SERVER_NDNC 0: NBT_SERVER_SELECT_SECRET_DOMAIN_6 1: NBT_SERVER_FULL_SECRET_DOMAIN_6 0: NBT_SERVER_ADS_WEB_SERVICE 0: NBT_SERVER_HAS_DNS_NAME 0: NBT_SERVER_IS_DEFAULT_NC 0: NBT_SERVER_FOREST_ROOT domain_uuid : 19a72884-72af-48c6-a1ea-a31b55b4965d forest : 'cfs.uoguelph.ca' dns_domain : 'cfs.uoguelph.ca' pdc_dns_name : 'dc06.cfs.uoguelph.ca' domain_name : 'CFS' pdc_name : 'DC06' 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/06/09 13:55:33.592856, 10, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:794(get_kdc_ip_string) get_kdc_ip_string: Returning kdc = 131.104.99.85 kdc = 131.104.99.119 kdc = 131.104.99.94 [2016/06/09 13:55:33.593083, 5, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/kerberos.c:956(create_local_private_krb5_conf_for_domain) create_local_private_krb5_conf_for_domain: wrote file /var/lib/samba/smb_krb5/krb5.conf.CFS with realm CFS.UOGUELPH.CA KDC list = kdc = 131.104.99.85 kdc = 131.104.99.119 kdc = 131.104.99.94 [2016/06/09 13:55:33.593135, 4, pid=11847, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery_dc.c:151(ads_dc_name) ads_dc_name: using server='DC07.CFS.UOGUELPH.CA' IP=131.104.99.85 [2016/06/09 13:55:33.593160, 5, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:253(ads_try_connect) ads_try_connect: sending CLDAP request to 131.104.99.85 (realm: cfs.uoguelph.ca) [2016/06/09 13:55:33.593874, 1, pid=11847, 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 : 0x000013fd (5117) 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 0: NBT_SERVER_ADS_WEB_SERVICE 0: NBT_SERVER_HAS_DNS_NAME 0: NBT_SERVER_IS_DEFAULT_NC 0: NBT_SERVER_FOREST_ROOT domain_uuid : 19a72884-72af-48c6-a1ea-a31b55b4965d forest : 'cfs.uoguelph.ca' dns_domain : 'cfs.uoguelph.ca' pdc_dns_name : 'dc07.cfs.uoguelph.ca' domain_name : 'CFS' pdc_name : 'DC07' 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/06/09 13:55:33.594244, 10, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store) sitename_store: realm = [CFS], sitename = [Default-First-Site-Name], expire = [2085923199] [2016/06/09 13:55:33.594285, 10, pid=11847, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:292(gencache_set_data_blob) Did not store value for AD_SITENAME/DOMAIN/CFS, we already got it [2016/06/09 13:55:33.594308, 10, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/sitename_cache.c:70(sitename_store) sitename_store: realm = [cfs.uoguelph.ca], sitename = [Default-First-Site-Name], expire = [2085923199] [2016/06/09 13:55:33.594336, 10, pid=11847, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:292(gencache_set_data_blob) Did not store value for AD_SITENAME/DOMAIN/CFS.UOGUELPH.CA, we already got it [2016/06/09 13:55:33.594362, 3, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:541(ads_connect) Successfully contacted LDAP server 131.104.99.85 [2016/06/09 13:55:33.594383, 10, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:72(ldap_open_with_timeout) Opening connection to LDAP server '131.104.99.85:389', timeout 15 seconds [2016/06/09 13:55:33.594457, 10, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:107(ldap_open_with_timeout) Initialized connection for LDAP server 'ldap://131.104.99.85:389' [2016/06/09 13:55:33.594487, 3, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:584(ads_connect) Connected to LDAP server dc07.cfs.uoguelph.ca [2016/06/09 13:55:33.594507, 10, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:211(ads_closest_dc) ads_closest_dc: NBT_SERVER_CLOSEST flag set [2016/06/09 13:55:33.594531, 10, pid=11847, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:87(saf_store) saf_store: domain = [CFS], server = [dc07.cfs.uoguelph.ca], expire = [1465495833] [2016/06/09 13:55:33.594561, 10, pid=11847, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:292(gencache_set_data_blob) Did not store value for SAF/DOMAIN/CFS, we already got it [2016/06/09 13:55:33.594586, 10, pid=11847, effective(0, 0), real(0, 0)] ../source3/libsmb/namequery.c:87(saf_store) saf_store: domain = [cfs.uoguelph.ca], server = [dc07.cfs.uoguelph.ca], expire = [1465495833] [2016/06/09 13:55:33.594630, 10, pid=11847, effective(0, 0), real(0, 0), class=tdb] ../source3/lib/gencache.c:292(gencache_set_data_blob) Did not store value for SAF/DOMAIN/CFS.UOGUELPH.CA, we already got it [2016/06/09 13:55:33.595783, 4, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:2870(ads_current_time) KDC time offset is 0 seconds [2016/06/09 13:55:33.596203, 4, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:1073(ads_sasl_bind) Found SASL mechanism GSS-SPNEGO [2016/06/09 13:55:33.596683, 3, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:723(ads_sasl_spnego_bind) ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2 [2016/06/09 13:55:33.596718, 3, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:723(ads_sasl_spnego_bind) ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2 [2016/06/09 13:55:33.596739, 3, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:723(ads_sasl_spnego_bind) ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2.3 [2016/06/09 13:55:33.596766, 3, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/sasl.c:723(ads_sasl_spnego_bind) ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10 [2016/06/09 13:55:33.596958, 5, pid=11847, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:672(gensec_start_mech) Starting GENSEC mechanism spnego [2016/06/09 13:55:33.597008, 5, pid=11847, effective(0, 0), real(0, 0)] ../auth/gensec/gensec_start.c:672(gensec_start_mech) Starting GENSEC submechanism gse_krb5 [2016/06/09 13:55:33.597136, 3, pid=11847, 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 dc07.cfs.uoguelph.ca or default ccache. Using default smb.conf realm CFS.UOGUELPH.CA [2016/06/09 13:55:33.617151, 3, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/ldap.c:904(ads_do_paged_search_args) ads_do_paged_search_args: ldap_search_with_timeout((&(objectCategory=group)(&(groupType:dn:1.2.840.113556.1.4.803:=-2147483648)(!(groupType:dn:1.2.840.113556.1.4.803:=1))))) -> Time limit exceeded [2016/06/09 13:55:33.617216, 1, pid=11847, effective(0, 0), real(0, 0)] ../source3/libads/ldap_utils.c:135(ads_do_search_retry_internal) ads reopen failed after error Time limit exceeded [2016/06/09 13:55:33.617240, 1, pid=11847, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_ads.c:479(enum_dom_groups) enum_dom_groups ads_search: Time limit exceeded [2016/06/09 13:55:33.617268, 10, pid=11847, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_cache.c:541(refresh_sequence_number) refresh_sequence_number: CFS time ok [2016/06/09 13:55:33.617289, 10, pid=11847, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_cache.c:586(refresh_sequence_number) refresh_sequence_number: CFS seq number is now 158887929 [2016/06/09 13:55:33.617310, 1, pid=11847, effective(0, 0), real(0, 0)] ../librpc/ndr/ndr.c:439(ndr_print_function_debug) wbint_QueryGroupList: struct wbint_QueryGroupList out: struct wbint_QueryGroupList groups : * groups: struct wbint_Principals num_principals : 0 principals: ARRAY(0) result : NT_STATUS_IO_TIMEOUT [2016/06/09 13:55:33.617382, 4, pid=11847, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_dual.c:1395(child_handler) Finished processing child request 59 [2016/06/09 13:55:33.617404, 10, pid=11847, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_dual.c:102(child_write_response) Writing 3508 bytes to parent [root@radius-test samba]#