Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

java.io.EOFException: EOF while reading packet #653

Closed
ghost opened this issue Jul 15, 2021 · 96 comments
Closed

java.io.EOFException: EOF while reading packet #653

ghost opened this issue Jul 15, 2021 · 96 comments
Assignees

Comments

@ghost
Copy link

ghost commented Jul 15, 2021

We are currently evaluating smbj and tested it using 3 shares (cannot add the real names here):

Share 1: \\samba_server\smb_with_optional_encryption
Share 2: \\windows_server\smb_with_enforced_encryption
Share 3: \\nas_server\smb_without_encryption

Using smbj 0.10.0 we saw the following behaviour:
Share 1 is OK: accessible (SMB_2_1)
Share 2 is OK: access denied (SMB_2_1)
Share 3 is OK: accessible (SMB_2_1)

Using smbj 0.11.1 we got an error with share 3:
Share 1 is OK: accessible (SMB_3_1_1)
Share 2 is OK: accessible (SMB_3_0_2)
Share 3 is not OK: throws the following error, no matter which configuration parameters we use or if we use no configuration at all:

Exception in thread "main" com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.connection.SMBSessionBuilder.establish(SMBSessionBuilder.java:114)
	at com.hierynomus.smbj.connection.Connection.authenticate(Connection.java:192)
	at com.my.app.SmbTest.main(SmbTest.java:1676)
Caused by: com.hierynomus.protocol.transport.TransportException: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.protocol.transport.TransportException$1.wrap(TransportException.java:30)
	at com.hierynomus.protocol.transport.TransportException$1.wrap(TransportException.java:24)
	at com.hierynomus.protocol.commons.concurrent.Futures.get(Futures.java:47)
	at com.hierynomus.smbj.connection.Connection.sendAndReceive(Connection.java:232)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.initiateSessionSetup(SMBSessionBuilder.java:197)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:126)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:142)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.establish(SMBSessionBuilder.java:109)
	... 2 more
Caused by: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.protocol.commons.concurrent.PromiseBackedFuture.get(PromiseBackedFuture.java:59)
	at com.hierynomus.protocol.commons.concurrent.CancellableFuture.get(CancellableFuture.java:84)
	at com.hierynomus.protocol.commons.concurrent.Futures.get(Futures.java:42)
	... 7 more
Caused by: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.common.SMBRuntimeException$1.wrap(SMBRuntimeException.java:28)
	at com.hierynomus.smbj.common.SMBRuntimeException$1.wrap(SMBRuntimeException.java:22)
	at com.hierynomus.protocol.commons.concurrent.Promise.deliverError(Promise.java:95)
	at com.hierynomus.smbj.connection.OutstandingRequests.handleError(OutstandingRequests.java:88)
	at com.hierynomus.smbj.connection.Connection.handleError(Connection.java:282)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:54)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readFully(DirectTcpPacketReader.java:72)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readTcpHeader(DirectTcpPacketReader.java:59)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.doRead(DirectTcpPacketReader.java:48)
	at com.hierynomus.smbj.transport.PacketReader.readPacket(PacketReader.java:70)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:48)
	... 1 more
Caused by: java.io.EOFException: EOF while reading packet
	... 6 more

We used the following code to test the library (only changed the SmbConfig using different parameters, e.g. withEncryptData(true) etc.):

SmbConfig config = SmbConfig.builder()
		.withSecurityProvider(new BCSecurityProvider())
		.build();
SMBClient client = new SMBClient(config);
SmbPath smbDir = SmbPath.parse("\\\\samba\\smb_with_optional_encryption");

try (com.hierynomus.smbj.connection.Connection connection = client.connect(smbDir.getHostname()))
{
	System.out.println("connected to: " + connection.getRemoteHostname() + "; protocol: "
			+ connection.getNegotiatedProtocol());
	AuthenticationContext ac = new AuthenticationContext("user1", pass.toCharArray(), "domain.com");
	Session session = connection.authenticate(ac);

	try (DiskShare share = (DiskShare) session.connectShare(smbDir.getShareName()))
	{
		for (FileIdBothDirectoryInformation f : share.list(smbDir.getPath()))
		{
			System.out.println("File : " + f.getFileName());
		}
	}
}

Any idea what's going wrong here?

@acarlsen
Copy link

I have the same issue, works with 0.10.0 but not with 0.11.1 - trying to connect to Samba server running in docker on Raspberry Pi - fresh Samba/Docker install from this repo: https://github.com/alexandreroman/rpi-samba
I tried forcing all dialects individually, tried with every SmbConfig option.. same error as above: EOF while reading packet

Using this Samba config:

[global]
socket options = TCP_NODELAY IPTOS_LOWDELAY SO_RCVBUF=65536 SO_SNDBUF=65536
smb ports = 445
max protocol = SMB2
min receivefile size = 16384
deadtime = 30
os level = 20
map to guest = bad user
printer = bsd
printcap name = /dev/null
load printers = no
create mask = 0644
force create mode = 0644
directory mask = 0755
force directory mode = 0755
browsable = yes
writable = yes
guest account = root
force user = root
force group = root
[Public]
path = /data/share
guest ok = yes
read only = no

@shallem
Copy link

shallem commented Feb 11, 2022

I am seeing the same issue with a NAS device. Is there any resolution to this issue, or any known workaround? I am using SMBJ 0.11.1, and I am seeing the same regression from 0.10.0, where this was working. I have also tried to force the dialect to SMB 2.1 and that does not seem to help.

@ghost
Copy link
Author

ghost commented Mar 1, 2022

Recently tried 0.11.5, same error. We still have to stick to 0.10.0.

@bjoernlohrmann
Copy link

bjoernlohrmann commented Jul 1, 2022

We (knime.com) have recently upgraded to 0.11.5 and are seeing this issue with our customers as well. Are there any news on how this could be fixed or worked around? (other than downgrading to 0.10)

@ZwoCa
Copy link

ZwoCa commented Mar 16, 2023

I've seen similar problems in one customers environment. I don't know for sure yet what environment he is using, but I think that in this specific case the SMB it is some kind of IBM solution. I'm still trying to get the necessary data from the customer and need to anonymize it. I hope I'm able to provide useful logs later on, although I'm afraid I won't manage to get a TCP dump.

I can already tell that in this specific case, SMB_2_1 dialect is negotiated between server and client. The "EOF while reading packet" occurs when the DirectTcpPacketReader reads the header of the second SMB2_SESSION_SETUP packet (first packet has status STATUS_MORE_PROCESSING_REQUIRED):

[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 3 >>
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 3 >>
[Packet Reader for xxx] INFO  com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - PacketReader error, got exception.
com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readFully(DirectTcpPacketReader.java:72)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readTcpHeader(DirectTcpPacketReader.java:59)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.doRead(DirectTcpPacketReader.java:48)
	at com.hierynomus.smbj.transport.PacketReader.readPacket(PacketReader.java:70)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:48)
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: java.io.EOFException: EOF while reading packet
	... 6 more

Browsing old commits, I found this change. I'm not sure if I understand the code correctly, but it seems to me like this could be a regression because the SMBSessionBuilder (which since 0.11.x replaces the old code linked above) only respects a so called "preauthSession" in case SMB_3_1_1 dialect is used.
EDIT: The difference in using the preauthSessionTable might be a bit more obvious when comparing authentication in 0.10.0 and session setup in 0.11.5.

@hierynomus hierynomus self-assigned this Mar 17, 2023
@ZwoCa
Copy link

ZwoCa commented Mar 17, 2023

Good morning, I just got together all the logs and stripped them from customers data. While I think my finding from above may still be a problem, it seems not to be the cause for the troubles my customer is experiencing. I've run a test using SMB_3_1_1 dialect, so the questionable if-conditions should be fulfilled, but the error remains the same.

I've written a simple test application which creates a folder on a share. This test application I've built once with smbj 0.10.0 and once with 0.11.5, the later variant I've run both setting SMB_2_1 dialect in SmbConfig or leaving the dialects default. The log output (level TRACE) is below.

