Opened 9 years ago

Closed 8 years ago

#261 closed defect (fixed)

Restarting server leaves mappings disconnected

Reported by: Lewis Rosenthal Owned by:
Priority: minor Milestone:
Component: Samba Client Plugin Version: Client 3.0.x
Keywords: credentials, login, logon, authentication, disconnect, reconnect Cc:

Description

Server is Samba 4.1.8 on openSuSE 13.2, SMB2, NTLMv2 auth. Editing smb.conf and subsequently restarting the daemon (service smb restart) disconnects the NetDrive mapping, and only a manual re-mapping will work (no auto-reconnect).

Client is 

 7-04-15  17:23       5,512,638    124  ndpsmb.dll

Attachments (3)

log.ndpsmb​ (7.8 KB) - added by Lewis Rosenthal 9 years ago.
Log showing initial successful dir, followed by subsequent attempt after restarting 4.1.8 server daemon on remote system
log.smbc​ (39.1 KB) - added by Lewis Rosenthal 9 years ago.
Log showing initial successful dir, followed by subsequent attempt after restarting 4.1.8 server daemon on remote system
log.smbd​ (118.1 KB) - added by Lewis Rosenthal 9 years ago.
Server-side log (level 10) of failed dir attempt after daemon restart

Download all attachments as: .zip

Change History (13)

comment:1 Changed 9 years ago by Paul Smedley

Please attach logs - I don't see why ndpsmb wouldn't reconnect automatically

Changed 9 years ago by Lewis Rosenthal

Attachment: log.ndpsmb​ added

Log showing initial successful dir, followed by subsequent attempt after restarting 4.1.8 server daemon on remote system

Changed 9 years ago by Lewis Rosenthal

Attachment: log.smbc​ added

Log showing initial successful dir, followed by subsequent attempt after restarting 4.1.8 server daemon on remote system

Changed 9 years ago by Lewis Rosenthal

Attachment: log.smbd​ added

Server-side log (level 10) of failed dir attempt after daemon restart

comment:2 Changed 9 years ago by Lewis Rosenthal

I've now increased my client loglevel to 10 (it was 9), so if the above client-side logs are not detailed enough, I can easily reproduce this with the greater verbosity.

​https://bugzilla.samba.org/show_bug.cgi?id=10584 seems to mention a similar map_errno_from_nt_status (c000020c), though this could be coincidental (I have not read that bug thoroughly).

comment:3 Changed 9 years ago by Paul Smedley

I will have to try and reproduce locally. I see in the logs that it does reconnect, but list_files is returning no files....

comment:4 Changed 8 years ago by Paul Smedley

This works for me with Latest 4.4.2 client and a server running Samba Version 4.1.17-Debian on a Raspberry Pi.

I did a dir on the Pi from an OS/2 command prompt; ran 'sudo service smbd restart' on the Pi then re-did the dir on the OS/2 command prompt and everything was good.

comment:5 Changed 8 years ago by Lewis Rosenthal

With 4.4.2, connecting to samba-4.2.2-5.10.x86_64 on openSUSE 13.2, I get the same type of behavior as described in (the re-opening of) #263, where: 

[c:\]dir k:

fails, but: 

[c:\]dir k:\Documents

