search

hierynomus / smbj

Server Message Block (SMB2, SMB3) implementation in Java
Other
707 stars 180 forks source link

There are no credits left to send warning / Timeout Exception #564

Open szh202020 opened 4 years ago

szh202020 commented 4 years ago

I keep receiving the following warning: There are no credits left to send SMB2_SESSION_SETUP, will block until there are more credits available. This causes it to block until the 60 second timeout is hit which causes it to throw java timeout exception, infrastructure guys looked at the storage server and are not seeing any issues. I'm only getting this in production and currently don't have a way to reproduce in test environments.

hierynomus commented 4 years ago

@szh202020 What kind of server/appliance is the production machine. Can you get us a debug (or trace) log of SMBJ connecting to the host, where we see the warning/error message?

szh202020 commented 4 years ago

@hierynomus It's a Windows Server 2016. Let me look into enabling debug in prod and I'll get back to you.

szh202020 commented 4 years ago

@hierynomus Here is the debug log of SMBJ connection to the host when that issue occurs:

Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,696 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.PacketReader - Starting PacketReader on thread: Packet Reader for prd-server Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,696 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Negotiating dialects [SMB_2_0_2, SMB_2_1] with server prd-server Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,696 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1) credits to SMB2_NEGOTIATE with message id << 0 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,696 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_NEGOTIATE with message id << 0 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,696 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 0 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,698 [Packet Reader for prd-server] [ ] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@274cd09d Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,699 [Packet Reader for prd-server] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 1 credits for com.hierynomus.mssmb2.SMB2PacketData@274cd09d, now available: 1 credits Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,699 [Packet Reader for prd-server] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 0 >> to SMB2_NEGOTIATE with message id << 0 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,699 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Negotiated the following connection settings: ConnectionInfo{ serverGuid=0ed09fe5-65da-4fb5-9d7f-2215e2021881, serverName='prd-server', negotiatedProtocol=NegotiatedProtocol{dialect=SMB_2_1, maxTransactSize=8388608, maxReadSize=8388608, maxWriteSize=8388608}, clientGuid=84087084-b2fe-4929-9d0a-122991c02079, clientCapabilities=[SMB2_GLOBAL_CAP_DFS], serverCapabilities=[SMB2_GLOBAL_CAP_DFS, SMB2_GLOBAL_CAP_LEASING, SMB2_GLOBAL_CAP_LARGE_MTU], clientSecurityMode=0, serverSecurityMode=3, server='null' Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,699 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Initialized Authentication of svc-account using NTLM Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,699 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1) credits to SMB2_SESSION_SETUP with message id << 1 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,699 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 1 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,699 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 1 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - More processing required for authentication of svc-account using com.hierynomus.smbj.auth.NtlmAuthenticator@acbd91e Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received token: Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],] Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],] Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],] Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],] Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Sequence[[ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],]]] Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Enumerated[1] Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1ObjectIdentifier[1.3.6.1.4.1.311.2.2.10] Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1OctetString[[78, 84, 76, 77, 83, 83, 80, 0, 2, 0, 0, 0, 6, 0, 6, 0, 56, 0, 0, 0, 21, -126, -119, -30, -60, -70, -52, 50, -39, 92, 72, 29, 0, 0, 0, 0, 0, 0, 0, 0, -96, 0, -96, 0, 62, 0, 0, 0, 10, 0, 57, 56, 0, 0, 0, 15, 83, 0, 70, 0, 71, 0, 2, 0, 6, 0, 83, 0, 70, 0, 71, 0, 1, 0, 20, 0, 86, 0, 83, 0, 83, 0, 45, 0, 83, 0, 84, 0, 79, 0, 82, 0, 69, 0, 55, 0, 4, 0, 28, 0, 83, 0, 70, 0, 71, 0, 46, 0, 67, 0, 79, 0, 82, 0, 80, 0, 46, 0, 76, 0, 79, 0, 67, 0, 65, 0, 76, 0, 3, 0, 50, 0, 86, 0, 83, 0, 83, 0, 45, 0, 83, 0, 116, 0, 111, 0, 114, 0, 101, 0, 55, 0, 46, 0, 83, 0, 70, 0, 71, 0, 46, 0, 67, 0, 79, 0, 82, 0, 80, 0, 46, 0, 76, 0, 79, 0, 67, 0, 65, 0, 76, 0, 5, 0, 20, 0, 67, 0, 79, 0, 82, 0, 80, 0, 46, 0, 76, 0, 79, 0, 67, 0, 65, 0, 76, 0, 7, 0, 8, 0, -72, -87, 59, 35, -100, 84, -42, 1, 0, 0, 0, 0]] Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.ntlm.messages.NtlmChallenge - Windows version = WindowsVersion[WINDOWS_MAJOR_VERSION_10, WINDOWS_MINOR_VERSION_0, 14393, NTLMSSP_REVISION_W2K3] Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,701 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received NTLM challenge from: Domain Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,765 [http-nio-8080-exec-7] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 2 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,765 [http-nio-8080-exec-8] [ ] WARN com.hierynomus.smbj.connection.Connection - There are no credits left to send SMB2_SESSION_SETUP, will block until there are more credits available. Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,766 [Packet Reader for prd-server] [ ] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@2db4bbed Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,766 [Packet Reader for prd-server] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 1 credits for com.hierynomus.mssmb2.SMB2PacketData@2db4bbed, now available: 1 credits Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,766 [Packet Reader for prd-server] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 2 >> to SMB2_SESSION_SETUP with message id << 2 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,766 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 0) credits to SMB2_SESSION_SETUP with message id << 3 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,766 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 3 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,766 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 3 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,773 [http-nio-8080-exec-8] [ ] INFO com.hierynomus.smbj.connection.Connection - Successfully authenticated svc-account on prd-server, session is 299529475719681 Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,773 [http-nio-8080-exec-8] [ ] INFO com.hierynomus.smbj.session.Session - Connecting to \prd-server\r on session 299529475719681 Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,773 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 511) credits to SMB2_TREE_CONNECT with message id << 5 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,773 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_TREE_CONNECT with message id << 5 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,773 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 5 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,783 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1025) credits to SMB2_CREATE with message id << 7 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,783 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_CREATE with message id << 7 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,783 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 7 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,784 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1025) credits to SMB2_CLOSE with message id << 9 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,784 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_CLOSE with message id << 9 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,784 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 9 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,786 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1027) credits to SMB2_CREATE with message id << 11 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,786 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_CREATE with message id << 11 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,786 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 11 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,792 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.share.SMB2Writer - Writing to \prd-server\r\doc.pdf from offset 0 Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,792 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 11 (out of 1029) credits to SMB2_WRITE with message id << 13 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,792 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_WRITE with message id << 13 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,811 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 13 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,819 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1043) credits to SMB2_FLUSH with message id << 27 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,819 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_FLUSH with message id << 27 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,819 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 27 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,834 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1043) credits to SMB2_CLOSE with message id << 31 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,834 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_CLOSE with message id << 31 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,834 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 31 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,836 [http-nio-8080-exec-8] [ ] INFO com.hierynomus.smbj.session.Session - Logging off session 299576854579201 from host prd-server Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,836 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1044) credits to SMB2_TREE_DISCONNECT with message id << 32 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,836 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_TREE_DISCONNECT with message id << 32 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,836 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 32 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,839 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.session.Session - Notified of TreeDisconnected <<1>> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,839 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1050) credits to SMB2_LOGOFF with message id << 34 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,839 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_LOGOFF with message id << 34 >> Jul 07 15:21:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:21:03,839 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 34 >>

Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,840 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299576854579201 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,841 [http-nio-8080-exec-8] [ ] WARN com.hierynomus.smbj.connection.Connection - Exception while closing session 299576854579201 Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: com.hierynomus.protocol.transport.TransportException: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: java.util.concurrent.TimeoutException: Timeout expired at com.hierynomus.protocol.transport.TransportException$1.wrap(TransportException.java:29) at com.hierynomus.protocol.transport.TransportException$1.wrap(TransportException.java:23) at com.hierynomus.protocol.commons.concurrent.Futures.get(Futures.java:43) at com.hierynomus.smbj.session.Session.logoff(Session.java:247) at com.hierynomus.smbj.session.Session.close(Session.java:274) at com.hierynomus.smbj.connection.Connection.close(Connection.java:153) at com.hierynomus.smbj.connection.Connection.close(Connection.java:128) at com.company.helper.FileOperationsHelper.writeDocument(FileOperationsHelper.java:143) at com.company.helper.UploadDocServiceHelper.write(UploadDocServiceHelper.java:277) at com.company.helper.UploadDocServiceHelper.transferDocument(UploadDocServiceHelper.java:222) at com.company.impl.DocumentsServiceImpl.uploadDocument(DocumentsServiceImpl.java:234) at com.company.impl.DocumentsServiceImpl$$FastClassBySpringCGLIB$$5bd5c52.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:736) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:84) at com.company.ent.metrics.aop.TimerAspect.doInTimer(TimerAspect.java:79) at com.company.ent.metrics.aop.TimerAspect.publicServiceMethod(TimerAspect.java:62) at sun.reflect.GeneratedMethodAccessor157.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:627) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:616) at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:671) at com.company.impl.DocumentsServiceImpl$$EnhancerBySpringCGLIB$$77903236.uploadDocument() at com.company.ent.imaging.controller.DocumentsController.uploadDocument(DocumentsController.java:197) at com.company.ent.imaging.controller.DocumentsController$$FastClassBySpringCGLIB$$87744882.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:736) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:84) at com.company.ent.metrics.aop.TimerAspect.doInTimer(TimerAspect.java:79) at com.company.ent.metrics.aop.TimerAspect.publicControllerMethod(TimerAspect.java:57) at sun.reflect.GeneratedMethodAccessor167.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:627) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:616) at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:69) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:671) at com.company.ent.imaging.controller.DocumentsController$$EnhancerBySpringCGLIB$$e1f00c71.uploadDocument() at sun.reflect.GeneratedMethodAccessor196.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872) at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.company.springsecurity.filter.SingleSignOutFilter.doFilter(SingleSignOutFilter.java:44) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.company.hystrix.HystrixReqeustContextServletFilter.doFilter(HystrixReqeustContextServletFilter.java:14) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:111) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:317) at com.company.springsecurity.servicepass.filter.ServicePassFilter.doFilter(ServicePassFilter.java:71) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at com.company.springsecurity.servicepass.authentication.filter.ServicePassAuthenticationFilter.doFilter(ServicePassAuthenticationFilter.java:169) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:158) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at com.company.springsecurity.filter.SingleSignOutFilter.doFilter(SingleSignOutFilter.java:44) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:66) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:214) at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:177) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:347) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:263) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:167) at org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:80) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:103) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.company.boot.proxy.ProxyHeadersFilter.doFilter(ProxyHeadersFilter.java:19) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:800) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1471) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: Caused by: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: java.util.concurrent.TimeoutException: Timeout expired at com.hierynomus.protocol.commons.concurrent.PromiseBackedFuture.get(PromiseBackedFuture.java:60) at com.hierynomus.protocol.commons.concurrent.CancellableFuture.get(CancellableFuture.java:84) at com.hierynomus.protocol.commons.concurrent.Futures.get(Futures.java:38) ... 167 common frames omitted Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: Caused by: com.hierynomus.smbj.common.SMBRuntimeException: java.util.concurrent.TimeoutException: Timeout expired at com.hierynomus.smbj.common.SMBRuntimeException$1.wrap(SMBRuntimeException.java:27) at com.hierynomus.smbj.common.SMBRuntimeException$1.wrap(SMBRuntimeException.java:21) at com.hierynomus.protocol.commons.concurrent.Promise.retrieve(Promise.java:136) at com.hierynomus.protocol.commons.concurrent.PromiseBackedFuture.get(PromiseBackedFuture.java:58) ... 169 common frames omitted Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: Caused by: java.util.concurrent.TimeoutException: Timeout expired ... 171 common frames omitted Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] INFO com.hierynomus.smbj.session.Session - Logging off session 299529475719681 from host prd-server Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1055) credits to SMB2_LOGOFF with message id << 37 >> Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,842 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.connection.Connection - Session << 299529475719681 >> logged off Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,854 [http-nio-8080-exec-8] [ ] WARN com.hierynomus.smbj.connection.Connection - Exception while closing session 299529475719681 Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: com.hierynomus.protocol.transport.TransportException: Cannot write SMB2_LOGOFF with message id << 37 >> as transport is disconnected at com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport.write(DirectTcpTransport.java:68) at com.hierynomus.smbj.connection.Connection.send(Connection.java:297) at com.hierynomus.smbj.session.Session.send(Session.java:292) at com.hierynomus.smbj.session.Session.logoff(Session.java:247) at com.hierynomus.smbj.session.Session.close(Session.java:274) at com.hierynomus.smbj.connection.Connection.close(Connection.java:153) at com.hierynomus.smbj.connection.Connection.close(Connection.java:128) at com.company.helper.FileOperationsHelper.writeDocument(FileOperationsHelper.java:143) at com.company.helper.UploadDocServiceHelper.write(UploadDocServiceHelper.java:277) at com.company.helper.UploadDocServiceHelper.transferDocument(UploadDocServiceHelper.java:222) at com.company.impl.DocumentsServiceImpl.uploadDocument(DocumentsServiceImpl.java:234) at com.company.impl.DocumentsServiceImpl$$FastClassBySpringCGLIB$$5bd5c52.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:736) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:84) at com.company.ent.metrics.aop.TimerAspect.doInTimer(TimerAspect.java:79) at com.company.ent.metrics.aop.TimerAspect.publicServiceMethod(TimerAspect.java:62) at sun.reflect.GeneratedMethodAccessor157.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:627) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:616) at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:671) at com.company.impl.DocumentsServiceImpl$$EnhancerBySpringCGLIB$$77903236.uploadDocument() at com.company.ent.imaging.controller.DocumentsController.uploadDocument(DocumentsController.java:197) at com.company.ent.imaging.controller.DocumentsController$$FastClassBySpringCGLIB$$87744882.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:736) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:84) at com.company.ent.metrics.aop.TimerAspect.doInTimer(TimerAspect.java:79) at com.company.ent.metrics.aop.TimerAspect.publicControllerMethod(TimerAspect.java:57) at sun.reflect.GeneratedMethodAccessor167.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:627) at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:616) at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:70) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:69) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:671) at com.company.ent.imaging.controller.DocumentsController$$EnhancerBySpringCGLIB$$e1f00c71.uploadDocument() at sun.reflect.GeneratedMethodAccessor196.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133) at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827) at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738) at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:872) at javax.servlet.http.HttpServlet.service(HttpServlet.java:661) at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846) at javax.servlet.http.HttpServlet.service(HttpServlet.java:742) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.company.springsecurity.filter.SingleSignOutFilter.doFilter(SingleSignOutFilter.java:44) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.company.hystrix.HystrixReqeustContextServletFilter.doFilter(HystrixReqeustContextServletFilter.java:14) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:111) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:317) at com.company.springsecurity.servicepass.filter.ServicePassFilter.doFilter(ServicePassFilter.java:71) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at com.company.springsecurity.servicepass.authentication.filter.ServicePassAuthenticationFilter.doFilter(ServicePassAuthenticationFilter.java:169) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:158) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at com.company.springsecurity.filter.SingleSignOutFilter.doFilter(SingleSignOutFilter.java:44) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:66) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331) at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:214) at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:177) at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:347) at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:263) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:109) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:93) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.session.web.http.SessionRepositoryFilter.doFilterInternal(SessionRepositoryFilter.java:167) at org.springframework.session.web.http.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:80) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:103) at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at com.company.boot.proxy.ProxyHeadersFilter.doFilter(ProxyHeadersFilter.java:19) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:493) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342) at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:800) at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66) at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:800) at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1471) at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,854 [http-nio-8080-exec-8] [ ] INFO com.hierynomus.smbj.connection.Connection - Closed connection to prd-server Jul 07 15:22:03 web-service-c8d77d485-kk9rv web-service: 2020-07-07 20:22:03,854 [http-nio-8080-exec-8] [ ] DEBUG com.hierynomus.smbj.SMBClient - Connection to << prd-server:445 >> closed