0.10.0 - working example
[main] DEBUG com.hierynomus.protocol.commons.socket.ProxySocketFactory - Connecting to host.domain.net/123.123.123.123:445
[main] DEBUG com.hierynomus.smbj.transport.PacketReader - Starting PacketReader on thread: Packet Reader for host.domain.net
[main] DEBUG com.hierynomus.smbj.connection.Connection - Negotiating dialects [SMB_2_0_2, SMB_2_1] with server host.domain.net
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB_COM_NEGOTIATE >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB_COM_NEGOTIATE
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB_COM_NEGOTIATE sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 0 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@14954813
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 1 credits for com.hierynomus.mssmb2.SMB2PacketData@14954813, now available: 1 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@14954813 took << 11 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 0 >> to `SMB2_NEGOTIATE with message id << 0 >>`
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1) credits to SMB2_NEGOTIATE with message id << 1 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_NEGOTIATE with message id << 1 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_NEGOTIATE with message id << 1 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_NEGOTIATE with message id << 1 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 1 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@44001200
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 129 credits for com.hierynomus.mssmb2.SMB2PacketData@44001200, now available: 129 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@44001200 took << 3 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 1 >> to `SMB2_NEGOTIATE with message id << 1 >>`
[main] DEBUG com.hierynomus.smbj.connection.Connection - Negotiated the following connection settings: ConnectionInfo{
  serverGuid=65abcfd4-f6aa-4108-97ca-a18edc0dd48f,
  serverName='host.domain.net',
  negotiatedProtocol=NegotiatedProtocol{dialect=SMB_2_1, maxTransactSize=8388608, maxReadSize=8388608, maxWriteSize=8388608},
  clientGuid=16f77aa6-a2fb-4d00-acaf-e2c0ac8b9459,
  clientCapabilities=[SMB2_GLOBAL_CAP_DFS],
  serverCapabilities=[SMB2_GLOBAL_CAP_DFS, SMB2_GLOBAL_CAP_LEASING, SMB2_GLOBAL_CAP_LARGE_MTU],
  clientSecurityMode=0,
  serverSecurityMode=1,
  server='null'
}
[main] INFO  com.hierynomus.smbj.connection.Connection - Successfully connected to: host.domain.net
[main] INFO  de.smbjVersionTester.SmbClient - Authenticating user 'user'...
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Initialized Authentication of user using NTLM
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 129) credits to SMB2_SESSION_SETUP with message id << 2 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 2 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 2 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 2 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 2 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@27e75b0a
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 129 credits for com.hierynomus.mssmb2.SMB2PacketData@27e75b0a, now available: 257 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@27e75b0a took << 2 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 2 >> to `SMB2_SESSION_SETUP with message id << 2 >>`
[main] DEBUG com.hierynomus.smbj.connection.Connection - More processing required for authentication of user using com.hierynomus.smbj.auth.NtlmAuthenticator@76a2ddf3
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received token: (... anonymized)
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 222
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,CONSTRUCTED,16]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 219
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 3
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 12
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 197
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],<unknown>]
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Sequence[[ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],<unknown>], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],<unknown>]]]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,10]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 1
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Enumerated[1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,6]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 10
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1ObjectIdentifier[1.3.6.1.4.1.311.2.2.10]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,4]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 194
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1OctetString[(... anonymized)]
[main] TRACE com.hierynomus.ntlm.messages.NtlmChallenge - NTLM channel contains MsvAvNdDomainName(2) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.NtlmChallenge - NTLM channel contains MsvAvNbComputerName(1) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.NtlmChallenge - NTLM channel contains MsvAvDnsDomainName(4) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.NtlmChallenge - NTLM channel contains MsvAvDnsComputerName(3) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.NtlmChallenge - NTLM channel contains MsvAvTimestamp(7) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.NtlmChallenge - NTLM channel contains MsvAvEOL(0) TargetInfo
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received NTLM challenge from: ChallengeTarget
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 257) credits to SMB2_SESSION_SETUP with message id << 3 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 3 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 3 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 3 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 3 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@4073e087
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 129 credits for com.hierynomus.mssmb2.SMB2PacketData@4073e087, now available: 385 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@4073e087 took << 4 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 3 >> to `SMB2_SESSION_SETUP with message id << 3 >>`
[main] INFO  com.hierynomus.smbj.connection.Connection - Successfully authenticated user on host.domain.net, session is 7211397476081734183
[main] INFO  de.smbjVersionTester.SmbClient - Connecting to share 'SHARE'...
[main] INFO  com.hierynomus.smbj.session.Session - Connecting to \\host.domain.net\SHARE on session 7211397476081734183
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 385) credits to SMB2_TREE_CONNECT with message id << 4 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_TREE_CONNECT with message id << 4 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_TREE_CONNECT with message id << 4 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_TREE_CONNECT with message id << 4 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 4 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@12907925
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 127 credits for com.hierynomus.mssmb2.SMB2PacketData@12907925, now available: 511 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@12907925 took << 3 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 4 >> to `SMB2_TREE_CONNECT with message id << 4 >>`
[main] INFO  de.smbjVersionTester.SmbClient - Connection established...
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 511) credits to SMB2_CREATE with message id << 5 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_CREATE with message id << 5 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_CREATE with message id << 5 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_CREATE with message id << 5 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 5 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@33a4204a
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 2 credits for com.hierynomus.mssmb2.SMB2PacketData@33a4204a, now available: 512 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@33a4204a took << 2 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 5 >> to `SMB2_CREATE with message id << 5 >>`
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 512) credits to SMB2_CLOSE with message id << 6 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_CLOSE with message id << 6 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_CLOSE with message id << 6 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_CLOSE with message id << 6 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 6 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@3c856f1b
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 1 credits for com.hierynomus.mssmb2.SMB2PacketData@3c856f1b, now available: 512 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@3c856f1b took << 1 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 6 >> to `SMB2_CLOSE with message id << 6 >>`
[main] INFO  de.smbjVersionTester.SmbClient - Creating folder 'WHIMG' in 'SHARE' of the share...
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 512) credits to SMB2_CREATE with message id << 7 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_CREATE with message id << 7 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_CREATE with message id << 7 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_CREATE with message id << 7 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 7 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@43754439
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 1 credits for com.hierynomus.mssmb2.SMB2PacketData@43754439, now available: 512 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@43754439 took << 5 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 7 >> to `SMB2_CREATE with message id << 7 >>`
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 512) credits to SMB2_CLOSE with message id << 8 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_CLOSE with message id << 8 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_CLOSE with message id << 8 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_CLOSE with message id << 8 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 8 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@18ffacaf
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 1 credits for com.hierynomus.mssmb2.SMB2PacketData@18ffacaf, now available: 512 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@18ffacaf took << 2 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 8 >> to `SMB2_CLOSE with message id << 8 >>`
[main] INFO  de.smbjVersionTester.SmbClient - Creating the folder succeeded.
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 512) credits to SMB2_TREE_DISCONNECT with message id << 9 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_TREE_DISCONNECT with message id << 9 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_TREE_DISCONNECT with message id << 9 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_TREE_DISCONNECT with message id << 9 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 9 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@77c4c46f
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 1 credits for com.hierynomus.mssmb2.SMB2PacketData@77c4c46f, now available: 512 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@77c4c46f took << 2 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 9 >> to `SMB2_TREE_DISCONNECT with message id << 9 >>`
[main] DEBUG com.hierynomus.smbj.session.Session - Notified of TreeDisconnected <<1>>
[main] INFO  com.hierynomus.smbj.session.Session - Logging off session 7211397476081734183 from host host.domain.net
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 512) credits to SMB2_LOGOFF with message id << 10 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_LOGOFF with message id << 10 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_LOGOFF with message id << 10 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_LOGOFF with message id << 10 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 10 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.PacketReader - Received packet com.hierynomus.mssmb2.SMB2PacketData@602e903b
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.Connection - Server granted us 1 credits for com.hierynomus.mssmb2.SMB2PacketData@602e903b, now available: 512 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.Connection - Send/Recv of packet com.hierynomus.mssmb2.SMB2PacketData@602e903b took << 1 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 10 >> to `SMB2_LOGOFF with message id << 10 >>`
[main] DEBUG com.hierynomus.smbj.connection.Connection - Session << 7211397476081734183 >> logged off
[main] DEBUG com.hierynomus.smbj.transport.PacketReader - Stopping PacketReader...
[main] INFO  com.hierynomus.smbj.connection.Connection - Closed connection to host.domain.net
[main] DEBUG com.hierynomus.smbj.SMBClient - Connection to << host.domain.net:445 >> closed
[main] INFO  com.hierynomus.smbj.SMBClient - Going to close all remaining connections
[Packet Reader for host.domain.net] INFO  com.hierynomus.smbj.transport.PacketReader - Thread[Packet Reader for host.domain.net,5,main] stopped.
0.11.5, using SMB_2_1 - not working
[main] DEBUG com.hierynomus.protocol.commons.socket.ProxySocketFactory - Connecting to host.domain.net/123.123.123.123:445
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Starting PacketReader on thread: Packet Reader for host.domain.net
[main] DEBUG com.hierynomus.smbj.connection.SMBProtocolNegotiator - Negotiating dialects [SMB_2_0_2, SMB_2_1]
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB_COM_NEGOTIATE >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB_COM_NEGOTIATE
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB_COM_NEGOTIATE sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 0 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_NEGOTIATE with message id << 0 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 1 credits for SMB2_NEGOTIATE with message id << 0 >>, now available: 1 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_NEGOTIATE with message id << 0 >> took << 10 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 0 >> to `SMB2_NEGOTIATE with message id << 0 >>`
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1) credits to SMB2_NEGOTIATE with message id << 1 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_NEGOTIATE with message id << 1 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_NEGOTIATE with message id << 1 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_NEGOTIATE with message id << 1 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 1 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_NEGOTIATE with message id << 1 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 129 credits for SMB2_NEGOTIATE with message id << 1 >>, now available: 129 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_NEGOTIATE with message id << 1 >> took << 2 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 1 >> to `SMB2_NEGOTIATE with message id << 1 >>`
[main] DEBUG com.hierynomus.smbj.connection.SMBProtocolNegotiator - Negotiated the following connection settings: ConnectionContext{
  serverGuid=65abcfd4-f6aa-4108-97ca-a18edc0dd48f,
  serverName='host.domain.net',
  negotiatedProtocol=NegotiatedProtocol{dialect=SMB_2_1, maxTransactSize=8388608, maxReadSize=8388608, maxWriteSize=8388608},
  clientGuid=e636161b-012b-4b3d-99eb-761d899d51db,
  clientCapabilities=[],
  serverCapabilities=[SMB2_GLOBAL_CAP_DFS, SMB2_GLOBAL_CAP_LEASING, SMB2_GLOBAL_CAP_LARGE_MTU],
  clientSecurityMode=1,
  serverSecurityMode=1,
  server='com.hierynomus.smbj.server.Server@78d6692f'
}
[main] INFO  com.hierynomus.smbj.connection.PacketEncryptor - Initialized PacketEncryptor with Cipher << AES_128_CCM >>
[main] INFO  com.hierynomus.smbj.connection.Connection - Successfully connected to: host.domain.net
[main] INFO  de.smbjVersionTester.SmbClient - Authenticating user 'user'...
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Initialized Authentication of user using NTLM
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 129) credits to SMB2_SESSION_SETUP with message id << 2 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 2 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 2 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 2 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 2 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_SESSION_SETUP with message id << 2 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 129 credits for SMB2_SESSION_SETUP with message id << 2 >>, now available: 257 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_SESSION_SETUP with message id << 2 >> took << 3 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 2 >> to `SMB2_SESSION_SETUP with message id << 2 >>`
[main] DEBUG com.hierynomus.smbj.connection.SMBSessionBuilder - More processing required for authentication of user using com.hierynomus.smbj.auth.NtlmAuthenticator@5e4bd84a
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received token: (... anonymized)
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 222
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,CONSTRUCTED,16]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 219
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 3
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 12
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 197
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],<unknown>]
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Sequence[[ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],<unknown>], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],<unknown>]]]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,10]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 1
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Enumerated[1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,6]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 10
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1ObjectIdentifier[1.3.6.1.4.1.311.2.2.10]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,4]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 194
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1OctetString[(... anonymized)]]
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvNdDomainName(2) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvNbComputerName(1) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvDnsDomainName(4) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvDnsComputerName(3) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvTimestamp(7) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvEOL(0) TargetInfo
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received NTLM challenge from: ChallengeTarget
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 257) credits to SMB2_SESSION_SETUP with message id << 3 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 3 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 3 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 3 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 3 >>
[Packet Reader for host.domain.net] INFO  com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - PacketReader error, got exception.
com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readFully(DirectTcpPacketReader.java:72)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readTcpHeader(DirectTcpPacketReader.java:59)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.doRead(DirectTcpPacketReader.java:48)
	at com.hierynomus.smbj.transport.PacketReader.readPacket(PacketReader.java:70)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:48)
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: java.io.EOFException: EOF while reading packet
	... 6 more
