Ubuntu 11.10 (kernel 3.0.4) I've noticed an anomaly when running a program that creates a small number of output files on a CIFS network share. One of the output files appears to be corrupted: the first line contains a long string of ^@ (ASCII NULL), followed by the expected data (tab-delimited numeric values). The other lines appear to be normal, but there aren't as many as expected (6 instead of 1,000). Sample of the output: ^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@ 0.0171336 0.0212791 0.129199 0.10037 0.0326974 0.0290939 0.0201371 0.0603848 0.0345106 0.00430885 0.108036 0.0365998 0.0429855 0.0224048 0.0496568 0.0368914 0.0141055 0.00231577 0.00796571 0.0263493 0.0113408 0.0147399 0.00599318 0.0197169 0.00563507 0.0136991 0.0534332 0.038746 0.000604263 0.050864 0.0532265 0.0159351 0.037813 0.0484131 0.0131025 0.098634 0.0256822 0.012495 0.0984072 0.00511325 0.16901 0.0453786 0.13176 0.0152235 0.0217565 0.0238086 0.0039197 0.0338673 0.00393313 0.0829335 0.0136131 0.10796 0.10842 0.0515564 0.118125 0.00660697 0.00292382 0.0905625 0.0461118 0.000703248 0.0315086 0.0288653 0.0880219 0.0312076 0.0140861 0.00304921 0.0580084 0.0442074 0.0772593 0.000842658 0.0174914 0.0183774 0.102918 0.000778389 0.0138765 0.0245259 0.0248157 0.0639402 0.0517471 0.000249088 0.0851772 0.00481187 0.0284765 0.00991917 0.0298476 0.0118467 0.0152653 0.0114918 0.0259155 0.0603263 0.004833 (each line extends beyond, but this is the file as viewed in vim with wrapping disabled) Interestingly, if I run the program with the top 100 attributes, resulting in an output file with 100 lines, I see no issues. But if I run with the top 1,000 (output file with 1,000 lines), the odd ^@ characters appear. If I run the same program and save the output files to the local drive, the aforementioned file is "valid": no ^@ characters and the correct number of lines. This leads me to believe that it has something to do with the CIFS-mounted network share. The share is mounted via CIFS from our NAS, a Sun Storage 7110. Note: we've recently upgraded our servers to 11.10, and were previously running 10.04. This issue wasn't present in 10.04. One of our desktops is running 11.04, and this issue doesn't manifest itself there either (same program, input data, writing to the network share). It only occurs on servers/desktops running 11.10. I rebooted one of our upgraded servers running 11.10 into a previous kernel, 2.6.38-11-server. I tested my program, viewed the file, and it appeared normal (again, same input, same program, writing data to the NAS CIFS share). So this is definitely a bug in the 3.0 kernel that ships with 11.10, since running 2.6.38-11 on the _same_ 11.10 system works and 3.0 doesn't, with no other library or system changes. This was originally reported on Launchpad, Ubuntu's bug tracker https://bugs.launchpad.net/ubuntu/+source/linux/+bug/879228 I've tested both the stock Ubuntu 11.10 kernel, 3.0.4, as well as an upstream kernel I compiled and installed, Linux 3.1. With both kernels I'm able to reproduce this corruption issue consistently.
Some questions... Do you have a reproducer for this issue that you can share? Are you able to reproduce this against other servers too? What mount options are you using? The line from the mount in /proc/mounts might be helpful... Exactly how long is the corrupted region? Is it always in the same place in the file? Would it be possible to get a network trace of the reproducer being run, along with a description of the corruption region of the file (offset and length)? Instructions for collecting a capture are here: http://wiki.samba.org/index.php/LinuxCIFS_troubleshooting#Wire_Captures
Even if you are not able to share the application that is being used to reproduce the problem, it would help if you could narrow down a test case or a simple program (small part of what the application does..).
Created attachment 7065 [details] Debug file created by CIFS while performing operation that causes file corruption
To answer the questions, the corruption can be consistently reproduced with the program I'm using, and the corruption is in the same place in the file (the first line) each time. It appears to be a bug in the 3.0 kernel, as I've only witnessed it on Ubuntu 11.10 machines running the stock kernel (based on upstream 3.0.4). When I boot into a previous kernel version (2.6.38), the corruption is no longer present. Here is the relevant mount point in /proc/mounts //192.168.10.10/share_share /mnt/nas cifs rw,nosuid,nodev,noexec,relatime,sec=ntlm,unc=\\192.168.10.10\share_share,username=nasmount,uid=0,noforceuid,gid=0,noforcegid,addr=192.168.10.10,file_mode=0755,dir_mode=0755,nounix,serverino,rsize=16384,wsize=131008,actimeo=1 0 0 I've attached the debug output as suggested in the mailing list and the comments here. Hopefully this will shed some light as to the source of the corruption.
It seems like client exceed the max buffer value. I found out that with total_len 87362 it succeeds but with total_len 125390 it fails. Nick, can you try it with mount option 'wsize=65536', please?
Interesting -- around the time that we see async writes going out to the file, we see these sorts of errors: [810093.500765] fs/cifs/connect.c: rfc1002 length 0x27 [810093.500769] Status code returned 0xc000000d NT_STATUS_INVALID_PARAMETER [810093.500771] fs/cifs/netmisc.c: Mapping smb error code 0xc000000d to POSIX err -22 I suspect that Pavel is correct and the server isn't handling large writes properly. What kind of CIFS server are you writing to here?
Pavel, thanks for the suggestion. I reran my test after mounting with option "wsize=65536", and there was no corruption, so it seems as if this fixed the issue. Jeff: the server is a Sun Storage 7110 NAS, with our share mounted via CIFS.
Ok, a couple more questions... When you get a corrupted file, does the kernel return an error on the fsync() or close()? It looks like you probably are getting an error, but I'd like to confirm that. Would it be possible to have you get a wire capture of the mount attempt? The client and server exchange some info when mounting and we need to see if the server is claiming to do something that it's unable to do.
Created attachment 7074 [details] patch -- lower default wsize to better match windows behavior No response from Nick, but I suspect that the capture will show the server setting CAP_LARGE_WRITE_ANDX. I'm considering proposing this patch for inclusion. It's arguable whether this is really a bug in the client or server since the spec really isn't clear... MS-SMB says that when CAP_LARGE_WRITE_ANDX is set, that the client can send larger writes than the MaxBufferSize. The new cifs writeback code takes advantage of that and sends a write in this case that's as large as possible (128k - 1, rounded down to a multiple of PAGE_CACHE_SIZE). The spec does not however state what the actual max is that the server must support in this situation. Apparently this server doesn't allow writes that large, probably because windows never sends writes that large. This patch should make the default closer to what Windows does. It's not quite exact -- it defaults to 65536 for writes, even though the windows max is 65535. Hopefully this won't be a problem in most cases, and that allows us to squeeze another page into each write.
(In reply to comment #8) > Ok, a couple more questions... > > When you get a corrupted file, does the kernel return an error on the fsync() > or close()? It looks like you probably are getting an error, but I'd like to > confirm that. > > Would it be possible to have you get a wire capture of the mount attempt? The > client and server exchange some info when mounting and we need to see if the > server is claiming to do something that it's unable to do. Apologies for the late reply. I re-mounted the filesystem without the wsize option, and reran my program (also clearing out the buffer using dmesg -c). I didn't see any issues, but there were a few CIFS lines: Nov 9 10:28:33 helix kernel: [1031031.764377] fs/cifs/inode.c: CIFS VFS: in cifs_unlink as Xid: 8061670 with uid: 1000 Nov 9 10:28:33 helix kernel: [1031031.764383] fs/cifs/transport.c: For smb_command 6 Nov 9 10:28:33 helix kernel: [1031031.764386] fs/cifs/transport.c: Sending smb: total_len 212 Nov 9 10:28:33 helix kernel: [1031031.764851] fs/cifs/connect.c: rfc1002 length 0x27 Nov 9 10:28:33 helix kernel: [1031031.764883] fs/cifs/transport.c: cifs_sync_mid_result: cmd=6 mid=11051 state=4 Nov 9 10:28:33 helix kernel: [1031031.764888] fs/cifs/inode.c: CIFS VFS: leaving cifs_unlink (xid = 8061670) rc = 0 Nov 9 10:30:20 helix kernel: [1031138.287382] fs/cifs/cifssmb.c: In echo request Nov 9 10:30:20 helix kernel: [1031138.287389] fs/cifs/transport.c: For smb_command 43 Nov 9 10:30:20 helix kernel: [1031138.287392] fs/cifs/transport.c: Sending smb: total_len 42 Nov 9 10:30:20 helix kernel: [1031138.287758] fs/cifs/connect.c: rfc1002 length 0x2a I also have a packet capture, but am trying to figure out to how to anonymize it for upload.
I should make it clear that the file was corrupted (without wsize=65536), but I didn't see the specific kernel errors you mentioned. (In reply to comment #10) > I > didn't see any issues, but there were a few CIFS lines: >
Those wouldn't be errors that would show up in dmesg. Rather the specific system calls would be returning those errors. If you're using standard tools like "cp" to copy files to the share then you might need to strace it in order to see those errors. In any case, I think the patch I attached earlier is probably reasonable. I plan to do a bit more testing with it and then I'll post it to the list for review.
Steve finally ended up taking this patch for 3.3 and I've marked it for stable kernels as well. Hopefully this will end up fixing the problem for others who have hit this. I'll go ahead and close this with a resolution of "FIXED". Please reopen if you still see this on kernels with commit ce91acb3 in place.