[jcifs] SmbComWriteAndX writes corrupt offset to wire

Richard Heap richardheap at beeb.net
Wed Apr 14 22:32:28 GMT 2004


J2SE 1.5 didn't make any difference, but what did was compiling the 
library myself (using 1.4.2 under windows) - can now run the test 
harness with -server on linux without problem. Also confirmed that the 
real application seems to work ok (so far) without -server.

So looks like I have a couple of choices... don't use -server on linux - 
or - compile the library myself

Thanks again
Richard

Richard Heap wrote:

> This is one of those things that you hope you never have to write, but 
> I'm feeling "compiler bug" (well JVM bug to be precise).
>
> Firstly 0.9.0p3 doesn't seem to make much difference
>
> Finally, I have a test harness that reproduces the problem (but it's 
> real elusive...)
>
> Ok, so back to the facts...
> Here's the first occurance of corruption in the logfile of a test run.
> 2004-04-14 12:53:54,441 ERROR [STDERR] queue.name.eqb: 
> writeParameterWordsWireFormat: offset=4000
> 2004-04-14 12:53:54,441 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 5F 0D  |.........0.p.h_.|
> 00020: 0E FF 00 00 00 0E C0 00 0F 00 00 00 00 00 00 00  |.ÿ....À.........|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00              |..... .?....    |
> 2004-04-14 12:53:54,441 ERROR [STDERR] queue.name.eqb: 
> writeAndXWireFormat1
> 2004-04-14 12:53:54,441 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 5F 0D  |.........0.p.h_.|
> 00020: 0E FF 00 00 00 0E C0 00 0F 00 00 00 00 00 00 00  |.ÿ....À.........|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
> 2004-04-14 12:53:54,441 ERROR [STDERR] queue.name.eqb: writeWireFormat
> 2004-04-14 12:53:54,441 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 5F 0D  |.........0.p.h_.|
> 00020: 0E FF 00 00 00 0E C0 00 0F 00 00 00 00 00 00 00  |.ÿ....À.........|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
> 2004-04-14 12:53:54,441 ERROR [STDERR] queue.name.eqb: 
> SmbComWriteAndX[command=SMB_COM_WRITE_ANDX,received=false,errorCode=0x00000000,flags=0x0018,flags2=0x8003,tid=12290,pid=28683,uid=26625,mid=3423,wordCount=14,byteCount=4000,andxCommand=0xFF,andxOffset=0,fid=49166,offset=4000,writeMode=0,remaining=0,dataLength=4000,dataOffset=63]
>
> Note how the offset is corrupt even directly after 
> writeParameterWordsWireFormat
>
>
> The interesting thing is that I have found the 'trigger' that causes 
> it to 'break'. The previous file copied is longer than normal, and, in 
> fact, the offset breaks half way through the file, as follows....
> 2004-04-14 12:53:53,803 ERROR [STDERR] queue.name.eqb: 
> writeParameterWordsWireFormat: offset=92000
> 2004-04-14 12:53:53,804 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0B 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 60 67 01 00 00 00 00 00 00  |.ÿ....À`g.......|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00              |..... .?....    |
> 2004-04-14 12:53:53,804 ERROR [STDERR] queue.name.eqb: 
> writeAndXWireFormat1
> 2004-04-14 12:53:53,804 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0B 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 60 67 01 00 00 00 00 00 00  |.ÿ....À`g.......|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
> 2004-04-14 12:53:53,804 ERROR [STDERR] queue.name.eqb: writeWireFormat
> 2004-04-14 12:53:53,804 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0B 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 60 67 01 00 00 00 00 00 00  |.ÿ....À`g.......|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
> 2004-04-14 12:53:53,804 ERROR [STDERR] queue.name.eqb: 
> SmbComWriteAndX[command=SMB_COM_WRITE_ANDX,received=false,errorCode=0x00000000,flags=0x0018,flags2=0x8003,tid=12290,pid=28683,uid=26625,mid=3339,wordCount=14,byteCount=4000,andxCommand=0xFF,andxOffset=0,fid=49165,offset=92000,writeMode=0,remaining=0,dataLength=4000,dataOffset=63]
> 2004-04-14 12:53:53,804 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0B 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 60 67 01 00 00 00 00 00 00  |.ÿ....À`g.......|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
> 2004-04-14 12:53:53,823 ERROR [STDERR] queue.name.eqb: 
> writeParameterWordsWireFormat: offset=96000
> 2004-04-14 12:53:53,823 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0C 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 00 77 01 00 00 00 00 00 00  |.ÿ....À.w.......|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00              |..... .?....    |
> 2004-04-14 12:53:53,823 ERROR [STDERR] queue.name.eqb: 
> writeAndXWireFormat1
> 2004-04-14 12:53:53,823 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0C 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 00 77 01 00 00 00 00 00 00  |.ÿ....À.w.......|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
> 2004-04-14 12:53:53,823 ERROR [STDERR] queue.name.eqb: writeWireFormat
> 2004-04-14 12:53:53,824 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0C 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 00 77 01 00 00 00 00 00 00  |.ÿ....À.w.......|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
> 2004-04-14 12:53:53,824 ERROR [STDERR] queue.name.eqb: 
> SmbComWriteAndX[command=SMB_COM_WRITE_ANDX,received=false,errorCode=0x00000000,flags=0x0018,flags2=0x8003,tid=12290,pid=28683,uid=26625,mid=3340,wordCount=14,byteCount=4000,andxCommand=0xFF,andxOffset=0,fid=49165,offset=96000,writeMode=0,remaining=0,dataLength=4000,dataOffset=63]
> 2004-04-14 12:53:53,824 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0C 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 00 77 01 00 00 00 00 00 00  |.ÿ....À.w.......|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
> 2004-04-14 12:53:53,845 ERROR [STDERR] queue.name.eqb: 
> writeParameterWordsWireFormat: offset=100000
> 2004-04-14 12:53:54,244 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0D 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 00 86 01 00 00 00 00 00 00  |.ÿ....À.........|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00              |..... .?....    |
> 2004-04-14 12:53:54,245 ERROR [STDERR] queue.name.eqb: 
> writeAndXWireFormat1
> 2004-04-14 12:53:54,245 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0D 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 00 86 01 00 00 00 00 00 00  |.ÿ....À.........|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
> 2004-04-14 12:53:54,245 ERROR [STDERR] queue.name.eqb: writeWireFormat
> 2004-04-14 12:53:54,245 ERROR [STDERR] 00000: FF 53 4D 42 2F 00 00 00 
> 00 18 03 80 00 00 00 00  |ÿSMB/...........|
> 00010: 00 00 00 00 00 00 00 00 02 30 0B 70 01 68 0D 0D  |.........0.p.h..|
> 00020: 0E FF 00 00 00 0D C0 00 86 01 00 00 00 00 00 00  |.ÿ....À.........|
> 00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
> 2004-04-14 12:53:54,245 ERROR [STDERR] queue.name.eqb: 
> SmbComWriteAndX[command=SMB_COM_WRITE_ANDX,received=false,errorCode=0x00000000,flags=0x0018,flags2=0x8003,tid=12290,pid=28683,uid=26625,mid=3341,wordCount=14,byteCount=4000,andxCommand=0xFF,andxOffset=0,fid=49165,offset=100000,writeMode=0,remaining=0,dataLength=4000,dataOffset=63]
>
> Notice how 92000 is encoded ok, 100000 is encoded incorrectly. Of 
> course, it's impossible to tell if 96000 is encoded correctly, as it 
> happens to have a 0 byte naturally.
>
> This longer than normal file seems to be the trigger that permanently 
> breaks the encoding.
>
> So back to the test harness - now modified to throw in a few files > 
> 100000 bytes. It won't break on Windows at all, and it won't break 
> with the client JVM on linux. It only breaks with the -server option. 
> I've tried 1.4.2_01 and 1.4.2_04 - same result. I'm downloading 1.5 at 
> the moment to see if that changes anything. (And just about to test 
> the real application without -server). Will let you know.
>
> Many Thanks
> Richard
>
> Michael B Allen wrote:
>
>>Hi Richard,
>>
>>  
>>
>>>After the server has been running for a few 10s of minutes we notice
>>>that the files written to the share are corrupt. It seems that files are
>>>initially copied ok, and then something 'breaks'. An ethereal trace
>>>shows that the offset of the server-bound WriteAndX messages is corrupt.
>>>    
>>>
>>
>>So once it happends it never corrects itself? That's strange because
>>you would think that provided the SmbFileOutputStream is closed and is
>>used exclusively by a single thread that any state associated with that
>>object would be reset when the next object was created. Has to be related
>>to some static variable/object.
>>
>>  
>>
>>>The following code...
>>>byte[] buffer = new byte[4000];
>>>while ((int length = in.read(buffer)) > 0) {
>>>  out.write(buffer, 0, length);
>>>}
>>>produces WriteAndX messages with the following offsets...
>>>0, 3840, 7936, etc (instead of 0, 4000, 8000)
>>>in hex these values are: 0x0F00 and 0x1F00 (should be 0x0FA0 and 0x1F40
>>>- i.e. it appears that the bottom byte is being squashed to zero)
>>>
>>>This appears to be confirmed by the following ALL level log:
>>>Apr 9 12:25:53.107 - smb sent
>>>SmbComWriteAndX[command=SMB_COM_WRITE_ANDX,received=false,
>>>errorCode=0x00000000,flags=0x0018,flags2=0x8003,tid=28677,pid=22517,
>>>uid=57345,mid=2957,wordCount=14,byteCount=4000,andxCommand=0xFF,
>>>andxOffset=0,fid=9,offset=4000,writeMode=0,remaining=0,dataLength=4000,
>>>dataOffset=63]
>>>Apr 9 12:25:53.107 - smb sent
>>>00000: FF 53 4D 42 2F 00 00 00 00 18 03 80 00 00 00 00  |ÿSMB/...........|
>>>00010: 00 00 00 00 00 00 00 00 05 70 F5 57 01 E0 8D 0B  |.........põW.à..|
>>>00020: 0E FF 00 00 00 09 00 00 0F 00 00 00 00 00 00 00  |.ÿ..............|
>>>00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F 58  |..... .?..... .X|
>>>    
>>>
>>
>>That's very interesting. It looks like an encoding error. Unfortunately
>>I have spend several hours trying to track this down without any luck. I
>>do not see anything obviously wrong with the encoding routines and I have
>>created a test program that writes 259760 byte file to a server every
>>800ms and then reads it back every 3 seconds. After letting it run for a
>>good hour with -Xmx500k for a while now I'm not seeing any problems.
>>
>>  
>>
>>>What is interesting is that the toString() of the SmbComWriteAndX still
>>>shows 4000, yet the hex dump shows 00 0F 00 00 (decimal 3840)
>>>    
>>>
>>
>>Yes it is. Good catch. It might be critically important. Can you try this
>>jar?
>>
>>  http://home.comcast.net/~miallen1/jcifs/jcifs-0.8.2x.jar
>>
>>Maybe we can zoom in on where the encoding error. Don't run with
>>log=ALL. It has very selective debugging statements hardcoded in
>>it. Basically the encoding routines for SmbComWriteAndX are called like:
>>
>>writeWireFormat
>>	writeHeaderWriteFormat
>>	writeAndXWireFormat
>>		writeParameterWordsWireFormat
>>		writeBytesWireFormat
>>
>>The offset is encoded in writeParameterWordsWireFormat but I suspect
>>it could be that it's encoded properly there only to be clobbered
>>by something or someone else. So I have placed hexdump calls at the
>>end of writeWireFormat, at the end of writeAndXWireFormat, and end
>>of writeParameterWordsWireFormat. The System.err output should looks
>>something like this:
>>
>>main: writeParameterWordsWireFormat: offset=188000
>>00000: FF 53 4D 42 2F 00 00 00 00 18 03 80 00 00 00 00  |ÿSMB/...........|
>>00010: 00 00 00 00 00 00 00 00 00 08 6B 12 00 08 DF 16  |..........k...ß.|
>>00020: 0E FF 00 00 00 07 30 60 DE 02 00 00 00 00 00 00  |.ÿ....0`Þ.......|
>>00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00              |..... .?....    |
>>
>>main: writeAndXWireFormat1
>>00000: FF 53 4D 42 2F 00 00 00 00 18 03 80 00 00 00 00  |ÿSMB/...........|
>>00010: 00 00 00 00 00 00 00 00 00 08 6B 12 00 08 DF 16  |..........k...ß.|
>>00020: 0E FF 00 00 00 07 30 60 DE 02 00 00 00 00 00 00  |.ÿ....0`Þ.......|
>>00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
>>
>>main: writeWireFormat
>>00000: FF 53 4D 42 2F 00 00 00 00 18 03 80 00 00 00 00  |ÿSMB/...........|
>>00010: 00 00 00 00 00 00 00 00 00 08 6B 12 00 08 DF 16  |..........k...ß.|
>>00020: 0E FF 00 00 00 07 30 60 DE 02 00 00 00 00 00 00  |.ÿ....0`Þ.......|
>>00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
>>
>>main:
>>SmbComWriteAndX[command=SMB_COM_WRITE_ANDX,received=false,errorCode=0x00000000,flags=0x0018,flags2=0x8003,tid=2048,pid=4715,uid=2048,mid=5855,wordCount=14,byteCount=4000,andxCommand=0xFF,andxOffset=0,fid=12295,offset=188000,writeMode=0,remaining=0,dataLength=4000,dataOffset=63]
>>00000: FF 53 4D 42 2F 00 00 00 00 18 03 80 00 00 00 00  |ÿSMB/...........|
>>00010: 00 00 00 00 00 00 00 00 00 08 6B 12 00 08 DF 16  |..........k...ß.|
>>00020: 0E FF 00 00 00 07 30 60 DE 02 00 00 00 00 00 00  |.ÿ....0`Þ.......|
>>00030: 00 00 00 00 00 A0 0F 3F 00 00 00 00 00 A0 0F     |..... .?..... . |
>>
>>So each sub-encoding method is called first and then the full SMB toString
>>and it's hexdump is printed immediately after the packet is written to the
>>wire. So this last dump is what should appear on the wire. Also notice the
>>thread name preceeds every debugging message (in the above case it is
>>'main').
>>
>>The data shown is just the header so the third line will always look like
>>this (not to be confused with other packets that will likey have a
>>different
>>WordCount other than 0E):
>>
>>00020: 0E FF 00 00 00 07 30 60 DE 02 00 00 00 00 00 00  |.ÿ....0`Þ.......|
>>       1  2  3  4     5     6           7
>>
>>The fields are:
>>
>>1 WordCount
>>2 AndXCommand
>>3 AndXReserved
>>4 AndXOffset
>>5 Fid
>>6 Offset <---- HERE'S THE OFFSET FIELD
>>7 Reserved
>>
>>So you should be able to just eyeball that 1st byte of the Offset (0x60
>>depicted above) and zero in on where it get's clobbered to 0x00. Can
>>you do that?
>>
>>Also you might try this jar:
>>
>>   http://home.comcast.net/~miallen1/jcifs/jcifs-0.9.0p3.jar
>>
>>It has some very significant changes regarding how the NbtSocket layer
>>works and how MIDs (multiplex ids) are allocated. It's basically a
>>"cleanup release" so it's very much a work in progress but it's reported
>>to work well so far. Probably won't make a difference but it's worth a
>>shot.
>>
>>  
>>
>>>There seems so little time/space for this to go wrong!
>>>Could the signing be going wrong - don't think so - we don't think we
>>>are using this and, anyway it would do an arraycopy of 8 bytes
>>>    
>>>
>>
>>Doubt it's signing.
>>
>>  
>>
>>>writeWireFormat just calls writeHeader and writeAndXWireFormat which
>>>seem simple enough...
>>>    
>>>
>>
>>Right. If toString says offset is right (4000) but the hexdump printed
>>after the packet is written to the wire is wrong than let's see if we can
>>zoom in on what in between is causing that byte to get clobbered.
>>
>>  
>>
>>>there does not seem to be batching going on...
>>>    
>>>
>>
>>I've never seen anything batch with an SmbComWriteAndX. You can set
>>jcifs.smb.client.useBatching = false.
>>
>>This is kind of a serious bug so I hope we can figure it out. I just
>>wish I could reproduce it. It's going to be tough without a minimalistic
>>program to reproduce the issue.
>>
>>Mike
>>
>>
>>  
>>
-------------- next part --------------
HTML attachment scrubbed and removed


More information about the jcifs mailing list