[main] ERROR com.hierynomus.protocol.commons.concurrent.Promise - << 3 >> woke to: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Stopping PacketReader...
[Packet Reader for host.domain.net] INFO  com.hierynomus.smbj.connection.Connection - Closed connection to host.domain.net
[main] INFO  com.hierynomus.smbj.connection.Connection - Closed connection to host.domain.net
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.SMBClient - Connection to << host.domain.net:445 >> closed
[main] DEBUG com.hierynomus.smbj.SMBClient - Connection to << host.domain.net:445 >> closed
[main] INFO  com.hierynomus.smbj.SMBClient - Going to close all remaining connections
[main] ERROR de.smbjVersionTester.Application - Could not authenticate user:
com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.connection.SMBSessionBuilder.establish(SMBSessionBuilder.java:114)
	at com.hierynomus.smbj.connection.Connection.authenticate(Connection.java:202)
	at de.smbjVersionTester.SmbClient.doWithShare(SmbClient.java:248)
	at de.smbjVersionTester.SmbClient.createFolder(SmbClient.java:74)
	at de.smbjVersionTester.SmbClient.checkConnection(SmbClient.java:52)
	at de.smbjVersionTester.Application.main(Application.java:61)
Caused by: com.hierynomus.protocol.transport.TransportException: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.protocol.transport.TransportException$1.wrap(TransportException.java:30)
	at com.hierynomus.protocol.transport.TransportException$1.wrap(TransportException.java:24)
	at com.hierynomus.protocol.commons.concurrent.Futures.get(Futures.java:47)
	at com.hierynomus.smbj.connection.Connection.sendAndReceive(Connection.java:242)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.initiateSessionSetup(SMBSessionBuilder.java:197)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:126)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:142)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.establish(SMBSessionBuilder.java:109)
	... 5 more
Caused by: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.protocol.commons.concurrent.PromiseBackedFuture.get(PromiseBackedFuture.java:59)
	at com.hierynomus.protocol.commons.concurrent.CancellableFuture.get(CancellableFuture.java:84)
	at com.hierynomus.protocol.commons.concurrent.Futures.get(Futures.java:42)
	at com.hierynomus.smbj.connection.Connection.sendAndReceive(Connection.java:242)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.initiateSessionSetup(SMBSessionBuilder.java:197)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:126)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:142)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.establish(SMBSessionBuilder.java:109)
	... 5 more
