Oliver Werner
2016-Oct-03 15:56 UTC
[Samba] Samba Member NT_STATUS_NETWORK_SESSION_EXPIRED
hey, now after observe last changes on the weekend… i have also the issue. After 10 hours i can’t connect to the shares on my member server. On Log of DC i found this: [2016/10/02 20:35:45.601265, 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: AS-REQ PL0024$@HQ.KONTRAST from ipv4:<member-ip>:55578 for krbtgt/HQ.KONTRAST at HQ.KONTRAST [2016/10/02 20:35:45.605069, 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: No preauth found, returning PREAUTH-REQUIRED -- PL0024$@HQ.KONTRAST [2016/10/02 20:35:45.605960, 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: AS-REQ PL0024$@HQ.KONTRAST from ipv4:<member-ip>:52659 for krbtgt/HQ.KONTRAST at HQ.KONTRAST [2016/10/02 20:35:45.610083, 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: Client sent patypes: encrypted-timestamp [2016/10/02 20:35:45.610128, 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: Looking for PKINIT pa-data -- PL0024$@HQ.KONTRAST [2016/10/02 20:35:45.610144, 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: Looking for ENC-TS pa-data -- PL0024$@HQ.KONTRAST [2016/10/02 20:35:45.610200, 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: ENC-TS Pre-authentication succeeded -- PL0024$@HQ.KONTRAST using arcfour-hmac-md5 [2016/10/02 20:35:45.617582, 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: AS-REQ authtime: 2016-10-02T20:35:45 starttime: unset endtime: 2016-10-03T06:35:45 renew till: 2016-10-09T20:35:45 [2016/10/02 20:35:45.617699, 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: Client supported enctypes: aes256-cts-hmac-sha1-96, aes128-cts-hmac-sha1-96, des3-cbc-sha1, des3-cbc-md5, arcfour-hmac-md5, using arcfour-hmac-md5/arcfou r-hmac-md5 [2016/10/02 20:35:45.617748, 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) Kerberos: Requested flags: renewable, forwardable [2016/10/02 20:35:45.619243, 3] ../source4/smbd/service_stream.c:66(stream_terminate_connection) Terminating connection - 'ldapsrv_call_loop: tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED‘ That looks ok, yes? When i see it means my member got a new ticket? But i found this on member: [2016/10/03 17:50:03.311002, 10, pid=26714, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_dual.c:512(child_process_request) child_process_request: request fn NDRCMD [2016/10/03 17:50:03.311015, 10, pid=26714, 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 (HQKONTRAST) [2016/10/03 17:50:03.311064, 10, pid=26714, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_cache.c:467(fetch_cache_seqnum) fetch_cache_seqnum: success [HQKONTRAST][4294967295 @ 1475509803] [2016/10/03 17:50:03.311081, 3, pid=26714, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_ads.c:1493(sequence_number) ads: fetch sequence_number for HQKONTRAST [2016/10/03 17:50:03.311119, 10, pid=26714, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_ads.c:230(ads_cached_connection) ads_cached_connection [2016/10/03 17:50:03.311191, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 17:50:03.321144, 3] ../source3/libads/ldap.c:618(ads_connect) Successfully contacted LDAP server <DC-IP> [2016/10/03 17:50:03.321230, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 17:50:03.323699, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 17:50:03.328830, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 17:50:03.332100, 3] ../source3/libads/ldap.c:618(ads_connect) Successfully contacted LDAP server <DC-IP> [2016/10/03 17:50:03.332177, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 17:50:03.335277, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 17:50:03.343177, 3] ../source3/libads/ldap.c:618(ads_connect) Successfully contacted LDAP server <DC-IP>5 [2016/10/03 17:50:03.343268, 3] ../source3/libads/ldap.c:661(ads_connect) Connected to LDAP server vl0227.hq.kontrast [2016/10/03 17:50:03.350195, 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2 [2016/10/03 17:50:03.350226, 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2 [2016/10/03 17:50:03.350238, 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10 [2016/10/03 17:50:03.379973, 0] ../source3/librpc/crypto/gse.c:341(gse_get_client_auth_token) gss_init_sec_context failed with [ The context has expired: Success] [2016/10/03 17:50:03.380079, 1] ../auth/gensec/spnego.c:623(gensec_spnego_create_negTokenInit) SPNEGO(gse_krb5) creating NEG_TOKEN_INIT failed: NT_STATUS_INTERNAL_ERROR [2016/10/03 17:50:03.380131, 0] ../source3/libads/sasl.c:785(ads_sasl_spnego_bind) kinit succeeded but ads_sasl_spnego_gensec_bind(KRB5) failed: An internal error occurred. [2016/10/03 17:50:03.380176, 1, pid=26714, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_ads.c:136(ads_cached_connection_connect) ads_connect for domain HQKONTRAST failed: An internal error occurred. [2016/10/03 17:50:03.380272, 3, pid=26714, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_ads.c:1493(sequence_number) ads: fetch sequence_number for HQKONTRAST [2016/10/03 17:50:03.380291, 10, pid=26714, effective(0, 0), real(0, 0), class=winbind] ../source3/winbindd/winbindd_ads.c:230(ads_cached_connection) ads_cached_connection may this helps to find the problem :/ OLIVER WERNER Systemadministrator> Am 30.09.2016 um 14:53 schrieb Oliver Werner via samba <samba at lists.samba.org>: > > Ok lets try it :) > > > So… here the awnser for your last questions > > Did you create the libnss_win* links ? > > yes i have add winbind in nsswitch. > > Do you require your users to have home directories on the domain member? > > yes but not on this member > > > > OLIVER WERNER > Systemadministrator > > >> Am 30.09.2016 um 14:43 schrieb Rowland Penny via samba <samba at lists.samba.org>: >> >> On Fri, 30 Sep 2016 14:31:06 +0200 >> Oliver Werner <oliver.werner at kontrast.de> wrote: >> >>> Hi rowland, >>> >>> is pam really need? >>> >>> Users should not login via terminal to this system. this is only as >>> Samba File-Server >>> >> >> Lets put it this way, to connect to the domain member your users must >> be known to the underlying OS. >> >> The domain member I am typing this on, uses a smb.conf very similar to >> yours and has been up for nearly 16 days. The only difference that I >> can see between your setup and mine, is the PAM configuration. >> >> Rowland >> >> -- >> To unsubscribe from this list go to the following URL and read the >> instructions: https://lists.samba.org/mailman/options/samba > > -- > To unsubscribe from this list go to the following URL and read the > instructions: https://lists.samba.org/mailman/options/samba
Rowland Penny
2016-Oct-03 16:54 UTC
[Samba] Samba Member NT_STATUS_NETWORK_SESSION_EXPIRED
On Mon, 3 Oct 2016 17:56:07 +0200 Oliver Werner <oliver.werner at kontrast.de> wrote:> hey, > > now after observe last changes on the weekend… i have also the issue. > > After 10 hours i can’t connect to the shares on my member server. > > On Log of DC i found this: > > [2016/10/02 20:35:45.601265, > 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: AS-REQ PL0024$@HQ.KONTRAST from ipv4:<member-ip>:55578 for > krbtgt/HQ.KONTRAST at HQ.KONTRAST [2016/10/02 20:35:45.605069, > 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: No preauth found, returning PREAUTH-REQUIRED -- > PL0024$@HQ.KONTRAST [2016/10/02 20:35:45.605960, > 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: AS-REQ PL0024$@HQ.KONTRAST from ipv4:<member-ip>:52659 for > krbtgt/HQ.KONTRAST at HQ.KONTRAST [2016/10/02 20:35:45.610083, > 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: Client sent patypes: encrypted-timestamp [2016/10/02 > 20:35:45.610128, > 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: Looking for PKINIT pa-data -- PL0024$@HQ.KONTRAST > [2016/10/02 20:35:45.610144, > 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: Looking for ENC-TS pa-data -- PL0024$@HQ.KONTRAST > [2016/10/02 20:35:45.610200, > 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: ENC-TS Pre-authentication succeeded -- PL0024$@HQ.KONTRAST > using arcfour-hmac-md5 [2016/10/02 20:35:45.617582, > 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: AS-REQ authtime: 2016-10-02T20:35:45 starttime: unset > endtime: 2016-10-03T06:35:45 renew till: 2016-10-09T20:35:45 > [2016/10/02 20:35:45.617699, > 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: Client supported enctypes: aes256-cts-hmac-sha1-96, > aes128-cts-hmac-sha1-96, des3-cbc-sha1, des3-cbc-md5, > arcfour-hmac-md5, using arcfour-hmac-md5/arcfou r-hmac-md5 > [2016/10/02 20:35:45.617748, > 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) > Kerberos: Requested flags: renewable, forwardable [2016/10/02 > 20:35:45.619243, > 3] ../source4/smbd/service_stream.c:66(stream_terminate_connection) > Terminating connection - 'ldapsrv_call_loop: > tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED‘ > > > That looks ok, yes? When i see it means my member got a new ticket? > But i found this on member: > > [2016/10/03 17:50:03.311002, 10, pid=26714, effective(0, 0), real(0, > 0), > class=winbind] ../source3/winbindd/winbindd_dual.c:512(child_process_request) > child_process_request: request fn NDRCMD [2016/10/03 17:50:03.311015, > 10, pid=26714, 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 (HQKONTRAST) > [2016/10/03 17:50:03.311064, 10, pid=26714, effective(0, 0), real(0, > 0), > class=winbind] ../source3/winbindd/winbindd_cache.c:467(fetch_cache_seqnum) > fetch_cache_seqnum: success [HQKONTRAST][4294967295 @ 1475509803] > [2016/10/03 17:50:03.311081, 3, pid=26714, effective(0, 0), real(0, > 0), > class=winbind] ../source3/winbindd/winbindd_ads.c:1493(sequence_number) > ads: fetch sequence_number for HQKONTRAST [2016/10/03 > 17:50:03.311119, 10, pid=26714, effective(0, 0), real(0, 0), > class=winbind] ../source3/winbindd/winbindd_ads.c:230(ads_cached_connection) > ads_cached_connection [2016/10/03 17:50:03.311191, > 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: > preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 > 17:50:03.321144, 3] ../source3/libads/ldap.c:618(ads_connect) > Successfully contacted LDAP server <DC-IP> [2016/10/03 > 17:50:03.321230, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) > get_dc_list: preferred server list: "vl0227.hq.kontrast, > *" [2016/10/03 17:50:03.323699, > 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: > preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 > 17:50:03.328830, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) > get_dc_list: preferred server list: "vl0227.hq.kontrast, > *" [2016/10/03 17:50:03.332100, > 3] ../source3/libads/ldap.c:618(ads_connect) Successfully contacted > LDAP server <DC-IP> [2016/10/03 17:50:03.332177, > 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: > preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 > 17:50:03.335277, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) > get_dc_list: preferred server list: "vl0227.hq.kontrast, > *" [2016/10/03 17:50:03.343177, > 3] ../source3/libads/ldap.c:618(ads_connect) Successfully contacted > LDAP server <DC-IP>5 [2016/10/03 17:50:03.343268, > 3] ../source3/libads/ldap.c:661(ads_connect) Connected to LDAP server > vl0227.hq.kontrast [2016/10/03 17:50:03.350195, > 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) > ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2 [2016/10/03 > 17:50:03.350226, > 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) > ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2 [2016/10/03 > 17:50:03.350238, > 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) > ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10 [2016/10/03 > 17:50:03.379973, > 0] ../source3/librpc/crypto/gse.c:341(gse_get_client_auth_token) > gss_init_sec_context failed with [ The context has expired: Success] > [2016/10/03 17:50:03.380079, > 1] ../auth/gensec/spnego.c:623(gensec_spnego_create_negTokenInit) > SPNEGO(gse_krb5) creating NEG_TOKEN_INIT failed: > NT_STATUS_INTERNAL_ERROR [2016/10/03 17:50:03.380131, > 0] ../source3/libads/sasl.c:785(ads_sasl_spnego_bind) kinit succeeded > but ads_sasl_spnego_gensec_bind(KRB5) failed: An internal error > occurred. [2016/10/03 17:50:03.380176, 1, pid=26714, effective(0, > 0), real(0, 0), > class=winbind] ../source3/winbindd/winbindd_ads.c:136(ads_cached_connection_connect) > ads_connect for domain HQKONTRAST failed: An internal error occurred. > [2016/10/03 17:50:03.380272, 3, pid=26714, effective(0, 0), real(0, > 0), > class=winbind] ../source3/winbindd/winbindd_ads.c:1493(sequence_number) > ads: fetch sequence_number for HQKONTRAST [2016/10/03 > 17:50:03.380291, 10, pid=26714, effective(0, 0), real(0, 0), > class=winbind] ../source3/winbindd/winbindd_ads.c:230(ads_cached_connection) > ads_cached_connection > > > may this helps to find the problem :/I have searched the logs on my DCs and a domain member and do not have anything like the above in any of them. It is now 19 days uptime on the domain member and this isn't unusual, it only went down last time because of a power problem. I repeat, I do not have this problem and the only difference between your setup and mine (as far as I can see) is the PAM setup. Rowland
Oliver Werner
2016-Oct-04 07:09 UTC
[Samba] Samba Member NT_STATUS_NETWORK_SESSION_EXPIRED
so i add the pam yesterday and now after 10 hours no connection to member is possible. :( Same errors in logs i send yesterday OLIVER WERNER Systemadministrator> Am 03.10.2016 um 18:54 schrieb Rowland Penny via samba <samba at lists.samba.org>: > > On Mon, 3 Oct 2016 17:56:07 +0200 > Oliver Werner <oliver.werner at kontrast.de <mailto:oliver.werner at kontrast.de>> wrote: > >> hey, >> >> now after observe last changes on the weekend… i have also the issue. >> >> After 10 hours i can’t connect to the shares on my member server. >> >> On Log of DC i found this: >> >> [2016/10/02 20:35:45.601265, >> 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >> Kerberos: AS-REQ PL0024$@HQ.KONTRAST from ipv4:<member-ip>:55578 for >> krbtgt/HQ.KONTRAST at HQ.KONTRAST [2016/10/02 20:35:45.605069, >> 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >> Kerberos: No preauth found, returning PREAUTH-REQUIRED -- >> PL0024$@HQ.KONTRAST [2016/10/02 20:35:45.605960, >> 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >> Kerberos: AS-REQ PL0024$@HQ.KONTRAST from ipv4:<member-ip>:52659 for >> krbtgt/HQ.KONTRAST at HQ.KONTRAST [2016/10/02 20:35:45.610083, >> 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >> Kerberos: Client sent patypes: encrypted-timestamp [2016/10/02 >> 20:35:45.610128, >> 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >> Kerberos: Looking for PKINIT pa-data -- PL0024$@HQ.KONTRAST >> [2016/10/02 20:35:45.610144, >> 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >> Kerberos: Looking for ENC-TS pa-data -- PL0024$@HQ.KONTRAST >> [2016/10/02 20:35:45.610200, >> 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >> Kerberos: ENC-TS Pre-authentication succeeded -- PL0024$@HQ.KONTRAST >> using arcfour-hmac-md5 [2016/10/02 20:35:45.617582, >> 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >> Kerberos: AS-REQ authtime: 2016-10-02T20:35:45 starttime: unset >> endtime: 2016-10-03T06:35:45 renew till: 2016-10-09T20:35:45 >> [2016/10/02 20:35:45.617699, >> 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >> Kerberos: Client supported enctypes: aes256-cts-hmac-sha1-96, >> aes128-cts-hmac-sha1-96, des3-cbc-sha1, des3-cbc-md5, >> arcfour-hmac-md5, using arcfour-hmac-md5/arcfou r-hmac-md5 >> [2016/10/02 20:35:45.617748, >> 3] ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >> Kerberos: Requested flags: renewable, forwardable [2016/10/02 >> 20:35:45.619243, >> 3] ../source4/smbd/service_stream.c:66(stream_terminate_connection) >> Terminating connection - 'ldapsrv_call_loop: >> tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED‘ >> >> >> That looks ok, yes? When i see it means my member got a new ticket? >> But i found this on member: >> >> [2016/10/03 17:50:03.311002, 10, pid=26714, effective(0, 0), real(0, >> 0), >> class=winbind] ../source3/winbindd/winbindd_dual.c:512(child_process_request) >> child_process_request: request fn NDRCMD [2016/10/03 17:50:03.311015, >> 10, pid=26714, 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 (HQKONTRAST) >> [2016/10/03 17:50:03.311064, 10, pid=26714, effective(0, 0), real(0, >> 0), >> class=winbind] ../source3/winbindd/winbindd_cache.c:467(fetch_cache_seqnum) >> fetch_cache_seqnum: success [HQKONTRAST][4294967295 @ 1475509803] >> [2016/10/03 17:50:03.311081, 3, pid=26714, effective(0, 0), real(0, >> 0), >> class=winbind] ../source3/winbindd/winbindd_ads.c:1493(sequence_number) >> ads: fetch sequence_number for HQKONTRAST [2016/10/03 >> 17:50:03.311119, 10, pid=26714, effective(0, 0), real(0, 0), >> class=winbind] ../source3/winbindd/winbindd_ads.c:230(ads_cached_connection) >> ads_cached_connection [2016/10/03 17:50:03.311191, >> 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: >> preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 >> 17:50:03.321144, 3] ../source3/libads/ldap.c:618(ads_connect) >> Successfully contacted LDAP server <DC-IP> [2016/10/03 >> 17:50:03.321230, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) >> get_dc_list: preferred server list: "vl0227.hq.kontrast, >> *" [2016/10/03 17:50:03.323699, >> 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: >> preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 >> 17:50:03.328830, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) >> get_dc_list: preferred server list: "vl0227.hq.kontrast, >> *" [2016/10/03 17:50:03.332100, >> 3] ../source3/libads/ldap.c:618(ads_connect) Successfully contacted >> LDAP server <DC-IP> [2016/10/03 17:50:03.332177, >> 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: >> preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 >> 17:50:03.335277, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) >> get_dc_list: preferred server list: "vl0227.hq.kontrast, >> *" [2016/10/03 17:50:03.343177, >> 3] ../source3/libads/ldap.c:618(ads_connect) Successfully contacted >> LDAP server <DC-IP>5 [2016/10/03 17:50:03.343268, >> 3] ../source3/libads/ldap.c:661(ads_connect) Connected to LDAP server >> vl0227.hq.kontrast [2016/10/03 17:50:03.350195, >> 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) >> ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2 [2016/10/03 >> 17:50:03.350226, >> 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) >> ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2 [2016/10/03 >> 17:50:03.350238, >> 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) >> ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10 [2016/10/03 >> 17:50:03.379973, >> 0] ../source3/librpc/crypto/gse.c:341(gse_get_client_auth_token) >> gss_init_sec_context failed with [ The context has expired: Success] >> [2016/10/03 17:50:03.380079, >> 1] ../auth/gensec/spnego.c:623(gensec_spnego_create_negTokenInit) >> SPNEGO(gse_krb5) creating NEG_TOKEN_INIT failed: >> NT_STATUS_INTERNAL_ERROR [2016/10/03 17:50:03.380131, >> 0] ../source3/libads/sasl.c:785(ads_sasl_spnego_bind) kinit succeeded >> but ads_sasl_spnego_gensec_bind(KRB5) failed: An internal error >> occurred. [2016/10/03 17:50:03.380176, 1, pid=26714, effective(0, >> 0), real(0, 0), >> class=winbind] ../source3/winbindd/winbindd_ads.c:136(ads_cached_connection_connect) >> ads_connect for domain HQKONTRAST failed: An internal error occurred. >> [2016/10/03 17:50:03.380272, 3, pid=26714, effective(0, 0), real(0, >> 0), >> class=winbind] ../source3/winbindd/winbindd_ads.c:1493(sequence_number) >> ads: fetch sequence_number for HQKONTRAST [2016/10/03 >> 17:50:03.380291, 10, pid=26714, effective(0, 0), real(0, 0), >> class=winbind] ../source3/winbindd/winbindd_ads.c:230(ads_cached_connection) >> ads_cached_connection >> >> >> may this helps to find the problem :/ > > I have searched the logs on my DCs and a domain member and do not have > anything like the above in any of them. > > It is now 19 days uptime on the domain member and this isn't unusual, > it only went down last time because of a power problem. > > I repeat, I do not have this problem and the only difference between > your setup and mine (as far as I can see) is the PAM setup. > > Rowland > > -- > To unsubscribe from this list go to the following URL and read the > instructions: https://lists.samba.org/mailman/options/samba <https://lists.samba.org/mailman/options/samba>
Oliver Werner
2016-Oct-05 10:53 UTC
[Samba] Samba Member NT_STATUS_NETWORK_SESSION_EXPIRED
OMG Louis thats look really good!!! After going to Samba 4.4.5 i do not had that issue since last 20 hours :o i will check it next hours (i hope days :D) OLIVER WERNER Systemadministrator> Am 04.10.2016 um 09:21 schrieb L.P.H. van Belle <belle at bazuin.nl>: > > Samba 4.5.0 ... go back to 4.4.5/4.4.6 > > Check the bug list, 4.5.0 has lots of bugs.. > > Greetz. > > Louis > > >> -----Oorspronkelijk bericht----- >> Van: samba [mailto:samba-bounces at lists.samba.org <mailto:samba-bounces at lists.samba.org>] Namens Oliver Werner via >> samba >> Verzonden: dinsdag 4 oktober 2016 9:10 >> Aan: Rowland Penny >> CC: samba at lists.samba.org <mailto:samba at lists.samba.org> >> Onderwerp: Re: [Samba] Samba Member NT_STATUS_NETWORK_SESSION_EXPIRED >> >> so i add the pam yesterday and now after 10 hours no connection to member >> is possible. :( >> >> Same errors in logs i send yesterday >> OLIVER WERNER >> Systemadministrator >> >> >> >>> Am 03.10.2016 um 18:54 schrieb Rowland Penny via samba >> <samba at lists.samba.org>: >>> >>> On Mon, 3 Oct 2016 17:56:07 +0200 >>> Oliver Werner <oliver.werner at kontrast.de >> <mailto:oliver.werner at kontrast.de <mailto:oliver.werner at kontrast.de>>> wrote: >>> >>>> hey, >>>> >>>> now after observe last changes on the weekend… i have also the issue. >>>> >>>> After 10 hours i can’t connect to the shares on my member server. >>>> >>>> On Log of DC i found this: >>>> >>>> [2016/10/02 20:35:45.601265, >>>> 3] >> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >>>> Kerberos: AS-REQ PL0024$@HQ.KONTRAST from ipv4:<member-ip>:55578 for >>>> krbtgt/HQ.KONTRAST at HQ.KONTRAST [2016/10/02 20:35:45.605069, >>>> 3] >> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >>>> Kerberos: No preauth found, returning PREAUTH-REQUIRED -- >>>> PL0024$@HQ.KONTRAST [2016/10/02 20:35:45.605960, >>>> 3] >> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >>>> Kerberos: AS-REQ PL0024$@HQ.KONTRAST from ipv4:<member-ip>:52659 for >>>> krbtgt/HQ.KONTRAST at HQ.KONTRAST [2016/10/02 20:35:45.610083, >>>> 3] >> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >>>> Kerberos: Client sent patypes: encrypted-timestamp [2016/10/02 >>>> 20:35:45.610128, >>>> 3] >> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >>>> Kerberos: Looking for PKINIT pa-data -- PL0024$@HQ.KONTRAST >>>> [2016/10/02 20:35:45.610144, >>>> 3] >> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >>>> Kerberos: Looking for ENC-TS pa-data -- PL0024$@HQ.KONTRAST >>>> [2016/10/02 20:35:45.610200, >>>> 3] >> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >>>> Kerberos: ENC-TS Pre-authentication succeeded -- PL0024$@HQ.KONTRAST >>>> using arcfour-hmac-md5 [2016/10/02 20:35:45.617582, >>>> 3] >> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >>>> Kerberos: AS-REQ authtime: 2016-10-02T20:35:45 starttime: unset >>>> endtime: 2016-10-03T06:35:45 renew till: 2016-10-09T20:35:45 >>>> [2016/10/02 20:35:45.617699, >>>> 3] >> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >>>> Kerberos: Client supported enctypes: aes256-cts-hmac-sha1-96, >>>> aes128-cts-hmac-sha1-96, des3-cbc-sha1, des3-cbc-md5, >>>> arcfour-hmac-md5, using arcfour-hmac-md5/arcfou r-hmac-md5 >>>> [2016/10/02 20:35:45.617748, >>>> 3] >> ../source4/auth/kerberos/krb5_init_context.c:80(smb_krb5_debug_wrapper) >>>> Kerberos: Requested flags: renewable, forwardable [2016/10/02 >>>> 20:35:45.619243, >>>> 3] ../source4/smbd/service_stream.c:66(stream_terminate_connection) >>>> Terminating connection - 'ldapsrv_call_loop: >>>> tstream_read_pdu_blob_recv() - NT_STATUS_CONNECTION_DISCONNECTED‘ >>>> >>>> >>>> That looks ok, yes? When i see it means my member got a new ticket? >>>> But i found this on member: >>>> >>>> [2016/10/03 17:50:03.311002, 10, pid=26714, effective(0, 0), real(0, >>>> 0), >>>> class=winbind] >> ../source3/winbindd/winbindd_dual.c:512(child_process_request) >>>> child_process_request: request fn NDRCMD [2016/10/03 17:50:03.311015, >>>> 10, pid=26714, 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 (HQKONTRAST) >>>> [2016/10/03 17:50:03.311064, 10, pid=26714, effective(0, 0), real(0, >>>> 0), >>>> class=winbind] >> ../source3/winbindd/winbindd_cache.c:467(fetch_cache_seqnum) >>>> fetch_cache_seqnum: success [HQKONTRAST][4294967295 @ 1475509803] >>>> [2016/10/03 17:50:03.311081, 3, pid=26714, effective(0, 0), real(0, >>>> 0), >>>> class=winbind] ../source3/winbindd/winbindd_ads.c:1493(sequence_number) >>>> ads: fetch sequence_number for HQKONTRAST [2016/10/03 >>>> 17:50:03.311119, 10, pid=26714, effective(0, 0), real(0, 0), >>>> class=winbind] >> ../source3/winbindd/winbindd_ads.c:230(ads_cached_connection) >>>> ads_cached_connection [2016/10/03 17:50:03.311191, >>>> 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: >>>> preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 >>>> 17:50:03.321144, 3] ../source3/libads/ldap.c:618(ads_connect) >>>> Successfully contacted LDAP server <DC-IP> [2016/10/03 >>>> 17:50:03.321230, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) >>>> get_dc_list: preferred server list: "vl0227.hq.kontrast, >>>> *" [2016/10/03 17:50:03.323699, >>>> 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: >>>> preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 >>>> 17:50:03.328830, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) >>>> get_dc_list: preferred server list: "vl0227.hq.kontrast, >>>> *" [2016/10/03 17:50:03.332100, >>>> 3] ../source3/libads/ldap.c:618(ads_connect) Successfully contacted >>>> LDAP server <DC-IP> [2016/10/03 17:50:03.332177, >>>> 3] ../source3/libsmb/namequery.c:3117(get_dc_list) get_dc_list: >>>> preferred server list: "vl0227.hq.kontrast, *" [2016/10/03 >>>> 17:50:03.335277, 3] ../source3/libsmb/namequery.c:3117(get_dc_list) >>>> get_dc_list: preferred server list: "vl0227.hq.kontrast, >>>> *" [2016/10/03 17:50:03.343177, >>>> 3] ../source3/libads/ldap.c:618(ads_connect) Successfully contacted >>>> LDAP server <DC-IP>5 [2016/10/03 17:50:03.343268, >>>> 3] ../source3/libads/ldap.c:661(ads_connect) Connected to LDAP server >>>> vl0227.hq.kontrast [2016/10/03 17:50:03.350195, >>>> 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) >>>> ads_sasl_spnego_bind: got OID=1.2.840.48018.1.2.2 [2016/10/03 >>>> 17:50:03.350226, >>>> 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) >>>> ads_sasl_spnego_bind: got OID=1.2.840.113554.1.2.2 [2016/10/03 >>>> 17:50:03.350238, >>>> 3] ../source3/libads/sasl.c:733(ads_sasl_spnego_bind) >>>> ads_sasl_spnego_bind: got OID=1.3.6.1.4.1.311.2.2.10 [2016/10/03 >>>> 17:50:03.379973, >>>> 0] ../source3/librpc/crypto/gse.c:341(gse_get_client_auth_token) >>>> gss_init_sec_context failed with [ The context has expired: Success] >>>> [2016/10/03 17:50:03.380079, >>>> 1] ../auth/gensec/spnego.c:623(gensec_spnego_create_negTokenInit) >>>> SPNEGO(gse_krb5) creating NEG_TOKEN_INIT failed: >>>> NT_STATUS_INTERNAL_ERROR [2016/10/03 17:50:03.380131, >>>> 0] ../source3/libads/sasl.c:785(ads_sasl_spnego_bind) kinit succeeded >>>> but ads_sasl_spnego_gensec_bind(KRB5) failed: An internal error >>>> occurred. [2016/10/03 17:50:03.380176, 1, pid=26714, effective(0, >>>> 0), real(0, 0), >>>> class=winbind] >> ../source3/winbindd/winbindd_ads.c:136(ads_cached_connection_connect) >>>> ads_connect for domain HQKONTRAST failed: An internal error occurred. >>>> [2016/10/03 17:50:03.380272, 3, pid=26714, effective(0, 0), real(0, >>>> 0), >>>> class=winbind] ../source3/winbindd/winbindd_ads.c:1493(sequence_number) >>>> ads: fetch sequence_number for HQKONTRAST [2016/10/03 >>>> 17:50:03.380291, 10, pid=26714, effective(0, 0), real(0, 0), >>>> class=winbind] >> ../source3/winbindd/winbindd_ads.c:230(ads_cached_connection) >>>> ads_cached_connection >>>> >>>> >>>> may this helps to find the problem :/ >>> >>> I have searched the logs on my DCs and a domain member and do not have >>> anything like the above in any of them. >>> >>> It is now 19 days uptime on the domain member and this isn't unusual, >>> it only went down last time because of a power problem. >>> >>> I repeat, I do not have this problem and the only difference between >>> your setup and mine (as far as I can see) is the PAM setup. >>> >>> Rowland >>> >>> -- >>> To unsubscribe from this list go to the following URL and read the >>> instructions: https://lists.samba.org/mailman/options/samba >> <https://lists.samba.org/mailman/options/samba <https://lists.samba.org/mailman/options/samba>> >> -- >> To unsubscribe from this list go to the following URL and read the >> instructions: https://lists.samba.org/mailman/options/samba <https://lists.samba.org/mailman/options/samba>