succeeds. This is, of course, after a restart of the server daemon on the far side of the connection (unlike #263, which deals with a constantly running server daemon).

Last edited 8 years ago by Lewis Rosenthal (previous) (diff)

comment:6 Changed 8 years ago by Paul Smedley

I still can't reproduce this either. Are you able to share your smb.conf? and also a screenshot of the ndpsmb settings from Netdrive. I wonder if there is a local configuration setting that influences this behaviour

Version 0, edited 8 years ago by Paul Smedley (next)

comment:7 Changed 8 years ago by Lewis Rosenthal

This one is easier than #263. ;-)

Here's the log connecting to samba-4.4.4-2.1.x86_64 on openSUSE Leap 42.1 after service smb restart: 

2016/06/19 15:06:17.40: 9 2: NdpRsrcQueryInfo in
2016/06/19 15:06:17.40: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/19 15:06:17.41: 9 2: NdpQueryPathInfo in [0x6738c0] <*>
2016/06/19 15:06:17.41: 9 2: NdpFindStart in [0x6738c0]
2016/06/19 15:06:17.41: 9 2: NdpFindStart: dir [\], dir_mask [*], mask [\*], szPath [*]
2016/06/19 15:06:17.41: 4 2:  smbwrp_filelist
2016/06/19 15:06:17.41: 1 2: Filelist <\*> on master <WORKGROUP> wgrp <workgroup> server <dp45sg> share <lewis> clidev <(null)>
2016/06/19 15:06:17.41: 1 2: list_files
2016/06/19 15:06:17.41: 4 2: SMB2 detected, calling list_files_smb2()
2016/06/19 15:06:17.41: 1 2: list_files_smb
2016/06/19 15:06:17.41: 9 2: NdpFindStart <*> (\*) cnt 0 65

Command line response (CMD.EXE) was: 

[C:\]dir k:

The volume label in drive K is NETDRIVE.
Directory of K:\

SYS0065: Network access is denied.

A subsequent: 

[C:\]dir k:\Documents

worked as expected, with: 

2016/06/19 15:13:08.45: 9 2: NdpRsrcQueryInfo in
2016/06/19 15:13:08.45: 9 2: NdpRsrcQueryInfo 0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/19 15:13:08.45: 9 2: NdpQueryPathInfo in [0x6738c0] <Documents>
2016/06/19 15:13:08.45: 9 2: dircache_find_path [Documents]
2016/06/19 15:13:08.45: 9 2: dcFindPath: [][Documents]
2016/06/19 15:13:08.45: 9 2: dircache: FindPath Documents not found
2016/06/19 15:13:08.45: 9 2: NdpQueryPathInfo pathparser for <\Documents> rc=0
2016/06/19 15:13:08.45: 9 2: NdpQueryPathInfo smbwrp_getattr for <\Documents>
2016/06/19 15:13:08.45: 4 2:  smbwrp_echo
2016/06/19 15:13:08.57: 1 2: Connecting to \\lewis:*********@workgroup:dp45sg\lewis. Master WORKGROUP:1
2016/06/19 15:13:08.58: 4 2: Server supports SMB3_11 protocol
2016/06/19 15:13:08.58: 4 2:  session setuping for <lewis>/<********> in <workgroup>
2016/06/19 15:13:08.61: 4 2: logon by lewis succeeded
2016/06/19 15:13:08.61: 4 2:  session setup ok. Sending tconx <lewis> <********>
2016/06/19 15:13:08.62: 4 2:  tconx ok
2016/06/19 15:13:08.62: 4 2:  smbwrp_getattr
2016/06/19 15:13:08.62: 4 2: getattr 0 16 <\Documents>
2016/06/19 15:13:08.64: 9 2: fname \Documents
2016/06/19 15:13:08.64: 9 2: size 0
2016/06/19 15:13:08.64: 9 2: mtime 1464728371 Tue May 31 16:59:31 2016
2016/06/19 15:13:08.64: 9 2: ftimeLastAccess 16:59:30
2016/06/19 15:13:08.64: 9 2: NdpQueryPathInfo <Documents> (\Documents) 0
2016/06/19 15:13:08.64: 9 2: NdpQueryPathInfo in [0x6738c0] <Documents>
2016/06/19 15:13:08.64: 9 2: dircache_find_path [Documents]
2016/06/19 15:13:08.64: 9 2: dcFindPath: [][Documents]
2016/06/19 15:13:08.64: 9 2: dircache: FindPath Documents not found
2016/06/19 15:13:08.64: 9 2: NdpQueryPathInfo pathparser for <\Documents> rc=0
2016/06/19 15:13:08.64: 9 2: NdpQueryPathInfo smbwrp_getattr for <\Documents>
2016/06/19 15:13:08.64: 4 2:  smbwrp_echo
2016/06/19 15:13:08.64: 4 2:  smbwrp_getattr
2016/06/19 15:13:08.65: 4 2: getattr 0 16 <\Documents>
2016/06/19 15:13:08.65: 9 2: fname \Documents
2016/06/19 15:13:08.65: 9 2: size 0
2016/06/19 15:13:08.65: 9 2: mtime 1464728371 Tue May 31 16:59:31 2016
2016/06/19 15:13:08.66: 9 2: ftimeLastAccess 16:59:30
2016/06/19 15:13:08.66: 9 2: NdpQueryPathInfo <Documents> (\Documents) 0
2016/06/19 15:13:08.66: 9 2: NdpQueryPathInfo in [0x6738c0] <Documents>
2016/06/19 15:13:08.66: 9 2: dircache_find_path [Documents]
2016/06/19 15:13:08.66: 9 2: dcFindPath: [][Documents]
2016/06/19 15:13:08.67: 9 2: dircache: FindPath Documents not found
2016/06/19 15:13:08.67: 9 2: NdpQueryPathInfo pathparser for <\Documents> rc=0
2016/06/19 15:13:08.67: 9 2: NdpQueryPathInfo smbwrp_getattr for <\Documents>
2016/06/19 15:13:08.67: 4 2:  smbwrp_echo
2016/06/19 15:13:08.67: 4 2:  smbwrp_getattr
2016/06/19 15:13:08.67: 4 2: getattr 0 16 <\Documents>
2016/06/19 15:13:08.68: 9 2: fname \Documents
2016/06/19 15:13:08.68: 9 2: size 0
2016/06/19 15:13:08.68: 9 2: mtime 1464728371 Tue May 31 16:59:31 2016
2016/06/19 15:13:08.68: 9 2: ftimeLastAccess 16:59:30
2016/06/19 15:13:08.68: 9 2: NdpQueryPathInfo <Documents> (\Documents) 0
2016/06/19 15:13:08.68: 9 2: NdpEASize in [0x6738c0] <\Documents>
2016/06/19 15:13:08.68: 4 2:  smbwrp_listea
2016/06/19 15:13:08.68: 4 2: EAList for <\Documents>
2016/06/19 15:13:08.69: 4 2: ea_get_file list failed - NT_STATUS_OK
2016/06/19 15:13:08.69: 9 2: NdpEASize <Documents> 0 282
2016/06/19 15:13:08.69: 9 2: NdpQueryPathInfo in [0x6738c0] <Documents\*>
2016/06/19 15:13:08.69: 9 2: NdpFindStart in [0x6738c0]
2016/06/19 15:13:08.69: 9 2: NdpFindStart: dir [\Documents\], dir_mask [*], mask [\Documents\*], szPath [Documents\*]
2016/06/19 15:13:08.69: 4 2:  smbwrp_filelist
2016/06/19 15:13:08.69: 1 2: Filelist <\Documents\*> on master <WORKGROUP> wgrp <workgroup> server <dp45sg> share <lewis> clidev <(null)>
2016/06/19 15:13:08.69: 1 2: list_files
2016/06/19 15:13:08.69: 4 2: SMB2 detected, calling list_files_smb2()
2016/06/19 15:13:08.69: 1 2: list_files_smb
2016/06/19 15:13:10.49: 4 2:  smbwrp_dir_add
2016/06/19 15:13:10.49: 8 2: adding <.> 289 0 261
2016/06/19 15:13:10.49: 9 2: fname \Documents\.
2016/06/19 15:13:10.49: 9 2: size 0
2016/06/19 15:13:10.49: 9 2: mtime 1464728371 Tue May 31 16:59:31 2016
2016/06/19 15:13:10.49: 9 2: ftimeLastAccess 16:59:30
2016/06/19 15:13:10.49: 4 2:  smbwrp_dir_add
2016/06/19 15:13:10.49: 8 2: adding <..> 289 0 261
2016/06/19 15:13:10.49: 9 2: fname \Documents\..
[etc.]

comment:8 Changed 8 years ago by Lewis Rosenthal

Are you able to share your smb.conf? and also a screenshot of the ndpsmb settings from Netdrive.

Sorry.

Surely: 

[global]
        workgroup = WORKGROUP
        loglevel = 10
        client max protocol = SMB3

and:

https://www.2rosenthals.com/wp-content/uploads/2016/06/captured001.png

https://www.2rosenthals.com/wp-content/uploads/2016/06/captured002.png

Last edited 8 years ago by Lewis Rosenthal (previous) (diff)

comment:9 Changed 8 years ago by Paul Smedley

Just testing a theory - can u try again with ​http://smedley.id.au/tmp/ndpsmb.zip

Theory is that netdrive thinks the connection is active, so doesn't attempt to create a connection, then the dir fails cos the connection isn't active.

I inserted :

debuglocal(9,"NdpRsrcQueryInfo? rc=%d, s = %s\n", rc,s);

#if 1

int rc2=checkMountResource(pRes); debuglocal(9,"NdpRsrcQueryInfo? rc2=%d\n", rc2);

#endif

Into NdpRsrcQueryInfo? - to hopefully check the connection status and tell us what's happening

comment:10 Changed 8 years ago by Lewis Rosenthal

Resolution: → fixed
Status: new → closed

Confirmed fixed in:

6-22-16 3:51 13,953,656 124 ndpsmb.dll

As a further test, I ran:

dp45sg:/home/lewis # service smb stop

I then attempted a dir against the drive letter: 

[c:\var\log]dir k:

 Volume in drive K is NETDRIVE
SYS0002: The system cannot find the file specified. "K:\*"
               0 bytes in 0 files and 0 dirs
     948,961,280 bytes (905MB) free

This failed, as expected (though note the correct SYS0002), and after waiting a few more seconds, I started the server again:

dp45sg:/home/lewis # service smb start

Without re-mapping or stopping/starting the control program, I once again ran a dir against the drive letter, which returned results (quickly): 

[c:\var\log]dir k:

 Volume in drive K is NETDRIVE
 Directory of  K:\*

 5-11-16  17:57         <DIR>        0  Apollo
 5-25-15  11:44         <DIR>        0  bash-shellshocker
[...]
 6-03-16  18:18          38,484      0  woocommerce-gateway-stripe.zip
      28,387,884 bytes (27MB) in 26 files and 24 dirs
      28,426,240 bytes (27MB) allocated
 147,397,607,424 bytes (137GB) free

Logs:

Initial attempt (server stopped): 

2016/06/22 23:46:55.60: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:46:55.63: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:46:55.63: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:46:55.63: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:46:55.63: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:46:55.63: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:46:55.63: 9 2: NdpRsrcQueryFSAllocate 0285fdd0
2016/06/22 23:46:55.63: 9 2: checkMountResource in tid#2
2016/06/22 23:46:55.64: 1 2: Connecting to \\lewis:*********@workgroup:dp45sg\lewis. Master WORKGROUP:1
2016/06/22 23:46:55.64: 4 2: Connection to dp45sg failed (Error NT_STATUS_CONNECTION_REFUSED)
2016/06/22 23:46:55.65: 9 2: NdpCreateConnection failed rc=3
2016/06/22 23:46:55.65: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:46:55.65: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:46:55.65: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:46:55.65: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:46:55.66: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:46:55.66: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:46:55.66: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:46:55.66: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:46:55.66: 9 2: NdpQueryPathInfo in [0x672fa0] <*>
2016/06/22 23:46:55.66: 9 2: NdpFindStart in [0x672fa0]
2016/06/22 23:46:55.66: 9 2: NdpFindStart: dir [\], dir_mask [*], mask [\*], szPath [*]
2016/06/22 23:46:55.66: 4 2:  smbwrp_echo
2016/06/22 23:46:55.66: 4 2: NdpFindStart, smbwrp_echo rc = -1, reconnecting.....
2016/06/22 23:46:55.66: 1 2: Connecting to \\lewis:*********@workgroup:dp45sg\lewis. Master WORKGROUP:1
2016/06/22 23:46:55.67: 4 2: Connection to dp45sg failed (Error NT_STATUS_CONNECTION_REFUSED)

Server started (very next log entry): 

2016/06/22 23:47:07.41: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:47:07.41: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:47:07.41: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:47:07.41: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:47:07.42: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:47:07.42: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:47:07.42: 9 2: NdpRsrcQueryFSAllocate 0285fdd0
2016/06/22 23:47:07.42: 9 2: checkMountResource in tid#2
2016/06/22 23:47:07.42: 1 2: Connecting to \\lewis:*********@workgroup:dp45sg\lewis. Master WORKGROUP:1
2016/06/22 23:47:07.43: 4 2: Server supports SMB3_11 protocol
2016/06/22 23:47:07.43: 4 2:  session setuping for <lewis>/<********> in <workgroup>
2016/06/22 23:47:07.54: 4 2: logon by lewis succeeded
2016/06/22 23:47:07.54: 4 2:  session setup ok. Sending tconx <lewis> <********>
2016/06/22 23:47:07.56: 4 2:  tconx ok
2016/06/22 23:47:07.56: 4 2:  smbwrp_dskattr
2016/06/22 23:47:07.57: 4 2: 
2016/06/22 23:47:07.57: 4 2:  smbwrp_disconnect
2016/06/22 23:47:07.57: 9 2: NdpRsrcQueryFSAllocate rc=0/rc1=0 (cUnit = 262016000/cUnitAvail = 143943124/cbSector = 1024)
2016/06/22 23:47:07.57: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:47:07.57: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:47:07.57: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:47:07.58: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:47:07.58: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:47:07.58: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:47:07.58: 9 2: NdpRsrcQueryInfo in
2016/06/22 23:47:07.58: 9 2: NdpRsrcQueryInfo rc=0, s = SMBFS64 \\workgroup:dp45sg\lewis@lewis
2016/06/22 23:47:07.58: 9 2: NdpQueryPathInfo in [0x672fa0] <*>
2016/06/22 23:47:07.58: 9 2: NdpFindStart in [0x672fa0]
2016/06/22 23:47:07.59: 9 2: NdpFindStart: dir [\], dir_mask [*], mask [\*], szPath [*]
2016/06/22 23:47:07.59: 4 2:  smbwrp_echo
2016/06/22 23:47:07.59: 4 2: NdpFindStart, smbwrp_echo rc = -1, reconnecting.....
2016/06/22 23:47:07.59: 1 2: Connecting to \\lewis:*********@workgroup:dp45sg\lewis. Master WORKGROUP:1
2016/06/22 23:47:07.59: 4 2: Server supports SMB3_11 protocol
2016/06/22 23:47:07.59: 4 2:  session setuping for <lewis>/<********> in <workgroup>
2016/06/22 23:47:07.62: 4 2: logon by lewis succeeded
2016/06/22 23:47:07.63: 4 2:  session setup ok. Sending tconx <lewis> <********>
2016/06/22 23:47:07.64: 4 2:  tconx ok
2016/06/22 23:47:07.64: 4 2:  smbwrp_filelist
2016/06/22 23:47:07.64: 1 2: Filelist <\*> on master <WORKGROUP> wgrp <workgroup> server <dp45sg> share <lewis> clidev <(null)>
2016/06/22 23:47:07.64: 1 2: list_files
2016/06/22 23:47:07.64: 4 2: SMB2 detected, calling list_files_smb2()
2016/06/22 23:47:07.64: 1 2: list_files_smb
2016/06/22 23:47:07.72: 4 2:  smbwrp_dir_add
2016/06/22 23:47:07.72: 8 2: adding <.> 289 764445696 261
2016/06/22 23:47:07.72: 9 2: fname \.
2016/06/22 23:47:07.72: 9 2: size 0
2016/06/22 23:47:07.72: 9 2: mtime 1466635978 Wed Jun 22 18:52:58 2016
2016/06/22 23:47:07.72: 9 2: ftimeLastAccess 18:52:58
[...]
Note: See TracTickets for help on using tickets.