Caused by: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.common.SMBRuntimeException$1.wrap(SMBRuntimeException.java:28)
	at com.hierynomus.smbj.common.SMBRuntimeException$1.wrap(SMBRuntimeException.java:22)
	at com.hierynomus.protocol.commons.concurrent.Promise.deliverError(Promise.java:95)
	at com.hierynomus.smbj.connection.OutstandingRequests.handleError(OutstandingRequests.java:88)
	at com.hierynomus.smbj.connection.Connection.handleError(Connection.java:292)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:54)
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readFully(DirectTcpPacketReader.java:72)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readTcpHeader(DirectTcpPacketReader.java:59)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.doRead(DirectTcpPacketReader.java:48)
	at com.hierynomus.smbj.transport.PacketReader.readPacket(PacketReader.java:70)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:48)
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readFully(DirectTcpPacketReader.java:72)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readTcpHeader(DirectTcpPacketReader.java:59)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.doRead(DirectTcpPacketReader.java:48)
	at com.hierynomus.smbj.transport.PacketReader.readPacket(PacketReader.java:70)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:48)
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
0.11.5, dialect not configured (using SMB_3_1_1) - not working
[main] DEBUG com.hierynomus.protocol.commons.socket.ProxySocketFactory - Connecting to host.domain.net/123.123.123.123:445
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Starting PacketReader on thread: Packet Reader for host.domain.net
[main] DEBUG com.hierynomus.smbj.connection.SMBProtocolNegotiator - Negotiating dialects [SMB_2_0_2, SMB_2_1, SMB_3_0, SMB_3_0_2, SMB_3_1_1]
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB_COM_NEGOTIATE >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB_COM_NEGOTIATE
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB_COM_NEGOTIATE sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 0 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_NEGOTIATE with message id << 0 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 1 credits for SMB2_NEGOTIATE with message id << 0 >>, now available: 1 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_NEGOTIATE with message id << 0 >> took << 7 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 0 >> to `SMB2_NEGOTIATE with message id << 0 >>`
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1) credits to SMB2_NEGOTIATE with message id << 1 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_NEGOTIATE with message id << 1 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_NEGOTIATE with message id << 1 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_NEGOTIATE with message id << 1 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 1 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_NEGOTIATE with message id << 1 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 129 credits for SMB2_NEGOTIATE with message id << 1 >>, now available: 129 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_NEGOTIATE with message id << 1 >> took << 3 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 1 >> to `SMB2_NEGOTIATE with message id << 1 >>`
[main] DEBUG com.hierynomus.smbj.connection.SMBProtocolNegotiator - Negotiated the following connection settings: ConnectionContext{
  serverGuid=65abcfd4-f6aa-4108-97ca-a18edc0dd48f,
  serverName='host.domain.net',
  negotiatedProtocol=NegotiatedProtocol{dialect=SMB_3_1_1, maxTransactSize=8388608, maxReadSize=8388608, maxWriteSize=8388608},
  clientGuid=a20149a0-0e13-4769-9ba1-867ebc32cb64,
  clientCapabilities=[SMB2_GLOBAL_CAP_LARGE_MTU],
  serverCapabilities=[SMB2_GLOBAL_CAP_DFS, SMB2_GLOBAL_CAP_LEASING, SMB2_GLOBAL_CAP_LARGE_MTU],
  clientSecurityMode=1,
  serverSecurityMode=1,
  server='com.hierynomus.smbj.server.Server@265adfad'
}
[main] INFO  com.hierynomus.smbj.connection.PacketEncryptor - Initialized PacketEncryptor with Cipher << AES_128_GCM >>
[main] INFO  com.hierynomus.smbj.connection.Connection - Successfully connected to: host.domain.net
[main] INFO  de.smbjVersionTester.SmbClient - Authenticating user 'user'...
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Initialized Authentication of user using NTLM
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 129) credits to SMB2_SESSION_SETUP with message id << 2 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 2 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 2 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 2 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 2 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_SESSION_SETUP with message id << 2 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 129 credits for SMB2_SESSION_SETUP with message id << 2 >>, now available: 257 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_SESSION_SETUP with message id << 2 >> took << 3 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 2 >> to `SMB2_SESSION_SETUP with message id << 2 >>`
[main] DEBUG com.hierynomus.smbj.connection.SMBSessionBuilder - More processing required for authentication of user using com.hierynomus.smbj.auth.NtlmAuthenticator@71c27ee8
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received token: (... anonymized)
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 222
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,CONSTRUCTED,16]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 219
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 3
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 12
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 197
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],<unknown>]
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Sequence[[ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],<unknown>], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],<unknown>]]]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,10]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 1
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Enumerated[1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,6]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 10
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1ObjectIdentifier[1.3.6.1.4.1.311.2.2.10]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,4]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 194
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1OctetString[(... anonymized)]]
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvNdDomainName(2) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvNbComputerName(1) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvDnsDomainName(4) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvDnsComputerName(3) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvTimestamp(7) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvEOL(0) TargetInfo
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received NTLM challenge from: ChallengeTarget
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 257) credits to SMB2_SESSION_SETUP with message id << 3 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 3 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 3 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 3 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 3 >>
[Packet Reader for host.domain.net] INFO  com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - PacketReader error, got exception.
com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readFully(DirectTcpPacketReader.java:72)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readTcpHeader(DirectTcpPacketReader.java:59)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.doRead(DirectTcpPacketReader.java:48)
	at com.hierynomus.smbj.transport.PacketReader.readPacket(PacketReader.java:70)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:48)
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: java.io.EOFException: EOF while reading packet
	... 6 more
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Stopping PacketReader...
[main] ERROR com.hierynomus.protocol.commons.concurrent.Promise - << 3 >> woke to: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
[main] INFO  com.hierynomus.smbj.connection.Connection - Closed connection to host.domain.net
[Packet Reader for host.domain.net] INFO  com.hierynomus.smbj.connection.Connection - Closed connection to host.domain.net
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.SMBClient - Connection to << host.domain.net:445 >> closed
[main] DEBUG com.hierynomus.smbj.SMBClient - Connection to << host.domain.net:445 >> closed
[main] INFO  com.hierynomus.smbj.SMBClient - Going to close all remaining connections
[main] ERROR de.smbjVersionTester.Application - Could not authenticate user:
com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.connection.SMBSessionBuilder.establish(SMBSessionBuilder.java:114)
	at com.hierynomus.smbj.connection.Connection.authenticate(Connection.java:202)
	at de.smbjVersionTester.SmbClient.doWithShare(SmbClient.java:248)
	at de.smbjVersionTester.SmbClient.createFolder(SmbClient.java:74)
	at de.smbjVersionTester.SmbClient.checkConnection(SmbClient.java:52)
	at de.smbjVersionTester.Application.main(Application.java:61)
Caused by: com.hierynomus.protocol.transport.TransportException: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.protocol.transport.TransportException$1.wrap(TransportException.java:30)
	at com.hierynomus.protocol.transport.TransportException$1.wrap(TransportException.java:24)
	at com.hierynomus.protocol.commons.concurrent.Futures.get(Futures.java:47)
	at com.hierynomus.smbj.connection.Connection.sendAndReceive(Connection.java:242)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.initiateSessionSetup(SMBSessionBuilder.java:197)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:126)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:142)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.establish(SMBSessionBuilder.java:109)
	... 5 more
Caused by: java.util.concurrent.ExecutionException: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.protocol.commons.concurrent.PromiseBackedFuture.get(PromiseBackedFuture.java:59)
	at com.hierynomus.protocol.commons.concurrent.CancellableFuture.get(CancellableFuture.java:84)
	at com.hierynomus.protocol.commons.concurrent.Futures.get(Futures.java:42)
	at com.hierynomus.smbj.connection.Connection.sendAndReceive(Connection.java:242)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.initiateSessionSetup(SMBSessionBuilder.java:197)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:126)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:142)
	at com.hierynomus.smbj.connection.SMBSessionBuilder.establish(SMBSessionBuilder.java:109)
	... 5 more
Caused by: com.hierynomus.smbj.common.SMBRuntimeException: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.common.SMBRuntimeException$1.wrap(SMBRuntimeException.java:28)
	at com.hierynomus.smbj.common.SMBRuntimeException$1.wrap(SMBRuntimeException.java:22)
	at com.hierynomus.protocol.commons.concurrent.Promise.deliverError(Promise.java:95)
	at com.hierynomus.smbj.connection.OutstandingRequests.handleError(OutstandingRequests.java:88)
	at com.hierynomus.smbj.connection.Connection.handleError(Connection.java:292)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:54)
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readFully(DirectTcpPacketReader.java:72)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readTcpHeader(DirectTcpPacketReader.java:59)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.doRead(DirectTcpPacketReader.java:48)
	at com.hierynomus.smbj.transport.PacketReader.readPacket(PacketReader.java:70)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:48)
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readFully(DirectTcpPacketReader.java:72)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readTcpHeader(DirectTcpPacketReader.java:59)
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.doRead(DirectTcpPacketReader.java:48)
	at com.hierynomus.smbj.transport.PacketReader.readPacket(PacketReader.java:70)
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:48)
	at java.lang.Thread.run(Thread.java:829) ~[?:?]

Would be great if there was a solution, as other customers are moving on to SMB3 shares requiring encryption and unfortunately the problems in this specifics customers environment blocks an update.

@hierynomus
Copy link
Owner

@ZwoCa Good evening, I've just pushed a potential fix after re-reviewing the MS-NLMP protocol details. Is it possible for you to try out a build from a branch/PR? If so, please check whether this problem is fixed with #755

@ZwoCa
Copy link

ZwoCa commented Mar 20, 2023

@hierynomus Thank you for looking into this. I've just built from branch and deployed a new version of my test application using smbj at the customers environment. Unfortunately, behavior is the same: it still fails processing the response to the second SMB2_SESSION_SETUP request, throwing an EOFException during readTcpHeader.

Please let me know if I there is some way I can help finding the cause. Guess a TCP dump would be helpful, but unfortunately, I will not get clearance from the customer for this. Maybe one could built in some well-placed additional logging?

@hierynomus
Copy link
Owner

Yes, correct i realized last night that it might not be correctly fixed.

@hierynomus
Copy link
Owner

@ZwoCa The branch is updated. If all's correct it should now calculate the correct MIC 🙈 ... The other option I can see is that we not send a MIC, but I'd rather fix it correctly.

@hierynomus
Copy link
Owner

If you could test it out that would be great

@ZwoCa
Copy link

ZwoCa commented Mar 25, 2023

Thank again @hierynomus - I'm happy to test it. Will have to wait until Monday or Tuesday though, before I'm able to reach out to the customer again.

I've seen that there is a new option in SmbConfig regarding the Windows version. I guess this is something I should "break out" in my test application, so I can play around with this setting in the customers environment?

@hierynomus
Copy link
Owner

