Opened 9 years ago
Closed 8 years ago
#263 closed defect (fixed)
Connection timeout (sleep with slow awakening)
| Reported by: | Lewis Rosenthal | Owned by: | |
|---|---|---|---|
| Priority: | minor | Milestone: | |
| Component: | Samba Client Plugin | Version: | Client 3.0.x |
| Keywords: | sleep, connection, wake, reconnect | Cc: | Paul Smedley |
Description
This continues the discussion we've had on the dev list, as it just happened to me with a NTLM/SMB1 share.
Connection was mapped and working. It sat idle for 61 minutes and few seconds. using 4OS2, I attempted a tab completion for a path, and got a beep (as it might if the drive were disconnected or the beginning of the path otherwise invalid).
Using ndpsmb-samba_4.2.3-heimdal-20150716b, log.ndpsmb shows:
2015/07/28 14:16:39.58: 9 2: NdpRsrcQueryInfo in 2015/07/28 14:16:39.62: 9 2: NdpRsrcQueryInfo 0 2015/07/28 14:16:39.62: 9 2: NdpRsrcQueryInfo in 2015/07/28 14:16:39.62: 9 2: NdpRsrcQueryInfo 0 2015/07/28 14:16:39.62: 9 2: NdpQueryPathInfo in [0x6213c0] <im*> 2015/07/28 14:16:39.63: 9 2: NdpFindStart in [0x6213c0] 2015/07/28 14:16:39.63: 9 2: NdpFindStart: dir [\], dir_mask [im*], mask [\*], szPath [im*] 2015/07/28 14:16:39.63: 4 2: smbwrp_filelist 2015/07/28 14:16:39.63: 1 2: Filelist <\*> on master <WORKGROUP> wgrp <workgroup> server <othello> share <data> clidev <A:> 2015/07/28 14:16:39.63: 1 2: list_files 2015/07/28 14:16:39.63: 9 2: dircache_list_files [] 2015/07/28 14:16:39.63: 9 2: findDirCache: [] 2015/07/28 14:16:39.63: 9 2: findDirCache: entry [LOTUS\Cantiag\ARCHIVE.FWK\COMMERCE.WK1] 2015/07/28 14:16:39.63: 9 2: findDirCache: entry [LOTUS\Cantiag\ARCHIVE.FWK] 2015/07/28 14:16:39.63: 9 2: findDirCache: entry [LOTUS\Cantiag] 2015/07/28 14:16:39.63: 9 2: findDirCache: entry [LOTUS] 2015/07/28 14:16:39.64: 9 2: findDirCache: entry [] 2015/07/28 14:16:39.64: 9 2: dcePathEqualTo: [] [] 2015/07/28 14:16:39.64: 9 2: findDirCache: 0x66f9e0 2015/07/28 14:16:39.64: 9 2: CacheRead: entry 0x66f9e0 found for [] 2015/07/28 14:16:39.64: 9 2: CacheRead: expired 2015/07/28 14:16:39.64: 9 2: CacheRead: [], 0 2015/07/28 14:16:39.64: 4 2: list_files level 260. mask <\*> 2015/07/28 14:16:39.67: 9 2: NdpFindStart <im*> (\im*) cnt 0 0 2015/07/28 14:16:40.62: 9 2: NdpRsrcQueryInfo in 2015/07/28 14:16:40.62: 9 2: NdpRsrcQueryInfo 0 2015/07/28 14:16:40.62: 9 2: NdpRsrcQueryInfo in 2015/07/28 14:16:40.62: 9 2: NdpRsrcQueryInfo 0
A subsequent:
dir g:\
paused for a few seconds, then provided results. Afterward, the same tab completion as above worked as expected (no delay; no beep).
Obviously, using CMD this would not be an issue, as there is no tab completion. I suspect that if we were able to cache the dir entries, this might also not be an issue, as we would return results from cache first (though an hour would be a long cache timeout).
Note that EA support is enabled for this share, even though the server does not support EAs over CIFS. I doubt that this has any bearing, however (the log does correctly report failure to get EA data when listing files).
Change History (24)
comment:1 by , 9 years ago
comment:2 by , 9 years ago
Condition still present with ndpsmb-samba_4.4.0rc3-heimdal-20160229.zip. After sitting idle between 13:35:30 and 23:38:21, attempting dir on an NTLMv1 share gets me a beep and the following in the log:
2016/03/18 23:38:21.75: 9 2: NdpRsrcQueryInfo in 2016/03/18 23:38:21.79: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@lewis 2016/03/18 23:38:21.79: 9 2: NdpRsrcQueryInfo in 2016/03/18 23:38:21.79: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@lewis 2016/03/18 23:38:21.79: 9 2: NdpRsrcQueryInfo in 2016/03/18 23:38:21.79: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@lewis 2016/03/18 23:38:21.79: 9 2: NdpRsrcQueryFSAllocate 0285fdd0 2016/03/18 23:38:21.79: 9 2: checkMountResource in tid#2 2016/03/18 23:38:21.79: 1 2: Connecting to \\lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/03/18 23:38:21.79: 1 2: NTLMv1 Support enabled 2016/03/18 23:38:22.43: 4 2: Server supports NT1 protocol 2016/03/18 23:38:22.43: 4 2: session setuping for <lewis>/<********> in <workgroup> 2016/03/18 23:38:22.56: 4 2: logon by lewis succeeded 2016/03/18 23:38:22.56: 4 2: session setup ok. Sending tconx <data> <********> 2016/03/18 23:38:22.60: 4 2: tconx ok 2016/03/18 23:38:22.60: 4 2: smbwrp_dskattr 2016/03/18 23:38:22.65: 4 2: Error in cli_disk_size: NT_STATUS_INVALID_NETWORK_RESPONSE 2016/03/18 23:38:22.65: 4 2: smbwrp_disconnect 2016/03/18 23:38:22.69: 9 2: NdpRsrcQueryFSAllocate 87/0 (cUnit = 123456/cUnitAvail = 123456/cbSector = 2048) 2016/03/18 23:38:22.69: 9 2: NdpRsrcQueryInfo in 2016/03/18 23:38:22.69: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@lewis 2016/03/18 23:38:22.69: 9 2: NdpRsrcQueryInfo in 2016/03/18 23:38:22.69: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@lewis 2016/03/18 23:38:22.69: 9 2: NdpRsrcQueryInfo in 2016/03/18 23:38:22.69: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@lewis 2016/03/18 23:38:22.69: 9 2: NdpRsrcQueryInfo in 2016/03/18 23:38:22.69: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@lewis 2016/03/18 23:38:22.69: 9 2: NdpQueryPathInfo in [0x670940] <*> 2016/03/18 23:38:22.69: 9 2: NdpFindStart in [0x670940] 2016/03/18 23:38:22.69: 9 2: NdpFindStart: dir [\], dir_mask [*], mask [\*], szPath [*] 2016/03/18 23:38:22.69: 4 2: smbwrp_filelist 2016/03/18 23:38:22.70: 1 2: Filelist <\*> on master <WORKGROUP> wgrp <workgroup> server <othello> share <data> clidev <A:> 2016/03/18 23:38:22.70: 1 2: list_files 2016/03/18 23:38:22.70: 9 2: dircache_list_files [] 2016/03/18 23:38:22.70: 9 2: findDirCache: [] 2016/03/18 23:38:22.70: 9 2: findDirCache: entry [Images\NY\Billing\Clients\ColPal] 2016/03/18 23:38:22.70: 9 2: findDirCache: entry [Images\NY\Billing\Clients] 2016/03/18 23:38:22.70: 9 2: findDirCache: entry [Images\NY\Billing] 2016/03/18 23:38:22.70: 9 2: findDirCache: entry [Images\NY] 2016/03/18 23:38:22.70: 9 2: findDirCache: entry [Images] 2016/03/18 23:38:22.70: 9 2: findDirCache: entry [] 2016/03/18 23:38:22.70: 9 2: dcePathEqualTo: [] [] 2016/03/18 23:38:22.70: 9 2: findDirCache: 0x6732a0 2016/03/18 23:38:22.70: 9 2: CacheRead: entry 0x6732a0 found for [] 2016/03/18 23:38:22.70: 9 2: CacheRead: expired 2016/03/18 23:38:22.70: 9 2: CacheRead: [], 0 2016/03/18 23:38:22.70: 4 2: list_files level 260. mask <\*> 2016/03/18 23:38:22.70: 9 2: NdpFindStart <*> (\*) cnt 0 0
FTP plugin continues to work as expected. The only way to regain access to Samba share is to restart the control program.
comment:3 by , 9 years ago
Quick update, here.
What I've discovered is that the lag must be between accesses of the/a Samba share and not from the time the control program is started. Thus, I can boot the system, let it sit idle overnight, and the next day, my first access of a Samba share will proceed as expected. However, if I boot, access the share, and then leave it idle, the next access will fail.
comment:4 by , 9 years ago
Hmm I wonder if it is related to caching? It might be interesting to back out the caching code and see if the problem goes away. That would give some good clues...
comment:5 by , 9 years ago
Default cache time is only 10 seconds, so I struggle to see any relationship there... I'll try and see if I can reproduce here. I've just accessed my samba server and will try again in an hour....
comment:6 by , 9 years ago
No delay here after the client idling for an hour..... I did a dir though, not an attempt at filename completion. I will try the tab filename completion again in another hour
comment:7 by , 9 years ago
All good with tab completion here after an hour as well....
Any other tips on trying to reproduce? Server here is running Samba 4.3.x on Ubuntu Server 16.04
comment:8 by , 9 years ago
What authentication are you using, Paul? I have a hunch that we won't see this with Kerberos, only with NTLMv1/v2.
Using your latest 4.4.2, I started the control program and ran a dir against an NTLMv1-authenticated SMB1 share. I let the system sit overnight, and I had no connectivity (dir failed) this morning until I stopped and restarted the control program.
comment:9 by , 9 years ago
I must work out how to subscribe to bug reports so that I see when updates are posted. I'm using SMB3 - not sure about authentication method, whatever Samba 4.x defaults to I suspect. Not kerberos.
comment:10 by , 9 years ago
| Cc: | added |
|---|
comment:11 by , 9 years ago
I just did some testing to a Samba Server running eCS, connection protocol is NT1. I also don't see the hang there. Anything unusual in smb.conf that could be contributing?
Can you upload a full log.ndpsmb?
comment:12 by , 9 years ago
Hmmm...
I thought of this the other day, and meant to have another look. Possible side-effect of spnego?
[global]
workgroup = WORKGROUP
loglevel = 10
client ntlmv2 auth = no
client use spnego = yes
That was a leftover from when we first started testing Kerberos. I'll turn it off. What does yours say?
comment:13 by , 9 years ago
| Resolution: | → invalid |
|---|---|
| Status: | new → closed |
Closing this as invalid.
Changing client use spnego = no seems to have resolved the issue. We might consider whether a change is needed to the default behavior or whether this should be a readme item when using non-SPNEGO methods.
Sorry to have wasted your time with this, Paul. Thanks for testing and providing a comparison. I should have re-tested on a clean system.
comment:14 by , 9 years ago
| Resolution: | invalid |
|---|---|
| Status: | closed → reopened |
Ah, wait...
I was wrong.
After sitting overnight:
[c:\]dir g:
fails, while:
[c:\]dir g:\Temp
succeeds.
comment:16 by , 9 years ago
Well, I was going to point to #261, but realized that I hadn't posted the log there, so...
2016/04/28 08:48:02.23: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:02.23: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:02.24: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:02.24: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:02.24: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:02.24: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:02.24: 9 2: NdpRsrcQueryFSAllocate 0285fdd0 2016/04/28 08:48:02.24: 9 2: checkMountResource in tid#2 2016/04/28 08:48:02.24: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/04/28 08:48:02.24: 1 2: NTLMv1 Support enabled 2016/04/28 08:48:02.45: 4 2: Server supports NT1 protocol 2016/04/28 08:48:02.45: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/04/28 08:48:02.52: 4 2: logon by Lewis succeeded 2016/04/28 08:48:02.52: 4 2: session setup ok. Sending tconx <data> <********> 2016/04/28 08:48:02.55: 4 2: tconx ok 2016/04/28 08:48:02.55: 4 2: smbwrp_dskattr 2016/04/28 08:48:02.59: 4 2: Error in cli_disk_size: NT_STATUS_INVALID_NETWORK_RESPONSE 2016/04/28 08:48:02.59: 4 2: smbwrp_disconnect 2016/04/28 08:48:02.62: 9 2: NdpRsrcQueryFSAllocate 87/0 (cUnit = 123456/cUnitAvail = 123456/cbSector = 2048) 2016/04/28 08:48:02.62: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:02.62: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:02.62: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:02.62: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:02.62: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:02.63: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:02.63: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:02.63: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:02.63: 9 2: NdpQueryPathInfo in [0x6709c0] <*> 2016/04/28 08:48:02.63: 9 2: NdpFindStart in [0x6709c0] 2016/04/28 08:48:02.63: 9 2: NdpFindStart: dir [\], dir_mask [*], mask [\*], szPath [*] 2016/04/28 08:48:02.63: 4 2: smbwrp_filelist 2016/04/28 08:48:02.63: 1 2: Filelist <\*> on master <WORKGROUP> wgrp <workgroup> server <othello> share <data> clidev <A:> 2016/04/28 08:48:02.63: 1 2: list_files 2016/04/28 08:48:02.63: 9 2: dircache_list_files [] 2016/04/28 08:48:02.63: 9 2: findDirCache: [] 2016/04/28 08:48:02.63: 9 2: findDirCache: 0 2016/04/28 08:48:02.63: 9 2: CacheRead: [], 0 2016/04/28 08:48:02.63: 4 2: list_files level 260. mask <\*> 2016/04/28 08:48:02.63: 9 2: NdpFindStart <*> (\*) cnt 0 0 2016/04/28 08:48:08.85: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:08.85: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:08.85: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:08.85: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:08.86: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:08.86: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:08.86: 9 2: NdpRsrcQueryFSAllocate 0285fdd0 2016/04/28 08:48:08.86: 9 2: checkMountResource in tid#2 2016/04/28 08:48:08.86: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/04/28 08:48:08.86: 1 2: NTLMv1 Support enabled 2016/04/28 08:48:09.20: 4 2: Server supports NT1 protocol 2016/04/28 08:48:09.20: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/04/28 08:48:09.28: 4 2: logon by Lewis succeeded 2016/04/28 08:48:09.28: 4 2: session setup ok. Sending tconx <data> <********> 2016/04/28 08:48:09.31: 4 2: tconx ok 2016/04/28 08:48:09.31: 4 2: smbwrp_dskattr 2016/04/28 08:48:09.35: 4 2: Error in cli_disk_size: NT_STATUS_INVALID_NETWORK_RESPONSE 2016/04/28 08:48:09.35: 4 2: smbwrp_disconnect 2016/04/28 08:48:09.38: 9 2: NdpRsrcQueryFSAllocate 87/0 (cUnit = 123456/cUnitAvail = 123456/cbSector = 2048) 2016/04/28 08:48:09.39: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:09.39: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:09.39: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:09.39: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:09.39: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:09.39: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:09.39: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:09.39: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:09.39: 9 2: NdpQueryPathInfo in [0x6709c0] <temp> 2016/04/28 08:48:09.39: 9 2: dircache_find_path [temp] 2016/04/28 08:48:09.39: 9 2: dcFindPath: [][temp] 2016/04/28 08:48:09.39: 9 2: dircache: FindPath temp not found 2016/04/28 08:48:09.39: 9 2: NdpQueryPathInfo pathparser for <\temp> rc=0 2016/04/28 08:48:09.39: 9 2: NdpQueryPathInfo smbwrp_getattr for <\temp> 2016/04/28 08:48:09.39: 4 2: smbwrp_echo 2016/04/28 08:48:09.40: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/04/28 08:48:09.40: 1 2: NTLMv1 Support enabled 2016/04/28 08:48:09.59: 4 2: Server supports NT1 protocol 2016/04/28 08:48:09.59: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/04/28 08:48:09.65: 4 2: logon by Lewis succeeded 2016/04/28 08:48:09.65: 4 2: session setup ok. Sending tconx <data> <********> 2016/04/28 08:48:09.69: 4 2: tconx ok 2016/04/28 08:48:09.69: 4 2: smbwrp_getattr 2016/04/28 08:48:09.69: 4 2: getattr 0 16 <\temp> 2016/04/28 08:48:09.69: 4 2: smbwrp_getattr, calling cli_qpathinfo2 2016/04/28 08:48:09.72: 9 2: fname \temp 2016/04/28 08:48:09.72: 9 2: size 0 2016/04/28 08:48:09.72: 9 2: mtime 1461251385 Thu Apr 21 11:09:45 2016 2016/04/28 08:48:09.72: 9 2: ftimeLastAccess 11:09:44 2016/04/28 08:48:09.73: 9 2: NdpQueryPathInfo <temp> (\temp) 0 2016/04/28 08:48:09.73: 9 2: NdpEASize in [0x6709c0] <\temp> 2016/04/28 08:48:09.73: 4 2: smbwrp_listea 2016/04/28 08:48:09.73: 4 2: EAList for <\temp> 2016/04/28 08:48:09.76: 4 2: ea_get_file list failed - NT_STATUS_INVALID_NETWORK_RESPONSE 2016/04/28 08:48:09.76: 9 2: NdpEASize <temp> 0 282 2016/04/28 08:48:09.77: 9 2: NdpRsrcQueryInfo in 2016/04/28 08:48:09.77: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/28 08:48:09.77: 9 2: NdpQueryPathInfo in [0x6709c0] <temp\*> 2016/04/28 08:48:09.77: 9 2: NdpFindStart in [0x6709c0] 2016/04/28 08:48:09.77: 9 2: NdpFindStart: dir [\temp\], dir_mask [*], mask [\temp\*], szPath [temp\*] 2016/04/28 08:48:09.77: 4 2: smbwrp_filelist 2016/04/28 08:48:09.77: 1 2: Filelist <\temp\*> on master <WORKGROUP> wgrp <workgroup> server <othello> share <data> clidev <A:> 2016/04/28 08:48:09.77: 1 2: list_files 2016/04/28 08:48:09.77: 9 2: dircache_list_files [temp] 2016/04/28 08:48:09.77: 9 2: findDirCache: [temp] 2016/04/28 08:48:09.77: 9 2: findDirCache: 0 2016/04/28 08:48:09.77: 9 2: CacheRead: [temp], 0 2016/04/28 08:48:09.77: 4 2: list_files level 260. mask <\temp\*>
This is essentially as I posted it, above, I think. There is one other possibility we haven't discussed: NetWare's CIFS implementation, unlike the native NW.IFS, does not support EAs, yet I have EA support enabled for the share. Thus, I do see repeated entries in the log for:
2016/04/27 23:32:29.44: 9 2: NdpEASize in [0x6709c0] <\HCA5> 2016/04/27 23:32:29.44: 4 2: smbwrp_listea 2016/04/27 23:32:29.44: 4 2: EAList for <\HCA5> 2016/04/27 23:32:29.47: 4 2: ea_get_file list failed - NT_STATUS_INVALID_NETWORK_RESPONSE 2016/04/27 23:32:29.47: 9 2: NdpEASize <HCA5> 0 282
I wonder if the lack of EA support has any bearing on this (when the client is configured to expect it)? I'll try specifically disabling EA support.
comment:17 by , 9 years ago
Fresh attempt (before I had to go sifting):
2016/04/29 01:15:07.11: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:15:07.11: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:15:07.11: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:15:07.11: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:15:07.11: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:15:07.11: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:15:07.12: 9 2: NdpRsrcQueryFSAllocate 0285fdd0 2016/04/29 01:15:07.12: 9 2: checkMountResource in tid#2 2016/04/29 01:15:07.12: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/04/29 01:15:07.12: 1 2: NTLMv1 Support enabled 2016/04/29 01:15:07.45: 4 2: Server supports NT1 protocol 2016/04/29 01:15:07.45: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/04/29 01:15:07.55: 4 2: logon by Lewis succeeded 2016/04/29 01:15:07.56: 4 2: session setup ok. Sending tconx <data> <********> 2016/04/29 01:15:07.59: 4 2: tconx ok 2016/04/29 01:15:07.59: 4 2: smbwrp_dskattr 2016/04/29 01:15:07.62: 4 2: Error in cli_disk_size: NT_STATUS_INVALID_NETWORK_RESPONSE 2016/04/29 01:15:07.63: 4 2: smbwrp_disconnect 2016/04/29 01:15:07.66: 9 2: NdpRsrcQueryFSAllocate 87/0 (cUnit = 123456/cUnitAvail = 123456/cbSector = 2048) 2016/04/29 01:15:07.66: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:15:07.66: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:15:07.66: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:15:07.66: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:15:07.66: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:15:07.66: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:15:07.66: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:15:07.67: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:15:07.67: 9 2: NdpQueryPathInfo in [0x689a20] <*> 2016/04/29 01:15:07.67: 9 2: NdpFindStart in [0x689a20] 2016/04/29 01:15:07.67: 9 2: NdpFindStart: dir [\], dir_mask [*], mask [\*], szPath [*] 2016/04/29 01:15:07.67: 4 2: smbwrp_filelist 2016/04/29 01:15:07.67: 1 2: Filelist <\*> on master <WORKGROUP> wgrp <workgroup> server <othello> share <data> clidev <A:> 2016/04/29 01:15:07.67: 1 2: list_files 2016/04/29 01:15:07.67: 9 2: dircache_list_files [] 2016/04/29 01:15:07.67: 9 2: findDirCache: [] 2016/04/29 01:15:07.67: 9 2: findDirCache: entry [] 2016/04/29 01:15:07.67: 9 2: dcePathEqualTo: [] [] 2016/04/29 01:15:07.67: 9 2: findDirCache: 0x6765c0 2016/04/29 01:15:07.67: 9 2: CacheRead: entry 0x6765c0 found for [] 2016/04/29 01:15:07.67: 9 2: CacheRead: expired 2016/04/29 01:15:07.67: 9 2: CacheRead: [], 0 2016/04/29 01:15:07.67: 4 2: list_files level 260. mask <\*> 2016/04/29 01:15:07.67: 9 2: NdpFindStart <*> (\*) cnt 0 0
Result:
SYS0002: The system cannot find the file specified.
Once I tack on a directory ("\" by itself won't do; it must be a directory name), I then get:
2016/04/29 01:18:35.43: 9 2: NdpRsrcQueryFSAllocate 87/0 (cUnit = 123456/cUnitAvail = 123456/cbSector = 2048) 2016/04/29 01:18:35.43: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:18:35.43: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:18:35.43: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:18:35.43: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:18:35.43: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:18:35.43: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:18:35.43: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:18:35.43: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:18:35.43: 9 2: NdpQueryPathInfo in [0x689a20] <temp> 2016/04/29 01:18:35.43: 9 2: dircache_find_path [temp] 2016/04/29 01:18:35.43: 9 2: dcFindPath: [][temp] 2016/04/29 01:18:35.43: 9 2: dircache: FindPath temp not found 2016/04/29 01:18:35.43: 9 2: NdpQueryPathInfo pathparser for <\temp> rc=0 2016/04/29 01:18:35.43: 9 2: NdpQueryPathInfo smbwrp_getattr for <\temp> 2016/04/29 01:18:35.43: 4 2: smbwrp_echo 2016/04/29 01:18:35.45: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/04/29 01:18:35.45: 1 2: NTLMv1 Support enabled 2016/04/29 01:18:35.67: 4 2: Server supports NT1 protocol 2016/04/29 01:18:35.67: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/04/29 01:18:35.74: 4 2: logon by Lewis succeeded 2016/04/29 01:18:35.74: 4 2: session setup ok. Sending tconx <data> <********> 2016/04/29 01:18:35.78: 4 2: tconx ok 2016/04/29 01:18:35.78: 4 2: smbwrp_getattr 2016/04/29 01:18:35.78: 4 2: getattr 0 16 <\temp> 2016/04/29 01:18:35.78: 4 2: smbwrp_getattr, calling cli_qpathinfo2 2016/04/29 01:18:35.81: 9 2: fname \temp 2016/04/29 01:18:35.81: 9 2: size 0 2016/04/29 01:18:35.82: 9 2: mtime 1461251385 Thu Apr 21 11:09:45 2016 2016/04/29 01:18:35.82: 9 2: ftimeLastAccess 11:09:44 2016/04/29 01:18:35.82: 9 2: NdpQueryPathInfo <temp> (\temp) 0 2016/04/29 01:18:35.82: 9 2: NdpEASize in [0x689a20] <\temp> 2016/04/29 01:18:35.82: 4 2: smbwrp_listea 2016/04/29 01:18:35.82: 4 2: EAList for <\temp> 2016/04/29 01:18:35.85: 4 2: ea_get_file list failed - NT_STATUS_INVALID_NETWORK_RESPONSE 2016/04/29 01:18:35.85: 9 2: NdpEASize <temp> 0 282 2016/04/29 01:18:35.85: 9 2: NdpRsrcQueryInfo in 2016/04/29 01:18:35.85: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/04/29 01:18:35.85: 9 2: NdpQueryPathInfo in [0x689a20] <temp\*> 2016/04/29 01:18:35.85: 9 2: NdpFindStart in [0x689a20] 2016/04/29 01:18:35.85: 9 2: NdpFindStart: dir [\temp\], dir_mask [*], mask [\temp\*], szPath [temp\*] 2016/04/29 01:18:35.86: 4 2: smbwrp_filelist 2016/04/29 01:18:35.86: 1 2: Filelist <\temp\*> on master <WORKGROUP> wgrp <workgroup> server <othello> share <data> clidev <A:> 2016/04/29 01:18:35.86: 1 2: list_files 2016/04/29 01:18:35.86: 9 2: dircache_list_files [temp] 2016/04/29 01:18:35.86: 9 2: findDirCache: [temp] 2016/04/29 01:18:35.86: 9 2: findDirCache: 0 2016/04/29 01:18:35.86: 9 2: CacheRead: [temp], 0 2016/04/29 01:18:35.86: 4 2: list_files level 260. mask <\temp\*> 2016/04/29 01:18:36.85: 9 2: dircache_write_begin pdc 0x625800 path [temp] 2016/04/29 01:18:36.85: 9 2: findDirCache: [temp] 2016/04/29 01:18:36.86: 9 2: findDirCache: 0 2016/04/29 01:18:36.86: 9 2: CacheWriteBegin: temp 2016/04/29 01:18:36.86: 9 2: dircache_write_begin returning ctx 0x679b60 2016/04/29 01:18:36.86: 4 2: list_files: got 54 files 2016/04/29 01:18:36.86: 4 2: smbwrp_dir_add 2016/04/29 01:18:36.86: 8 2: adding <.> 289 0 261 2016/04/29 01:18:36.86: 9 2: fname \temp\. 2016/04/29 01:18:36.86: 9 2: size 0 2016/04/29 01:18:36.86: 9 2: mtime 1461251385 Thu Apr 21 11:09:45 2016 2016/04/29 01:18:36.86: 9 2: ftimeLastAccess 11:09:44 2016/04/29 01:18:36.86: 9 2: dircache_write_entry 0x679b60 2016/04/29 01:18:36.86: 4 2: smbwrp_dir_add 2016/04/29 01:18:36.86: 8 2: adding <..> 289 0 261 2016/04/29 01:18:36.86: 9 2: fname \temp\.. 2016/04/29 01:18:36.86: 9 2: size 0 2016/04/29 01:18:36.86: 9 2: mtime 1461010663 Mon Apr 18 16:17:43 2016 2016/04/29 01:18:36.86: 9 2: ftimeLastAccess 16:17:42 2016/04/29 01:18:36.86: 9 2: dircache_write_entry 0x679b60 2016/04/29 01:18:36.86: 4 2: smbwrp_dir_add
and the listing proceeds as expected.
comment:18 by , 8 years ago
Can you please try (with latest 4.4.4 code): [c:\]dir g:
wait 1 hour 1 minute (or however long you normally wait) then: [c:\]dir g: (again)
and send unedited ndpsmb.log?
I'd like to see a log for a working and non-working case of the same directory listing.
I really wish I could reproduce locally :(
comment:19 by , 8 years ago
Aha...
Got the condition with SMB1. Did not get it with SMB3_11.
Sending unedited logs privately, as there is some directory content which may not be suitable for public display.
I should try toggling EA support for the NetWare CIFS off, just in case that's a factor.
comment:20 by , 8 years ago
I should try toggling EA support for the NetWare CIFS off, just in case that's a factor.
I can confirm that whether EAs are enabled for the non-EA-aware SMB1 share, this condition is consistent.
comment:21 by , 8 years ago
Seems fixed with:
6-22-16 3:51 13,953,656 124 ndpsmb.dll
First run ([c:\]dir g:):
2016/06/22 16:37:29.8: 9 2: NdpRsrcQueryInfo in 2016/06/22 16:37:29.12: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 16:37:29.12: 9 2: NdpRsrcQueryInfo in 2016/06/22 16:37:29.12: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 16:37:29.14: 9 2: NdpRsrcQueryInfo in 2016/06/22 16:37:29.14: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 16:37:29.14: 9 2: NdpRsrcQueryFSAllocate 0285fdd0 2016/06/22 16:37:29.14: 9 2: checkMountResource in tid#2 2016/06/22 16:37:29.16: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/06/22 16:37:29.17: 1 2: NTLMv1 Support enabled 2016/06/22 16:37:29.78: 4 2: Server supports NT1 protocol 2016/06/22 16:37:29.78: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/06/22 16:37:30.15: 4 2: logon by Lewis succeeded 2016/06/22 16:37:30.15: 4 2: session setup ok. Sending tconx <data> <********> 2016/06/22 16:37:30.19: 4 2: tconx ok 2016/06/22 16:37:30.19: 4 2: smbwrp_dskattr 2016/06/22 16:37:30.27: 4 2: Error in cli_disk_size: NT_STATUS_INVALID_NETWORK_RESPONSE 2016/06/22 16:37:30.27: 4 2: smbwrp_disconnect 2016/06/22 16:37:30.39: 9 2: NdpRsrcQueryFSAllocate rc=87/rc1=0 (cUnit = 123456/cUnitAvail = 123456/cbSector = 2048) 2016/06/22 16:37:30.39: 9 2: NdpRsrcQueryInfo in 2016/06/22 16:37:30.39: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 16:37:30.39: 9 2: NdpRsrcQueryInfo in 2016/06/22 16:37:30.39: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 16:37:30.39: 9 2: NdpRsrcQueryInfo in 2016/06/22 16:37:30.39: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 16:37:30.39: 9 2: NdpRsrcQueryInfo in 2016/06/22 16:37:30.39: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 16:37:30.40: 9 2: NdpCreateConnection in 2016/06/22 16:37:30.40: 9 2: NdpCreateConnection send CONNECT 2016/06/22 16:37:30.40: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/06/22 16:37:30.40: 1 2: NTLMv1 Support enabled 2016/06/22 16:37:30.62: 4 2: Server supports NT1 protocol 2016/06/22 16:37:30.63: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/06/22 16:37:30.67: 4 2: logon by Lewis succeeded 2016/06/22 16:37:30.68: 4 2: session setup ok. Sending tconx <data> <********> 2016/06/22 16:37:30.80: 4 2: tconx ok 2016/06/22 16:37:30.81: 9 2: NdpCreateConnection [0x671120] rc=0 2016/06/22 16:37:30.81: 9 2: NdpQueryPathInfo in [0x671120] <*> 2016/06/22 16:37:30.81: 9 2: NdpFindStart in [0x671120] 2016/06/22 16:37:30.81: 9 2: NdpFindStart: dir [\], dir_mask [*], mask [\*], szPath [*] 2016/06/22 16:37:30.81: 4 2: smbwrp_echo 2016/06/22 16:37:30.90: 4 2: smbwrp_filelist 2016/06/22 16:37:30.91: 1 2: Filelist <\*> on master <WORKGROUP> wgrp <workgroup> server <othello> share <data> clidev <A:> 2016/06/22 16:37:30.91: 1 2: list_files 2016/06/22 16:37:30.91: 9 2: dircache_list_files [] 2016/06/22 16:37:30.91: 9 2: findDirCache: [] 2016/06/22 16:37:30.91: 9 2: findDirCache: 0 2016/06/22 16:37:30.91: 9 2: CacheRead: [], 0 2016/06/22 16:37:30.91: 4 2: list_files level 260. mask <\*> 2016/06/22 16:37:34.42: 9 2: dircache_write_begin pdc 0x6257a0 path [] 2016/06/22 16:37:34.42: 9 2: findDirCache: [] 2016/06/22 16:37:34.42: 9 2: findDirCache: 0 2016/06/22 16:37:34.42: 9 2: CacheWriteBegin: 2016/06/22 16:37:34.42: 9 2: dircache_write_begin returning ctx 0x672b80 2016/06/22 16:37:34.42: 4 2: list_files: got 103 files 2016/06/22 16:37:34.42: 4 2: smbwrp_dir_add 2016/06/22 16:37:34.42: 8 2: adding <1040> 289 529564672 261 2016/06/22 16:37:34.43: 9 2: fname \1040 2016/06/22 16:37:34.43: 9 2: size 0 2016/06/22 16:37:34.43: 9 2: mtime 1292633962 Fri Dec 17 19:59:22 2010 2016/06/22 16:37:34.43: 9 2: ftimeLastAccess 19:59:22 2016/06/22 16:37:34.43: 9 2: dircache_write_entry 0x672b80 [...] 2016/06/22 16:37:34.82: 9 2: mtime 1292686078 Sat Dec 18 10:27:58 2010 2016/06/22 16:37:34.82: 9 2: ftimeLastAccess 10:27:58 2016/06/22 16:37:34.82: 9 2: dircache_write_entry 0x672b80 2016/06/22 16:37:34.82: 9 2: dircache_write_end: pdce 0x672b80 2016/06/22 16:37:34.82: 9 2: NdpFindStart <*> (\*) cnt 0 rc=0
wait approx 2 hours 25 minutes, and run again:
2016/06/22 19:02:30.38: 9 2: NdpRsrcQueryInfo in 2016/06/22 19:02:30.39: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 19:02:30.39: 9 2: NdpRsrcQueryInfo in 2016/06/22 19:02:30.39: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 19:02:30.39: 9 2: NdpRsrcQueryInfo in 2016/06/22 19:02:30.39: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 19:02:30.40: 9 2: NdpRsrcQueryFSAllocate 0285fdd0 2016/06/22 19:02:30.40: 9 2: checkMountResource in tid#2 2016/06/22 19:02:30.40: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/06/22 19:02:30.40: 1 2: NTLMv1 Support enabled 2016/06/22 19:02:31.23: 4 2: Server supports NT1 protocol 2016/06/22 19:02:31.23: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/06/22 19:02:31.36: 4 2: logon by Lewis succeeded 2016/06/22 19:02:31.36: 4 2: session setup ok. Sending tconx <data> <********> 2016/06/22 19:02:31.40: 4 2: tconx ok 2016/06/22 19:02:31.40: 4 2: smbwrp_dskattr 2016/06/22 19:02:31.43: 4 2: Error in cli_disk_size: NT_STATUS_INVALID_NETWORK_RESPONSE 2016/06/22 19:02:31.43: 4 2: smbwrp_disconnect 2016/06/22 19:02:31.47: 9 2: NdpRsrcQueryFSAllocate rc=87/rc1=0 (cUnit = 123456/cUnitAvail = 123456/cbSector = 2048) 2016/06/22 19:02:31.47: 9 2: NdpRsrcQueryInfo in 2016/06/22 19:02:31.47: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 19:02:31.47: 9 2: NdpRsrcQueryInfo in 2016/06/22 19:02:31.47: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 19:02:31.47: 9 2: NdpRsrcQueryInfo in 2016/06/22 19:02:31.47: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 19:02:31.47: 9 2: NdpRsrcQueryInfo in 2016/06/22 19:02:31.47: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/22 19:02:31.47: 9 2: NdpQueryPathInfo in [0x671120] <*> 2016/06/22 19:02:31.47: 9 2: NdpFindStart in [0x671120] 2016/06/22 19:02:31.47: 9 2: NdpFindStart: dir [\], dir_mask [*], mask [\*], szPath [*] 2016/06/22 19:02:31.47: 4 2: smbwrp_echo 2016/06/22 19:02:31.52: 4 2: smbwrp_filelist 2016/06/22 19:02:31.52: 1 2: Filelist <\*> on master <WORKGROUP> wgrp <workgroup> server <othello> share <data> clidev <A:> 2016/06/22 19:02:31.52: 1 2: list_files 2016/06/22 19:02:31.52: 9 2: dircache_list_files [] 2016/06/22 19:02:31.52: 9 2: findDirCache: [] 2016/06/22 19:02:31.52: 9 2: findDirCache: entry [] 2016/06/22 19:02:31.52: 9 2: dcePathEqualTo: [] [] 2016/06/22 19:02:31.53: 9 2: findDirCache: 0x672b80 2016/06/22 19:02:31.53: 9 2: CacheRead: entry 0x672b80 found for [] 2016/06/22 19:02:31.53: 9 2: CacheRead: expired 2016/06/22 19:02:31.53: 9 2: CacheRead: [], 0 2016/06/22 19:02:31.53: 4 2: list_files level 260. mask <\*> 2016/06/22 19:02:32.52: 9 2: dircache_write_begin pdc 0x6257a0 path [] 2016/06/22 19:02:32.52: 9 2: findDirCache: [] 2016/06/22 19:02:32.52: 9 2: findDirCache: 0 2016/06/22 19:02:32.53: 9 2: CacheWriteBegin: 2016/06/22 19:02:32.53: 9 2: dircache_write_begin returning ctx 0x673ac0 2016/06/22 19:02:32.53: 4 2: list_files: got 103 files 2016/06/22 19:02:32.53: 4 2: smbwrp_dir_add 2016/06/22 19:02:32.53: 8 2: adding <1040> 289 529564672 261 2016/06/22 19:02:32.53: 9 2: fname \1040 2016/06/22 19:02:32.53: 9 2: size 0 2016/06/22 19:02:32.53: 9 2: mtime 1292633962 Fri Dec 17 19:59:22 2010 2016/06/22 19:02:32.53: 9 2: ftimeLastAccess 19:59:22 2016/06/22 19:02:32.53: 9 2: dircache_write_entry 0x673ac0 [...] 2016/06/22 19:02:32.91: 9 2: mtime 1292686078 Sat Dec 18 10:27:58 2010 2016/06/22 19:02:32.91: 9 2: ftimeLastAccess 10:27:58 2016/06/22 19:02:32.91: 9 2: dircache_write_entry 0x673ac0 2016/06/22 19:02:32.91: 9 2: dircache_write_end: pdce 0x673ac0 2016/06/22 19:02:32.91: 9 2: NdpFindStart <*> (\*) cnt 0 rc=0
I'm certain we were losing the connection in under 2 hours before (more like 45 minutes to an hour, IIRC).
I'll keep this open and try the dir again in the morning, with the client sitting idle. If we get success then, I'll close this ticket as resolved.
Thanks, Paul!
comment:22 by , 8 years ago
Hey Lewis.
The log above shows my fix had no impact here - ie it wasn't needed.
2016/06/22 19:02:31.47: 9 2: NdpFindStart: dir [\], dir_mask [*], mask [\*], szPath [*] 2016/06/22 19:02:31.47: 4 2: smbwrp_echo 2016/06/22 19:02:31.52: 4 2: smbwrp_filelist
if smbwrp_echo - ie a ping to the server fails, the client will now automatically reconnect - this didn't happen in the above....
comment:23 by , 8 years ago
Okay, then.
I waited 10.5 hours, and in between, the VPN connection itself went down (power went out), though my client did not (on battery; thus, the control program was running continuously).
The dir command worked. Here is the log:
2016/06/23 10:37:09.37: 9 2: NdpRsrcQueryInfo in 2016/06/23 10:37:09.40: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/23 10:37:09.40: 9 2: NdpRsrcQueryInfo in 2016/06/23 10:37:09.40: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/23 10:37:09.41: 9 2: NdpRsrcQueryInfo in 2016/06/23 10:37:09.41: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/23 10:37:09.41: 9 2: NdpRsrcQueryFSAllocate 0285fdd0 2016/06/23 10:37:09.41: 9 2: checkMountResource in tid#2 2016/06/23 10:37:09.41: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/06/23 10:37:09.41: 1 2: NTLMv1 Support enabled 2016/06/23 10:37:10.21: 4 2: Server supports NT1 protocol 2016/06/23 10:37:10.21: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/06/23 10:37:10.34: 4 2: logon by Lewis succeeded 2016/06/23 10:37:10.34: 4 2: session setup ok. Sending tconx <data> <********> 2016/06/23 10:37:10.38: 4 2: tconx ok 2016/06/23 10:37:10.38: 4 2: smbwrp_dskattr 2016/06/23 10:37:10.48: 4 2: Error in cli_disk_size: NT_STATUS_INVALID_NETWORK_RESPONSE 2016/06/23 10:37:10.48: 4 2: smbwrp_disconnect 2016/06/23 10:37:10.51: 9 2: NdpRsrcQueryFSAllocate rc=87/rc1=0 (cUnit = 123456/cUnitAvail = 123456/cbSector = 2048) 2016/06/23 10:37:10.51: 9 2: NdpRsrcQueryInfo in 2016/06/23 10:37:10.51: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/23 10:37:10.52: 9 2: NdpRsrcQueryInfo in 2016/06/23 10:37:10.52: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/23 10:37:10.52: 9 2: NdpRsrcQueryInfo in 2016/06/23 10:37:10.52: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/23 10:37:10.52: 9 2: NdpRsrcQueryInfo in 2016/06/23 10:37:10.52: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:othello\data@Lewis 2016/06/23 10:37:10.52: 9 2: NdpQueryPathInfo in [0x626260] <*> 2016/06/23 10:37:10.52: 9 2: NdpFindStart in [0x626260] 2016/06/23 10:37:10.52: 9 2: NdpFindStart: dir [\], dir_mask [*], mask [\*], szPath [*] 2016/06/23 10:37:10.52: 4 2: smbwrp_echo 2016/06/23 10:37:10.52: 4 2: NdpFindStart, smbwrp_echo rc = -1, reconnecting..... 2016/06/23 10:37:10.52: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/06/23 10:37:10.52: 1 2: NTLMv1 Support enabled 2016/06/23 10:37:10.76: 4 2: Server supports NT1 protocol 2016/06/23 10:37:10.76: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/06/23 10:37:10.82: 4 2: logon by Lewis succeeded 2016/06/23 10:37:10.82: 4 2: session setup ok. Sending tconx <data> <********> 2016/06/23 10:37:11.0: 4 2: tconx ok 2016/06/23 10:37:11.0: 4 2: smbwrp_filelist 2016/06/23 10:37:11.0: 1 2: Filelist <\*> on master <WORKGROUP> wgrp <workgroup> server <othello> share <data> clidev <A:> 2016/06/23 10:37:11.0: 1 2: list_files 2016/06/23 10:37:11.0: 9 2: dircache_list_files [] 2016/06/23 10:37:11.0: 9 2: findDirCache: [] 2016/06/23 10:37:11.0: 9 2: findDirCache: entry [] 2016/06/23 10:37:11.0: 9 2: dcePathEqualTo: [] [] 2016/06/23 10:37:11.0: 9 2: findDirCache: 0x671180 2016/06/23 10:37:11.0: 9 2: CacheRead: entry 0x671180 found for [] 2016/06/23 10:37:11.0: 9 2: CacheRead: expired 2016/06/23 10:37:11.0: 9 2: CacheRead: [], 0 2016/06/23 10:37:11.0: 4 2: list_files level 260. mask <\*> 2016/06/23 10:37:12.45: 9 2: dircache_write_begin pdc 0x6257a0 path [] 2016/06/23 10:37:12.45: 9 2: findDirCache: [] 2016/06/23 10:37:12.45: 9 2: findDirCache: 0 2016/06/23 10:37:12.45: 9 2: CacheWriteBegin: 2016/06/23 10:37:12.45: 9 2: dircache_write_begin returning ctx 0x6718e0 2016/06/23 10:37:12.45: 4 2: list_files: got 103 files 2016/06/23 10:37:12.45: 4 2: smbwrp_dir_add 2016/06/23 10:37:12.45: 8 2: adding <1040> 289 764445696 261 2016/06/23 10:37:12.45: 9 2: fname \1040 2016/06/23 10:37:12.45: 9 2: size 0 2016/06/23 10:37:12.45: 9 2: mtime 1292633962 Fri Dec 17 19:59:22 2010 2016/06/23 10:37:12.45: 9 2: ftimeLastAccess 19:59:22 2016/06/23 10:37:12.45: 9 2: dircache_write_entry 0x6718e0 [...]
This time, I think we have it. See:
2016/06/23 10:37:10.52: 4 2: smbwrp_echo 2016/06/23 10:37:10.52: 4 2: NdpFindStart, smbwrp_echo rc = -1, reconnecting..... 2016/06/23 10:37:10.52: 1 2: Connecting to \\Lewis:*********@workgroup:othello\data. Master WORKGROUP:1 2016/06/23 10:37:10.52: 1 2: NTLMv1 Support enabled 2016/06/23 10:37:10.76: 4 2: Server supports NT1 protocol 2016/06/23 10:37:10.76: 4 2: session setuping for <Lewis>/<********> in <workgroup> 2016/06/23 10:37:10.82: 4 2: logon by Lewis succeeded 2016/06/23 10:37:10.82: 4 2: session setup ok. Sending tconx <data> <********> 2016/06/23 10:37:11.0: 4 2: tconx ok 2016/06/23 10:37:11.0: 4 2: smbwrp_filelist
Note:
See TracTickets
for help on using tickets.
This remains an issue with ndpsmb-samba_4.3.0rc3-heimdal-20150820. Once the cache expires, directories are not re-cached, tab completion fails, as does dir (tested against SMB1 share, with NTLM auth). Log snippet (dir <NetDrive volume>:) from log.ndpsmb:
Stopping the control program and starting it, gets this working again.
Note also reference to:
Error in cli_disk_size: NT_STATUS_INVALID_NETWORK_RESPONSENot sure if this is extra noise or something of importance.