szh202020 commented 4 years ago

@hierynomus any advice on this issue? Still occurs almost daily.

rummepa commented 3 years ago

Is there any progress on this ? I have a customer who is running into a similar problem.

wworku commented 3 years ago

Hi everyone did you ever manage to resolve this issue? I am facing the same thing now in production

hierynomus commented 3 years ago

Also see https://github.com/hierynomus/smbj/issues/270 for the same issue.

From discussion on that ticket, it is most likely a problem on the server side, as the last comment noted that even smbclient from the Samba team runs into this problem.

ayur2021 commented 3 years ago

@hierynomus There is the const PREFERRED_MINIMUM_CREDITS in com.hierynomus.smbj.connection.SequenceWindow that is set to 512, and in com.hierynomus.smbj.connection.Connection in the function send() the way that the credits are calculated is Math.max(512 - availableCredits - grantCredits, grantCredits). Can that param be configurable in future version when creating the connection? In NETAPP machines, the default value for the credits is 128 so I think the current configuration of the client is what's making everyone that's facing this issue to fail. I checked the behaviour between 2 Windows Server (one client and one server), the server was configured to Smb2CreditsMin=0 and Smb2CreditsMax=0. Using Wireshark the client never requests more credits than the minimum configured on the Server (in this case 0), all client requests are 0 and the server automatically grants 1 credit. When testing SMBJ I saw that the client is continuously asking for 511.

tsnsteelersfan commented 2 years ago

Any update on this issue? Just experienced this for the first time as well.

zacharybest commented 6 months ago

Was doing some testing using a MuleSoft SMB connector, which uses SMBJ.

In working with infrastructure, we found that a smart firewall was interpreting the traffic as a DDOS attack. In this case, the traffic would be blocked, but the errrors and warning we would receive were about credits not being available.