I don't think it's needed to change. Not sure yet whether I'll keep it in SmbConfig or will hardcode it below the surface. It's mainly just passed around during Ntlm authentication for debugging purposes on client/server side. As far as the spec's concerned there should be no version dependent behaviour, but ymmv...

@ZwoCa
Copy link

ZwoCa commented Mar 27, 2023

I've tested the new build. It seems like there is a bit of progress, however, still SMB2_SESSION_SETUP fails.

Instead of throwing an EOFException whentrying to read the TCP header of the second SMB2_SESSION_SETUP request, it now fails because the server sends an STATUS_LOGON_FAILURE (0xc000006d) response:

0.11.6-SNAPSHOT
[main] DEBUG com.hierynomus.protocol.commons.socket.ProxySocketFactory - Connecting to host.domain.net/123.123.123.123:445
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Starting PacketReader on thread: Packet Reader for host.domain.net
[main] DEBUG com.hierynomus.smbj.connection.SMBProtocolNegotiator - Negotiating dialects [SMB_2_0_2, SMB_2_1, SMB_3_0, SMB_3_0_2, SMB_3_1_1]
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB_COM_NEGOTIATE >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB_COM_NEGOTIATE
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB_COM_NEGOTIATE sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 0 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_NEGOTIATE with message id << 0 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 1 credits for SMB2_NEGOTIATE with message id << 0 >>, now available: 1 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_NEGOTIATE with message id << 0 >> took << 12 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 0 >> to `SMB2_NEGOTIATE with message id << 0 >>`
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1) credits to SMB2_NEGOTIATE with message id << 1 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_NEGOTIATE with message id << 1 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_NEGOTIATE with message id << 1 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_NEGOTIATE with message id << 1 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 1 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_NEGOTIATE with message id << 1 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 129 credits for SMB2_NEGOTIATE with message id << 1 >>, now available: 129 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_NEGOTIATE with message id << 1 >> took << 3 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 1 >> to `SMB2_NEGOTIATE with message id << 1 >>`
[main] DEBUG com.hierynomus.smbj.connection.SMBProtocolNegotiator - Negotiated the following connection settings: ConnectionContext{
  serverGuid=65abcfd4-f6aa-4108-97ca-a18edc0dd48f,
  serverName='host.domain.net',
  negotiatedProtocol=NegotiatedProtocol{dialect=SMB_3_1_1, maxTransactSize=8388608, maxReadSize=8388608, maxWriteSize=8388608},
  clientGuid=bb7defd0-4ab0-4a0b-83c7-9e1b231224d2,
  clientCapabilities=[SMB2_GLOBAL_CAP_LARGE_MTU],
  serverCapabilities=[SMB2_GLOBAL_CAP_DFS, SMB2_GLOBAL_CAP_LEASING, SMB2_GLOBAL_CAP_LARGE_MTU],
  clientSecurityMode=1,
  serverSecurityMode=1,
  server='com.hierynomus.smbj.server.Server@1e461e41'
}
[main] INFO  com.hierynomus.smbj.connection.PacketEncryptor - Initialized PacketEncryptor with Cipher << null >>
[main] INFO  com.hierynomus.smbj.connection.Connection - Successfully connected to: host.domain.net
[main] INFO  de.smbjVersionTester.SmbClient - Authenticating user 'user'...
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Initialized Authentication of user using NTLM
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 129) credits to SMB2_SESSION_SETUP with message id << 2 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 2 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 2 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 2 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 2 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_SESSION_SETUP with message id << 2 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 129 credits for SMB2_SESSION_SETUP with message id << 2 >>, now available: 257 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_SESSION_SETUP with message id << 2 >> took << 3 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 2 >> to `SMB2_SESSION_SETUP with message id << 2 >>`
[main] DEBUG com.hierynomus.smbj.connection.SMBSessionBuilder - More processing required for authentication of user using com.hierynomus.smbj.auth.NtlmAuthenticator@4748a0f9
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received token: (... anonymized)
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 238
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,CONSTRUCTED,16]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 235
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 3
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 12
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 213
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],<unknown>]
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Sequence[[ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],<unknown>], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],<unknown>]]]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,10]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 1
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Enumerated[1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,6]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 10
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1ObjectIdentifier[1.3.6.1.4.1.311.2.2.10]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,4]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 210
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1OctetString[(... anonymized)]]
[main] DEBUG com.hierynomus.ntlm.messages.NtlmChallenge - Windows version = WindowsVersion[WINDOWS_MAJOR_VERSION_6, WINDOWS_MINOR_VERSION_1, 0, NTLMSSP_REVISION_W2K3]
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvNbDomainName(2) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvNbComputerName(1) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvDnsDomainName(4) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvDnsComputerName(3) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvTimestamp(7) TargetInfo
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - NTLM channel contains MsvAvEOL(0) TargetInfo
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received NTLM challenge from: ChallengeTarget
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 257) credits to SMB2_SESSION_SETUP with message id << 3 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 3 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 3 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 3 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 3 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_SESSION_SETUP with message id << 3 >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 129 credits for SMB2_SESSION_SETUP with message id << 3 >>, now available: 385 credits
[Packet Reader for host.domain.net] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_SESSION_SETUP with message id << 3 >> took << 3 ms >>
[Packet Reader for host.domain.net] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 3 >> to `SMB2_SESSION_SETUP with message id << 3 >>`
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Stopping PacketReader...
[main] INFO  com.hierynomus.smbj.connection.Connection - Closed connection to host.domain.net
[Packet Reader for host.domain.net] INFO  com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Thread[Packet Reader for host.domain.net,5,main] stopped.
[main] DEBUG com.hierynomus.smbj.SMBClient - Connection to << host.domain.net:445 >> closed
[main] INFO  com.hierynomus.smbj.SMBClient - Going to close all remaining connections
[main] ERROR de.smbjVersionTester.Application - Could not authenticate user:
com.hierynomus.mssmb2.SMBApiException: STATUS_LOGON_FAILURE (0xc000006d): Authentication failed for 'user' using com.hierynomus.smbj.auth.NtlmAuthenticator@4748a0f9
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:144) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:142) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at com.hierynomus.smbj.connection.SMBSessionBuilder.establish(SMBSessionBuilder.java:109) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at com.hierynomus.smbj.connection.Connection.authenticate(Connection.java:202) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at de.smbjVersionTester.SmbClient.doWithShare(SmbClient.java:248) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at de.smbjVersionTester.SmbClient.createFolder(SmbClient.java:74) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at de.smbjVersionTester.SmbClient.checkConnection(SmbClient.java:52) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at de.smbjVersionTester.Application.main(Application.java:61) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]

I've double-checked the login credentials, they are correct, switching back to SMBJ 0.10.0 with the same credentials it works as expected. The password does not contain any weird characters, just lower case characters and a number. The username is 7 characters long and alpha-numeric only.

@hierynomus
Copy link
Owner

Well that's good and bad news, this means that the new Session Setup is accepted by the remote side. Meaning that at least indeed part of the work is correct ;)

Question: Is it possible for you/your client to obtain the server log to see why it complains that there is a LOGON failure? Feel free to forward it to my email if they don't want to drop it here.

@ZwoCa
Copy link

ZwoCa commented Mar 27, 2023

Thank you. It will be a bit of a challenge to find someone in charge who is willing to help, but I'm trying my best. It may take some days, though.

@hierynomus
Copy link
Owner

No problem... Just a thought that crossed my mind, which SecurityProvider are you using? I've noticed an inconsistency whilst testing the NtlmV2Functions... The JceSecurityProvider gives the expected results (according to the MS-NLMP samples provided). However, the BCSecurityProvider, and the JceSecurityProvider backed by BouncyCastle give different/wrong results.

@ZwoCa
Copy link

ZwoCa commented Mar 27, 2023

Up to now I didn't modify the SecurityProvider via SmbConfig, so BCSecurityProvider was used. However, I just changed it to JceSecurityProvider, but the error is still the same.

@hierynomus
Copy link
Owner

Ahh too bad, that would've been too easy...

@ZwoCa
Copy link

ZwoCa commented Mar 29, 2023

I've got an update. The bad news is that getting an excerpt from the logs or an TCP dump will require a lot of effort. Administration of the clients SMB servers is handled by another company. There are a lot parties involved and this would probably need NDAs and someone from management to push it.

However, someone from SMB ops took a look at the TCP dumps himself and while I'm not allowed to get or share them, I've been given at least one small hint on what might be going wrong:

When using SMBJ 0.10.0, for the second Session Setup Request (NTLMSSP_AUTH) the TCP dump will show: "User: europe.domain\qualifieduser" (actual data anonymized).

