Bug 10113 - smbclient: Didn´t get entire file size
smbclient: Didn´t get entire file size
Status: ASSIGNED
Product: Samba 4.0
Classification: Unclassified
Component: libsmbclient
4.0.16
All All
: P5 major
: ---
Assigned To: Samba QA Contact
Samba QA Contact
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2013-08-26 06:12 UTC by Alternativend
Modified: 2014-04-18 20:37 UTC (History)
4 users (show)

See Also:


Attachments
patch: stop cifs from using virtual circuits (4.55 KB, patch)
2013-09-14 14:02 UTC, Jeff Layton
no flags Details
patch: stop cifs from using virtual circuits (revised) (5.16 KB, patch)
2013-09-14 14:05 UTC, Jeff Layton
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Alternativend 2013-08-26 06:12:36 UTC
Hello,
i have some quite big problems with smbclient. Im backing up a lot of Windows shares with it (http://www.amanda.org) and Im getting this error quite often on shares with a lot of files in it.

 sendbackup: info BACKUP=APPLICATION
  sendbackup: info APPLICATION=amsamba
  sendbackup: info RECOVER_CMD=/bin/gzip -dc |/usr/lib/amanda/application/amsamba restore [./file-to-restore]+
  sendbackup: info COMPRESS_SUFFIX=.gz
  sendbackup: info end
  ? smbclient: Error reading file \Rert\Fotos\0002.JPG : NT_STATUS_OK
  ? smbclient: Didn't get entire file. size=763113, nread=327600
  ? smbclient: NT_STATUS_OK opening remote file \ert\Fotos\Haus\0003.JPG (\Reichert\Internes\Fotos\Haus\)
  ? smbclient: NT_STATUS_CONNECTION_INVALID listing \ert\Fotos\Haus\*
  ? smbclient: NT_STATUS_CONNECTION_INVALID listing \ert\Fotos\PersNT_STATUS_OK opening remote file \ert\Fotos\Thumbs.db (\ert\Fotos\)
  ? smbclient: NT_STATUS_CONNECTION_INVALID listing \ert\Fotos\*
  ? smbclient: NT_STATUS_CONNECTION_INVALID listing \ert\Management\*

The server is a Debian Wheezy with smbclient 3.6.17 and manually patched the Timeout listing thing (https://bugzilla.samba.org/show_bug.cgi?id=9904).

Please tell me how I can help to solve this problem. I need a stable backup solution.

Thanks!
Comment 1 Alternativend 2013-08-27 08:18:30 UTC
Here is the end of the logfile created via:

smbclient  -d 10 "\\\\VMX01\\Daten" -U backup -E -W DOM-Tc  Ziel.tar


I hope that you can do something with it.


[0000] CA A2 6B AA 78 A2 DB 45                            ..k.x..E 
smb_signing_md5: sequence number 536047
smb_signing_check_pdu: seq 536047: got good SMB signature of
[0000] 22 9C 47 EC EE 81 51 7C                            ".G...Q| 
cli_pull_read_done: Pushing 65520 bytes, 0 already pushed
nread=65651040
smb_signing_md5: sequence number 536048
smb_signing_sign_pdu: sent SMB signature of
[0000] 44 64 59 4B 82 B2 33 ED                            DdYK..3. 
smb_signing_md5: sequence number 536049
smb_signing_check_pdu: seq 536049: got good SMB signature of
[0000] 11 C9 55 7F D5 7A FA 1B                            ..U..z.. 
cli_pull_read_done: Pushing 65520 bytes, 0 already pushed
nread=65716560
smb_signing_md5: sequence number 536050
smb_signing_sign_pdu: sent SMB signature of
[0000] B1 1C CB 18 7F A8 B6 88                            ........ 
Error reading file \Lernpartnerschaften\2009-11\Flyer - Fotos - Logos\P1020271.MOV : NT_STATUS_OK
Didn't get entire file. size=85347546, nread=65716560
Padding with 19630986 zeros
    85347546 ( 9805,6 kb/s) \Lernpartnerschaften\2009-11\Flyer - Fotos - Logos\P1020271.MOV
(9805,55 kb/s) (average -1179,97 kb/s)
dos_clean_name [\Lernpartnerschaften\2009-11\Flyer - Fotos - Logos\P1020272.JPG]
unix_clean_name [\Lernpartnerschaften\2009-11\Flyer - Fotos - Logos\P1020272.JPG]
NT_STATUS_OK opening remote file \Lernpartnerschaften\2009-11\Flyer - Fotos - Logos\P1020272.JPG (\Lernpartnerschaften\Flyer - Fotos - Logos\England\)
lang_tdb_init: /usr/share/samba/de_DE.UTF-8.msg: Datei oder Verzeichnis nicht gefunden
NT_STATUS_CONNECTION_INVALID listing \Lernpartnerschaften\Flyer - Fotos - Logos\England\*
strlen(cur_dir)=128, strlen(finfo->name)=37
name=Fotos He 3. Meeting -Madrid 23-270610,cur_dir=\Lernpartnerschaften\Flyer - Fotos - Logos\Fotos von Meetings\
Writing a dir, Name = \Lernpartnerschaften\\Fotos von Meetings\
WriteTarHdr, Type = 5, Size= 0, Name = \Lernpartnerschaften\Meeting -Madrid 23-270610\
WriteTarHdr, Type = L, Size= 168, Name = /./@LongLink
File name in tar file: ./Lernpartnerschaften/Madrid 23-270610/, size=167, 
                directory \Lernpartnerschaften\Madrid 23-270610\
Doing list with mtar_mask: \Lernpartnerschaften\Madrid 23-270610\*
num_setup=1, max_setup=0, param_total=348, this_param=348, max_param=10, data_total=0, this_data=0, max_data=16644, param_offset=68, param_pad=0, param_disp=0, data_offset=416, data_pad=0, data_disp=0
NT_STATUS_CONNECTION_INVALID listing \Lernpartnerschaften\Fotos von Meetings\Madrid 23-270610\*
strlen(cur_dir)=128, strlen(finfo->name)=20
name=Fotos von Juan Lucio,cur_dir=Lernpartnerschaften\Legends 2009-11\Fotos von Meetings\
Writing a dir, Name = \DLernpartnerschaften\Fotos von Meetings\
WriteTarHdr, Type = 5, Size= 0, Name = \Lernpartnerschaften\Legends 2009-11\
WriteTarHdr, Type = L, Size= 151, Name = /./@LongLink
Comment 2 Jeremy Allison 2013-08-29 00:07:33 UTC
All this log is showing is that smbclient experienced an error reading from the server. Can you get a wireshark trace covering the exact read request that causes the error to occur ?

Jeremy.
Comment 3 Alternativend 2013-08-29 06:04:08 UTC
I have made a dump with:

tshark -p -w FILENAME port 445 or port 139

But the file is about 4,4GB big. How can i provide the important lines to secretly to you?
Comment 4 Alternativend 2013-09-09 11:09:54 UTC
The problem still exists in Samba 4.0.9.

Please guys i do really need your help with this.
Comment 5 Volker Lendecke 2013-09-09 11:57:49 UTC
(In reply to comment #4)
> The problem still exists in Samba 4.0.9.
> 
> Please guys i do really need your help with this.

encrypt it with gpg (which will also zip it). My key for example is 1045aa4f. Upload it to some webserver and give me the url.
Comment 6 Jeremy Allison 2013-09-10 22:34:42 UTC
Ok, I've analysed the dumps you sent (finally, sorry).

You're getting hit by the "reset on zero VC" code
in Windows (I'm assuming this is against a Windows
server).

In the second dump you sent:

split_04541_20130829080001.cap

look at packet 165. This is from a client on TCP port
40391 -> port 445.

Now look at packet 193 - coming FROM THE SAME CLIENT.
This has TCP source port 40444 -> port 445.

So you have a second connection being fired off from
the same client at the same time you're doing the
backup. Windows doesn't like that.

As soon as this second connection sends the sessionsetupX
request (packet 230) with a VC number of zero Windows
sends a RST packet and drops the first connection.

See here:

http://msdn.microsoft.com/en-us/library/ee441661.aspx

for details. Noteably:

"A VcNumber of zero (0) has special significance. It is possible
for a connectionless transport to not provide any indication of
failure when a client fails or is reset. A virtual circuit with
a VcNumber of zero (0), regardless of the SessionKey value, is
defined to indicate to the server that the client has abandoned
all previous virtual circuits and that the server MUST close
those VCs as well, ensuring proper cleanup of resources."

Whatever process you have on the box that is doing that
second connection - don't do that whilst the backup
is active.

Jeremy.
Comment 7 Jeremy Allison 2013-09-10 22:35:19 UTC
This is not a bug in smbclient.
Comment 8 Alternativend 2013-09-11 05:19:53 UTC
(In reply to comment #7)
> This is not a bug in smbclient.

Hi Jeremy,
Volker helped me out with this bug and he came to the same conclusion.
The problem seems to be a mounted CIFS share which is always mounted on this sever. After unmounting this second share tonight the backup was successful.

So for everyone who reads this, check if you have any open CIFS mount´s on that machine somewhere.

Thanks so much for your help, i think this could help a lot of people.
Comment 9 Jeff Layton 2013-09-14 13:59:12 UTC
Reopening this bug since it is a valid problem, just not with smbclient...
Comment 10 Jeff Layton 2013-09-14 14:02:57 UTC
Created attachment 9213 [details]
patch: stop cifs from using virtual circuits

This kernel patch *might* help this situation. I don't see any reason to continue using vcnum of 0, so let's just hardcode it to 1 as Implementing CIFS suggests.

Completely untested, but it does build. Would you be able to test it out and see if it helps?
Comment 11 Jeff Layton 2013-09-14 14:05:44 UTC
Created attachment 9214 [details]
patch: stop cifs from using virtual circuits (revised)

Minor revision -- also rip out now unused static function.
Comment 12 Alternativend 2013-09-14 14:49:01 UTC
i will try to build it again with this patch and the second open CIFS share.
Will give you a reply.
Comment 13 Alternativend 2013-09-19 05:39:21 UTC
First run with the patch integrated looked good. 
I have got an error when trying to upgrade samba saying that winbind service is already provided. Installing it without sernet-samba-ad and sernet-samba-winbind works well.
Comment 14 Jeff Layton 2013-09-19 12:00:33 UTC
(In reply to comment #13)
> First run with the patch integrated looked good. 

Good, thanks for testing it.

> I have got an error when trying to upgrade samba saying that winbind service is
> already provided. Installing it without sernet-samba-ad and
> sernet-samba-winbind works well.

This sounds unrelated to the problem in this bug. I'll chalk it up to some sort of package dependency issue.
Comment 15 Alternativend 2013-09-27 06:17:46 UTC
Ok so after a few runs everything seems fine.

Thanks for the Patch!
Comment 16 Alternativend 2014-04-08 08:05:07 UTC
Hi,
sorry for reopening this, but the problem is back again like it seems. 
I have just updated to Version 4.0.16-SerNet-Debian-8.wheezy and i get the same error again. 

I have added the patch and applied it with:

quilt pop -a ; quilt push -a; quilt add 0001-cifs-stop-trying-to-use-virtual-circuits.patch

Then i have rebuilt the package with debuild and made a dry run with smbclient.

What could be wrong there again?
Comment 17 Jeff Layton 2014-04-08 10:15:14 UTC
Moving back to userland samba bug. Assuming that the kernel is patched properly the vcnum == 0 problem should no longer be an issue.
Comment 18 Alternativend 2014-04-08 11:20:18 UTC
(In reply to comment #17)
> Moving back to userland samba bug. Assuming that the kernel is patched properly
> the vcnum == 0 problem should no longer be an issue.

Which means in samba 4.0.16 it´s fixed by default? Or do i have to downgrade something?
Comment 19 Alternativend 2014-04-08 15:09:04 UTC
I have tried it now without applying the patch, but after a few GB´s he fails with the same error. Im doing a second run now and im capturing the packages.

Maybe you want to have a look into it?