However when doing the same with SMBJ 0.11.5, the TCP dump will show "User: e\q". So only the first letter of domain and username is sent, which of cause would explain the STATUS_LOGN_FAILURE response.

I'm sorry I can't provide any further details, but I hope this makes sense and gives a hint in the right direction?

@hierynomus
Copy link
Owner

Let me quickly dive into the old code :) Not sure I can explain the difference. Mainly also because I did a walkthrough of the code just last few days

@hierynomus
Copy link
Owner

I've looked and looked and cannot explain that currently. I've added trace logging of NTLM messages to this branch now. It should log a nice toString for each NTLM message (received and sending) to see whether there's something in there that we can deduce. Could you run a build of this branch using your sample program?

@hierynomus
Copy link
Owner

@ZwoCa Another question, you've mentioned that 0.10.0 works correctly, and 0.11.5 does not. Not sure whether you've tried narrowing down the version range. Could you try the following 2 versions if it's not too much to ask:

  • 0.11.0
  • A build from commit 78da5c8. This is between 0.10.0 and 0.11.0 where a bulk of the SMB3 work was merged.

Thanks!

@ZwoCa
Copy link

ZwoCa commented Mar 30, 2023

Hi Jeroen,

of cause I'm happy to try this. Thank you very much for your support. :)

  • I did a build from commit 78da5c8 (which gives a 0.10.1-SNAPSHOT). It's working fine, like 0.10.0 did. The sample program did authenticate successfully (it has also written and deleted a file later on).
  • I tried it with 0.11.0 (btw this release is not available at Maven Central, so I built it myself). However, with this build the EOFException fixed in issue-653 branch is happening again, so I'm not reaching the "point of interest".

Regarding the added trace logging, here is a fresh log:

0.11.6-SNAPSHOT, commit 449d5d7
[main] DEBUG com.hierynomus.protocol.commons.socket.ProxySocketFactory - Connecting to host.domain.tld/123.123.123.123:445
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Starting PacketReader on thread: Packet Reader for host.domain.tld
[main] DEBUG com.hierynomus.smbj.connection.SMBProtocolNegotiator - Negotiating dialects [SMB_2_0_2, SMB_2_1, SMB_3_0, SMB_3_0_2, SMB_3_1_1]
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB_COM_NEGOTIATE >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB_COM_NEGOTIATE
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB_COM_NEGOTIATE sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 0 >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_NEGOTIATE with message id << 0 >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 1 credits for SMB2_NEGOTIATE with message id << 0 >>, now available: 1 credits
[Packet Reader for host.domain.tld] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_NEGOTIATE with message id << 0 >> took << 12 ms >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 0 >> to `SMB2_NEGOTIATE with message id << 0 >>`
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 1) credits to SMB2_NEGOTIATE with message id << 1 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_NEGOTIATE with message id << 1 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_NEGOTIATE with message id << 1 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_NEGOTIATE with message id << 1 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 1 >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_NEGOTIATE with message id << 1 >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 129 credits for SMB2_NEGOTIATE with message id << 1 >>, now available: 129 credits
[Packet Reader for host.domain.tld] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_NEGOTIATE with message id << 1 >> took << 6 ms >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 1 >> to `SMB2_NEGOTIATE with message id << 1 >>`
[main] DEBUG com.hierynomus.smbj.connection.SMBProtocolNegotiator - Negotiated the following connection settings: ConnectionContext{
  serverGuid=65abcfd4-f6aa-4108-97ca-a18edc0dd48f,
  serverName='host.domain.tld',
  negotiatedProtocol=NegotiatedProtocol{dialect=SMB_3_1_1, maxTransactSize=8388608, maxReadSize=8388608, maxWriteSize=8388608},
  clientGuid=163fb572-83a2-4fb0-9aac-1eb5d175ab6d,
  clientCapabilities=[SMB2_GLOBAL_CAP_LARGE_MTU],
  serverCapabilities=[SMB2_GLOBAL_CAP_DFS, SMB2_GLOBAL_CAP_LEASING, SMB2_GLOBAL_CAP_LARGE_MTU],
  clientSecurityMode=1,
  serverSecurityMode=1,
  server='com.hierynomus.smbj.server.Server@3899782c'
}
[main] INFO  com.hierynomus.smbj.connection.PacketEncryptor - Initialized PacketEncryptor with Cipher << null >>
[main] INFO  com.hierynomus.smbj.connection.Connection - Successfully connected to: host.domain.tld
[main] INFO  de.smbjVersionTester.SmbClient - Authenticating user 'qualifieduser'...
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Initialized Authentication of qualifieduser using NTLM
[main] TRACE com.hierynomus.smbj.auth.NtlmAuthenticator - Sending NTLM negotiate message: NtlmNegotiate{
  domain=''',
  workstation='europe.domain',
  negotiateFlags=[NTLMSSP_NEGOTIATE_KEY_EXCH, NTLMSSP_NEGOTIATE_128, NTLMSSP_NEGOTIATE_VERSION, NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY, NTLMSSP_NEGOTIATE_ALWAYS_SIGN, NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED, NTLMSSP_NEGOTIATE_NTLM, NTLMSSP_NEGOTIATE_SIGN, NTLMSSP_REQUEST_TARGET, NTLMSSP_NEGOTIATE_UNICODE],
  version=WindowsVersion[WINDOWS_MAJOR_VERSION_6, WINDOWS_MINOR_VERSION_1, 0, NTLMSSP_REVISION_W2K3]
}
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 129) credits to SMB2_SESSION_SETUP with message id << 2 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 2 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 2 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 2 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 2 >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_SESSION_SETUP with message id << 2 >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 129 credits for SMB2_SESSION_SETUP with message id << 2 >>, now available: 257 credits
[Packet Reader for host.domain.tld] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_SESSION_SETUP with message id << 2 >> took << 6 ms >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 2 >> to `SMB2_SESSION_SETUP with message id << 2 >>`
[main] DEBUG com.hierynomus.smbj.connection.SMBSessionBuilder - More processing required for authentication of qualifieduser using com.hierynomus.smbj.auth.NtlmAuthenticator@1a6c1270
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received token: <anonymized>
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 238
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,CONSTRUCTED,16]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 235
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 3
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 12
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 213
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],<unknown>]
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Sequence[[ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,0],<unknown>], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,1],<unknown>], ASN1TaggedObject[ASN1Tag[CONTEXT_SPECIFIC,CONSTRUCTED,2],<unknown>]]]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,10]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 1
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1Enumerated[1]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,6]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 10
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1ObjectIdentifier[1.3.6.1.4.1.311.2.2.10]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 tag ASN1Tag[UNIVERSAL,PRIMITIVE,4]
[main] TRACE com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object length: 210
[main] DEBUG com.hierynomus.asn1.ASN1InputStream - Read ASN.1 object: ASN1OctetString[[<anonymized>]]
[main] DEBUG com.hierynomus.ntlm.messages.NtlmChallenge - Windows version = WindowsVersion[WINDOWS_MAJOR_VERSION_6, WINDOWS_MINOR_VERSION_1, 0, NTLMSSP_REVISION_W2K3]
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - Read TargetInfo MsvAvNbDomainName(2) --> ABC
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - Read TargetInfo MsvAvNbComputerName(1) --> HOST
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - Read TargetInfo MsvAvDnsDomainName(4) --> europe.domain
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - Read TargetInfo MsvAvDnsComputerName(3) --> host.europe.domain
[main] TRACE com.hierynomus.ntlm.messages.TargetInfo - Read TargetInfo MsvAvTimestamp(7) --> Thu Mar 30 13:42:38 CEST 2023
[main] TRACE com.hierynomus.smbj.auth.NtlmAuthenticator - Received NTLM challenge: NtlmChallenge{
  targetName='ABC',
  negotiateFlags=[NTLMSSP_NEGOTIATE_KEY_EXCH, NTLMSSP_NEGOTIATE_128, NTLMSSP_NEGOTIATE_VERSION, NTLMSSP_NEGOTIATE_TARGET_INFO, NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY, NTLMSSP_TARGET_TYPE_DOMAIN, NTLMSSP_NEGOTIATE_ALWAYS_SIGN, NTLMSSP_NEGOTIATE_NTLM, NTLMSSP_NEGOTIATE_SIGN, NTLMSSP_NEGOTIATE_UNICODE],
  serverChallenge=a7 c4 c7 6a de d7 5a 03,
  version=WindowsVersion[WINDOWS_MAJOR_VERSION_6, WINDOWS_MINOR_VERSION_1, 0, NTLMSSP_REVISION_W2K3],
  targetInfo=TargetInfo{targetInfo={MsvAvNbDomainName=ABC, MsvAvNbComputerName=HOST, MsvAvDnsDomainName=europe.domain, MsvAvDnsComputerName=host.europe.domain, MsvAvTimestamp=Thu Mar 30 13:42:38 CEST 2023}}
}
[main] DEBUG com.hierynomus.smbj.auth.NtlmAuthenticator - Received NTLM challenge from: ABC
[main] TRACE com.hierynomus.smbj.auth.NtlmAuthenticator - Sending NTLM authenticate message: NtlmAuthenticate{
  mic=7a 02 11 77 4e bd 14 bf e7 ad 9f 2e 7a 9d a1 ee,
  lmResponse=00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00,
  ntResponse=<anonymized, same information as in TargetInfo above: ABC, HOST, europe.domain, host.europe.domain>,
  domainName='europe.domain',
  userName='qualifieduser',
  workstation='',
  encryptedRandomSessionKey=[<secret>],
}
[main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 257) credits to SMB2_SESSION_SETUP with message id << 3 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 3 >> >>
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 3 >>
[main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 3 >> sent, lock released.
[main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 3 >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Received packet SMB2_SESSION_SETUP with message id << 3 >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.smbj.connection.packet.SMB2CreditGrantingPacketHandler - Server granted us 129 credits for SMB2_SESSION_SETUP with message id << 3 >>, now available: 385 credits
[Packet Reader for host.domain.tld] TRACE com.hierynomus.smbj.connection.packet.SMB2AsyncResponsePacketHandler - Send/Recv of packet SMB2_SESSION_SETUP with message id << 3 >> took << 3 ms >>
[Packet Reader for host.domain.tld] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Setting << 3 >> to `SMB2_SESSION_SETUP with message id << 3 >>`
[main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Stopping PacketReader...
[main] INFO  com.hierynomus.smbj.connection.Connection - Closed connection to host.domain.tld
[Packet Reader for host.domain.tld] INFO  com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - Thread[Packet Reader for host.domain.tld,5,main] stopped.
[main] DEBUG com.hierynomus.smbj.SMBClient - Connection to << host.domain.tld:445 >> closed
[main] INFO  com.hierynomus.smbj.SMBClient - Going to close all remaining connections
[main] ERROR de.smbjVersionTester.Application - Could not authenticate user:
com.hierynomus.mssmb2.SMBApiException: STATUS_LOGON_FAILURE (0xc000006d): Authentication failed for 'qualifieduser' using com.hierynomus.smbj.auth.NtlmAuthenticator@1a6c1270
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:144) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at com.hierynomus.smbj.connection.SMBSessionBuilder.setupSession(SMBSessionBuilder.java:142) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at com.hierynomus.smbj.connection.SMBSessionBuilder.establish(SMBSessionBuilder.java:109) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at com.hierynomus.smbj.connection.Connection.authenticate(Connection.java:202) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at de.smbjVersionTester.SmbClient.doWithShare(SmbClient.java:249) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at de.smbjVersionTester.SmbClient.createFolder(SmbClient.java:75) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at de.smbjVersionTester.SmbClient.checkConnection(SmbClient.java:53) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at de.smbjVersionTester.Application.main(Application.java:61) ~[smbj-version-tester-0.11.6-SNAPSHOT-jar-with-dependencies.jar:0.1-SNAPSHOT]

Again, it's anonymized, but I tried to keep the different entries consistent. Please let me know if you need the ntResponse, I could share it via email but need to get clearance first.

What I found to be kind of interesting: The trace log for NtlmAuthenticate shows complete domain and user name (europe.domain\qualifieduser). In yesterdays TCP dump, with 0.10.0 domain and user name where also fully readable, but truncated to one character (e\q) when using 0.11.6-SNAPSHOT:

yesterdays excerpt from TCP dump, 011.6-SNAPSHOT
SMB2 Header
	NT Status: STATUS_LOGON_FAILURE (0xc000006d)
	Command: Session Setup (1)
	Credits granted: 129
	Session Id: 0x64241bcd00001915 Acct:q Domain:e Host:
		[Account: q]
		[Domain: e]
		[Host: ]
		[Authenticated in Frame: 11]

@ZwoCa
Copy link

ZwoCa commented Mar 30, 2023

I just realized something a bit strange: Please have a look at NtlmNegotiate log entry:

[main] TRACE com.hierynomus.smbj.auth.NtlmAuthenticator - Sending NTLM negotiate message: NtlmNegotiate{
  domain=''',
  workstation='europe.domain',
  negotiateFlags=[NTLMSSP_NEGOTIATE_KEY_EXCH, NTLMSSP_NEGOTIATE_128, NTLMSSP_NEGOTIATE_VERSION, NTLMSSP_NEGOTIATE_EXTENDED_SESSIONSECURITY, NTLMSSP_NEGOTIATE_ALWAYS_SIGN, NTLMSSP_NEGOTIATE_OEM_DOMAIN_SUPPLIED, NTLMSSP_NEGOTIATE_NTLM, NTLMSSP_NEGOTIATE_SIGN, NTLMSSP_REQUEST_TARGET, NTLMSSP_NEGOTIATE_UNICODE],
  version=WindowsVersion[WINDOWS_MAJOR_VERSION_6, WINDOWS_MINOR_VERSION_1, 0, NTLMSSP_REVISION_W2K3]
}

← The content of domain is a single quotation mark, while the content of workstation is what I'd expect to be the domain.

However, in NtlmAuthenticate looks better:

[main] TRACE com.hierynomus.smbj.auth.NtlmAuthenticator - Sending NTLM authenticate message: NtlmAuthenticate{
  mic=7a 02 11 77 4e bd 14 bf e7 ad 9f 2e 7a 9d a1 ee,
  lmResponse=00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00,
  ntResponse=<anonymized, same information as in TargetInfo above: ABC, HOST, europe.domain, host.europe.domain>,
  domainName='europe.domain',
  userName='qualifieduser',
  workstation='',
  encryptedRandomSessionKey=[<secret>],
}

@hierynomus
Copy link
Owner

@ZwoCa You are correct, I mixed up the two fields when constructing the NtlmNegotiate. Just pushed the fix for that to the branch, you can try it out, but I'm not sure that it will make a huge difference.

@ZwoCa
Copy link

ZwoCa commented Apr 4, 2023

@hierynomus Thanks for the fix. The output regarding NtlmNegotiate looks reasonable now, but unfortunately and as expected it didn't make a difference regarding the STATUS_LOGON_FAILURE.

I'm afraid air is getting thin, is there anything else to try? I guess that given this error, normally one would take a look at the server side for further debugging… But the provider of the Samba service has already indicated that they don't see it as their problem and have no intention of taking action here.

@hierynomus
Copy link
Owner

Well there are a few more options we can try luckily, in order:

  1. The difference between commit 78da5c8 and 0.11.0 is mainly that the SMB3XX dialects were added to the supported dialects and some small refactorings were done. You could try to make a build from: a7e9e07, which adds the SMB3xx dialects to the config. If that breaks then we have a bit more info. One thing to try then is to use the current branch and set the dialects only to 2.1 and 2.0.2 to see whether that also works.
  2. Using the same commit from above, try to use SMB3 but disable signing/encryption to see whether there's any difference
  3. MS-NLMP is now implemented, but it could be that with smb3 signing and encryption is mandatory in the MS-SPNG (SPNEGO / NegTokenTarg message). That part of the spec I'll implement next on the branch to see whether that fixes the problem.

For me the hard part is that I'm not sure how to reproduce this on my samba docker image. That would considerably speed up testing efforts.

@hierynomus
Copy link
Owner

Goodmorning @ZwoCa, do you have any update on the first two points?

@hierynomus
Copy link
Owner

Well at least the semi-positive news is that the master branch then at least fixes something for some hosts.... Any luck in finding a new "old" host to test on? It's really a shame that we're so close to the finish line and we lost the testing host.

@ZwoCa
Copy link

ZwoCa commented May 26, 2023

Unfortunately, no news so far. The customer did not simply move the share to a new host, but they switched the entire storage solution. Formerly, it was "on DELL-System [sic]", now they switched to NetApp. So it's a completely new infrastructure, sub-contracted to a new company.

There may still be a chance that some users at the customer site are still using the old infrastructure, that might behave like the test host that was shut down. I'm in touch with them, but it will take me some time to sort that out. Hopefully, I can use one of these (production) hosts for testing purposes.

@ZwoCa
Copy link

ZwoCa commented Jun 5, 2023

Just a quick update: I'm in touch with an user who appears to still be using one of the old, problematic shares. I'll have the change to test it tomorrow, so hopefully I'll be able to reproduce the original issue with 0.11.5 and test if commit 72fbbe5 is working.

@hierynomus
Copy link
Owner

Great to hear! In the meantime I've pushed an additional commit: 900621d

And I've got one more lined up. It would be great if you could (after reproducing the EOF with 0.11.5), could iteratively try the commits from 72fbbe5 onwards.

Then I'll push the commit that I have locally also, and we can make fast steps (before they also decommission their env 🙈 😉 ).

Do you agree to this?

@ZwoCa
Copy link

ZwoCa commented Jun 5, 2023

May I ask you to already push this commit? If you don't want to push it to the current branch, maybe on another (temporary) branch? This way, I could prepare the necessary test application(s).

The user does not really have anything to do with the matter and only makes himself and his environment available out of pure kindness, so I don't want to stretch his patience, and want to prevent him from doing his job as little as possible. 🙈

@hierynomus
Copy link
Owner

Done! 5aba7cf is also present... 🤞

Let me know if one of these commits starts breaking...

@ZwoCa
Copy link

ZwoCa commented Jun 6, 2023

Good news, the users share still uses the old environment, so I can recreate the error again.

Commits up to including 900621d work fine.

However, with 5aba7cf, the error is back:

09:36:00.903 [main] DEBUG com.hierynomus.smbj.connection.Connection - Granted 1 (out of 257) credits to SMB2_SESSION_SETUP with message id << 3 >>
09:36:00.904 [main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Acquiring write lock to send packet << SMB2_SESSION_SETUP with message id << 3 >> >>
09:36:00.904 [main] DEBUG com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Writing packet SMB2_SESSION_SETUP with message id << 3 >>
09:36:00.904 [main] TRACE com.hierynomus.smbj.transport.tcp.direct.DirectTcpTransport - Packet SMB2_SESSION_SETUP with message id << 3 >> sent, lock released.
09:36:00.904 [main] DEBUG com.hierynomus.protocol.commons.concurrent.Promise - Awaiting << 3 >>
09:36:00.907 [Packet Reader for host.domain.tld] INFO  com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader - PacketReader error, got exception.
com.hierynomus.protocol.transport.TransportException: java.io.EOFException: EOF while reading packet
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readFully(DirectTcpPacketReader.java:72) ~[5_smbj-version-tester-5aba7cf-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.readTcpHeader(DirectTcpPacketReader.java:59) ~[5_smbj-version-tester-5aba7cf-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at com.hierynomus.smbj.transport.tcp.direct.DirectTcpPacketReader.doRead(DirectTcpPacketReader.java:48) ~[5_smbj-version-tester-5aba7cf-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at com.hierynomus.smbj.transport.PacketReader.readPacket(PacketReader.java:70) ~[5_smbj-version-tester-5aba7cf-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at com.hierynomus.smbj.transport.PacketReader.run(PacketReader.java:48) ~[5_smbj-version-tester-5aba7cf-jar-with-dependencies.jar:0.1-SNAPSHOT]
	at java.lang.Thread.run(Thread.java:829) ~[?:?]
Caused by: java.io.EOFException: EOF while reading packet
	... 6 more

I hope this helps narrowing down the problem?

@hierynomus
Copy link
Owner

Hi, well that's (semi) good news...
I've reverted the failing commit, and split off a piece of code which "I think" should be safe... e16fb93 is the new commit. If you can test that it would be great. In the meantime I'll go over the last part of the diff between the master and this branch and try to figure out the problem.

@ZwoCa
Copy link

ZwoCa commented Jun 6, 2023

Hi @hierynomus - we ran the test, but e16fb93 is also failing: Same error message as witnessed before. So the culprit appears to be in this piece of code?

@hierynomus
Copy link
Owner

Ok, now this is interesting indeed. What's the SmbConfig (and NtlmConfig) that you're now using with that commit? ....

@ZwoCa
Copy link

ZwoCa commented Jun 6, 2023

It's pretty default: The only change on the default config from SmbConfig.build() is that multiProtocolNegotiate is set to true. To be honest, I didn't realize this setting is enabled in the test application before - I should have noticed this earlier.

Also timeouts are increased, but I guess they are not of relevance here.

@hierynomus
Copy link
Owner

Ok! Let me check the code... Will be back tomorrow probably ;)

@ZwoCa
Copy link

ZwoCa commented Jun 9, 2023

Hi @hierynomus, I just wanted to let you know, that from tomorrow on I'm on vacation (and also business trips) until the end of the month. Therefore, I will not have a change to test any new commits at the customers environment until I'm back in July.

However, a colleague of mine has agreed to follow up on the topic and to try out any new commits at the customer's site. So if you have something new to test, just post an update - my colleague can probably give you feedback shortly.

Also, I want to take this opportunity to thank you for being so committed to finding the cause of the issue.

@hierynomus
Copy link
Owner

hierynomus commented Jun 9, 2023 via email

@hierynomus
Copy link
Owner

Hi @ZwoCa (and colleague), I've just pushed a new commit (e648ab6), please try it out and let me know.

@JanDornseifer
Copy link

Hi @hierynomus - I'm not the named colleague of @ZwoCa but we also experienced the error with a NAS server on customer side using v0.11.5. I have been following your conversation and thought I could support you both until @ZwoCa is back from vacation.

Don't want to bring in confusion, but just want to let you know that with a build of current working-auth branch (e648ab6) we could authenticate and push a file. I then reverted the commit and merged e16fb93 which leads to failing authentication again, just to be sure to not making anything dumb. In addition, I tried current master that is also failing with the customer's NAS server.

@hierynomus
Copy link
Owner

Hi @JanDornseifer, wow, thanks a lot for jumping in and testing this. It seems that we're on the right track again with the new commit, which is great to know. There's a few things that need to be added now to the Authenticator to bring it back up to speed with what's in the spec. I'll try to add a next increment tomorrow or Friday.

Would be great if you could test that when it's there.

@ZwoCa
Copy link

ZwoCa commented Jun 28, 2023

Hi @hierynomus, I just built an updated version of our test application using your latest commit. However, I guess feedback will have to wait until next week, as our contact at the customers site will hardly be available this week.

@ZwoCa
Copy link

ZwoCa commented Jun 28, 2023

I was lucky and just found a time slot to try it out at our customers site. I can confirm @JanDornseifer results, it's still working with commit e648ab6. 👍

@JanDornseifer
Copy link

Hi @hierynomus - sure, I will try to support you both as best I can. I will test new commits in parallel with @ZwoCa.

@hierynomus
Copy link
Owner

@ZwoCa Great to hear that it also works for your customers! Let's bring this to the finish line ;)

@ZwoCa
Copy link

ZwoCa commented Jul 3, 2023

Good morning @hierynomus. I'm happy to be able to tell you that it's still working fine with your latest commit. 🎉

Thank you so much for your efforts. So finish line is ultimately in reach, I guess? Are there any more things to try or is it only a question of releasing a new (non-snapshot) version now? I see that there is still a WORKING_AUTH_TODO file, but it seems to be out of date.

@hierynomus
Copy link
Owner

@ZwoCa Goodmorning! Well the main thing I would still need to do now is to make the default for NtlmConfig.integrity = true, but doing so currently will fail authentication, because of the missing mechListMic in the wrapping message. This is becoming slightly urgent due to the July Windows security update....

But other than that, the current working-auth branch is back on par with master and has solved the direct problems.

My course of action will be:

  • merge working-auth to master
  • Release a new 0.12.0 version based off of this work
  • Try to implement the signing/sealing of the NegTokenTarg message, so that integrity can be turned back on

@hierynomus
Copy link
Owner

@ZwoCa I've just merged master into the working-auth branch, can you do a sanity check that nothing broke before I continue

@ZwoCa
Copy link

ZwoCa commented Jul 3, 2023

Maybe I'm missing something, but merging the master to working-auth branch did only do one actual change: In NtlmAuthenticate class, there two flags for integrityEnabled and omitVersion were added (but they are not used). Apart from that, a comment in NtlmAuthenticator changed as well as a test.

Was this really your intention?

@hierynomus
Copy link
Owner

Yes, that indeed should be what happened, those 2 flags need to be removed indeed still, but other than that the few conflicting changes there were I overrode with the branch's contents.

@ZwoCa
Copy link

ZwoCa commented Jul 3, 2023

OK. Sanity check was successful, we just ran the test at the customers environment. 👍

@JanDornseifer
Copy link

@hierynomus @ZwoCa I can also confirm. Works with NAS server of our customer as well.

@hierynomus
Copy link
Owner

Given that the branch has been merged, I'm going to close this large thread ;)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants