1.3.0.81 failure writing from FTP client
J
ftp> bin
200 Switching to Binary mode.
ftp> get SLES-11-SP1-DVD-x86_64-GM-DVD1.iso
local: SLES-11-SP1-DVD-x86_64-GM-DVD1.iso remote: SLES-11-SP1-DVD-
x86_64-GM-DVD1.iso
229 Entering Extended Passive Mode (|||19555|)
150 Opening BINARY mode data connection for SLES-11-SP1-DVD-x86_64-GM-
DVD1.iso (3036372992 bytes).
0%
|
| 4789 KB 4.67 MB/s 10:18 ETAftp: SLES-11-SP1-DVD-x86_64-GM-
DVD1.iso: short write
0%
|
| 4789 KB 4.67 MB/s 10:18 ETA
426 Failure writing network stream.
4904488 bytes received in 00:01 (4.66 MB/s)
Environment:
SLES11-SP1, x86_64, JAVA_HOME=/usr/java/jdk1.6.0_22, RPMs are 1.3.0.81
as confirmed on their web pages. Filesystem is mounted locally,
access policy is VOLUME.
A local copy works fine.
Also, if access policy is volume and mount point is 777 and mode of
the volume at creation is 777, why can other users not see the mount
point or access the volume?
thanks
Jan Stender
> Got this
>
>
> ftp> bin
> 200 Switching to Binary mode.
> ftp> get SLES-11-SP1-DVD-x86_64-GM-DVD1.iso
> local: SLES-11-SP1-DVD-x86_64-GM-DVD1.iso remote: SLES-11-SP1-DVD-
> x86_64-GM-DVD1.iso
> 229 Entering Extended Passive Mode (|||19555|)
> 150 Opening BINARY mode data connection for SLES-11-SP1-DVD-x86_64-GM-
> DVD1.iso (3036372992 bytes).
> 0%
> |
> | 4789 KB 4.67 MB/s 10:18 ETAftp: SLES-11-SP1-DVD-x86_64-GM-
> DVD1.iso: short write
> 0%
> |
> | 4789 KB 4.67 MB/s 10:18 ETA
> 426 Failure writing network stream.
> 4904488 bytes received in 00:01 (4.66 MB/s)
>
>
> Environment:
> SLES11-SP1, x86_64, JAVA_HOME=/usr/java/jdk1.6.0_22, RPMs are 1.3.0.81
> as confirmed on their web pages. Filesystem is mounted locally,
> access policy is VOLUME.
>
> A local copy works fine.
Is there any meaningful log output in /var/log/xtreemfs wrt. this problem?
> Also, if access policy is volume and mount point is 777 and mode of
> the volume at creation is 777, why can other users not see the mount
> point or access the volume?
>
It's because FUSE disallows other users access to a mount point unless
it was mounted with '-o allow_other'. Please try to mount the volume
with 'mount.xtreemfs -o allow_other ...'.
Best regards,
Jan
J
>
> Is there any meaningful log output in /var/log/xtreemfs wrt. this problem?
nothing of this.
I tried remounting
mount.xtreemfs -d NOTICE -l /root/log-for-3.lis viscsi/forroot /for
but nothing of interest there.
I tried strace of the ftp session and it shows
26578 write(5, "N\246\3066\321\237.K\2\36{>\256x\5\266\346\2dy_
\266\375\17$\203\223\352'\323\270\263"..., 92672) = 92672
26578 read(4, "\213\215\240\300SF\306\243H\255\366\315\355\313m
\305\2426nNYx\37w\357W\344\252*\367\227|"..., 1048576) = 92672
26578 write(5, "\213\215\240\300SF\306\243H\255\366\315\355\313m
\305\2426nNYx\37w\357W\344\252*\367\227|"..., 92672) = 92672
26578 read(4, "\324\2040\1)\222\30$\245\10CJ\6B`
\237\33\317:\366\346\210\0373\367@C\0208\204(`"..., 1048576) = 92672
26578 write(5, "\324\2040\1)\222\30$\245\10CJ\6B`
\237\33\317:\366\346\210\0373\367@C\0208\204(`"..., 92672) = 92672
26578 read(4, "M\25\4\20\226\10\3AQ$A\5\20<\34791\266$H
\26\244\210\210\202\226\242b\nxw\270"..., 1048576) = 92672
26578 write(5, "M\25\4\20\226\10\3AQ$A\5\20<\34791\266$H
\26\244\210\210\202\226\242b\nxw\270"..., 92672) = 44344
26578 --- SIGALRM (Alarm clock) @ 0 (0) ---
26578 ioctl(1, TIOCGPGRP, [26577]) = 0
26578 write(1, "\r 0% | "..., 130) = 130
26578 rt_sigreturn(0x1) = 44344
26578 write(2, "ftp: ", 5) = 5
26578 write(2, "/for/4thbigfile: short write", 28) = 28
26578 write(2, "\n", 1) = 1
Using dd to copy 92672-byte blocks succeeds. Using curl succeeds.
There is just something about that FTP client that breaks things.
>
> > Also, if access policy is volume and mount point is 777 and mode of
> > the volume at creation is 777, why can other users not see the mount
> > point or access the volume?
>
> It's because FUSE disallows other users access to a mount point unless
> it was mounted with '-o allow_other'. Please try to mount the volume
> with 'mount.xtreemfs -o allow_other ...'.
Michael Berlin
Thank you for your report and sorry for my late reply.
First of all I cannot reproduce your problem: Could you please give
detailed instructions how to reproduce this error, preferably using our
public demo server demo.xtreemfs.org/demo and a publicly available FTP file?
Here's what I tried so far:
# Run client in debug mode in foreground and mount demo server:
mount.xtreemfs localhost/ftp ~/mnt -d DEBUG -f
# Download a file from a FTP in another shell:
cd ~/mnt
ftp cdimage.debian.org
# use "anonymous" and "b...@bla.net" as user and password
# inside the ftp session, run:
ftp> cd /debian-cd/current/amd64/iso-dvd
ftp> get debian-6.0.3-amd64-DVD-1.iso
Download works as expected. My system is an Ubuntu 10.10 Maverick with
Fuse 2.8.5 installed and the Ubuntu "ftp" package 0.17-23.
About the error itself:
It seems "ftp" is not able to cope with the fact that a write() did
actually write less bytes than requested. Therefore it complains about
such a "short write" and stops the download.
However, the XtreemFS client itself does never do a short write: It does
always write all bytes it got from Fuse itself and retries until it
managed to write everything or returns an error.
If you enable the debug output in the client with -d DEBUG, you can see
a line for every write request received from Fuse:
xtreemfs_fuse_write /debian-6.0.3-amd64-DVD-1.iso size: 17376
Here the XtreemFS client had to write 17376 bytes. On my system these
numbers of bytes to be written were identical to the output of an strace
of the "ftp" session.
So far I don't know why the "ftp" program should see a "short write".
Have you already tried to mount it with -o directio?
Besides that, it would be great if we could reproduce the error on my
machine so that I can further look into it.
Best regards,
Michael
J
Here is a debug log, as requested
[ D | ?:0 | 10/25 07:26:10.630 | 0xcbe180 ] xtreemfs_fuse_write /
SLES-11-SP1-DVD-x86_64-GM-DVD1.iso size: 4096
[ D | ?:0 | 10/25 07:26:10.630 | 0xcbe180 ] xtreemfs_fuse_write /
SLES-11-SP1-DVD-x86_64-GM-DVD1.iso size: 4096
[ D | ?:0 | 10/25 07:26:10.631 | 0xcbe180 ] xtreemfs_fuse_write /
SLES-11-SP1-DVD-x86_64-GM-DVD1.iso size: 4096
[ D | ?:0 | 10/25 07:26:10.631 | 0xcbe180 ] xtreemfs_fuse_write /
SLES-11-SP1-DVD-x86_64-GM-DVD1.iso size: 4096
[ D | ?:0 | 10/25 07:26:10.632 | 0xcbe180 ] xtreemfs_fuse_write /
SLES-11-SP1-DVD-x86_64-GM-DVD1.iso size: 4096
[ D | ?:0 | 10/25 07:26:10.633 | 0xcbe180 ] xtreemfs_fuse_write /
SLES-11-SP1-DVD-x86_64-GM-DVD1.iso size: 4096
[ D | ?:0 | 10/25 07:26:10.633 | 0xcbe180 ] INTERRUPT triggered,
setting TLS pointer
[ D | ?:0 | 10/25 07:26:10.633 | 0xcbe180 ] Caught interrupt, aborting
sync request.
[ D | ?:0 | 10/25 07:26:10.634 | 0xcbe180 ] xtreemfs_fuse_flush /
SLES-11-SP1-DVD-x86_64-GM-DVD1.iso
[ D | ?:0 | 10/25 07:26:10.634 | 0xcbe180 ] WriteBackFileSize:
file_id: 5 # bytes: 32497664 close file? 0
[ D | ?:0 | 10/25 07:26:10.634 | 0xcbe180 ] xtreemfs_fuse_lock on
path /SLES-11-SP1-DVD-x86_64-GM-DVD1.iso command: set lock type:
unlock start: 0 length: 0 pid: 0
[ D | ?:0 | 10/25 07:26:10.635 | 0xcbe180 ]
FileHandleImplementation::ReleaseLock: Skipping unlock request as
there is no lock known for the PID: 0 (Lock description: 0, 0, 0)
[ D | ?:0 | 10/25 07:26:10.635 | 0xcbe070 ] xtreemfs_fuse_release /
SLES-11-SP1-DVD-x86_64-GM-DVD1.iso
[ D | ?:0 | 10/25 07:26:10.635 | 0xd34770 ] getattr on path /SLES-11-
SP1-DVD-x86_64-GM-DVD1.iso
[ D | ?:0 | 10/25 07:26:10.636 | 0xd34770 ] getattr: serving from stat-
cache /SLES-11-SP1-DVD-x86_64-GM-DVD1.iso 32497664
[ D | ?:0 | 10/25 07:26:10.636 | 0xcbe180 ] xtreemfs_fuse_utimens on
path /SLES-11-SP1-DVD-x86_64-GM-DVD1.iso
[ D | ?:0 | 10/25 07:26:10.636 | 0xcbe180 ] MetadataCache
UpdateStatAttributes: /SLES-11-SP1-DVD-x86_64-GM-DVD1.iso to_set: 48
[ D | ?:0 | 10/25 07:26:10.636 | 0xcbe180 ] getattr on path /SLES-11-
SP1-DVD-x86_64-GM-DVD1.iso
[ D | ?:0 | 10/25 07:26:10.637 | 0xcbe180 ] getattr: serving from stat-
cache /SLES-11-SP1-DVD-x86_64-GM-DVD1.iso 32497664
[ D | ?:0 | 10/25 07:26:13.930 | 0xcb1ea0 ] START open_file_table:
Periodic XCap renewal for 0 open files.
[ D | ?:0 | 10/25 07:26:13.930 | 0xcb1ea0 ] END open_file_table:
Periodic XCap renewal for 0 open files.
[ D | ?:0 | 10/25 07:26:13.930 | 0xcaf9b0 ] START open_file_table:
Periodic filesize update for 0 open files.
[ D | ?:0 | 10/25 07:26:13.930 | 0xcaf9b0 ] END open_file_table:
Periodic filesize update for 0 open files.
and the ftp session looked like this
ftp> get SLES-11-SP1-DVD-x86_64-GM-DVD1.iso
local: SLES-11-SP1-DVD-x86_64-GM-DVD1.iso remote: SLES-11-SP1-DVD-
x86_64-GM-DVD1.iso
1% | | 31765 KB 6.20 MB/s
07:41 ETAftp: SLES-11-SP1-DVD-x86_64-GM-DVD1.iso: short write
1% | | 31765 KB 6.20 MB/s
07:41 ETA
ftp> quit
Michael Berlin
Unfortunately, this does not really help. I do not see any obvious
problems. However, you can see in the log, that the write() was
interrupted (see the two lines containing "INTERRUPT triggered, setting
TLS pointer" and "Caught interrupt, aborting sync request.")
I'm wondering who did interrupt the write(). I guess you did not press
Ctrl + C? So it probably comes from the "ftp" program. Can you please
check if the interrupt is issued by "ftp" after it did abort with the
"short write" error?
Besides that, please try the following two things: Test the client with
the mount options -o direct_io and --interrupt-signal=0 (each separately).
Could you please also check if you have already the latest version from
the unstable repository
(http://download.opensuse.org/repositories/home:/xtreemfs:/unstable/)?
The best way to track down this issue is if I could reproduce the error
locally. Can you tell me please which Linux distribution you are using
and what's the package version of the "ftp" program? Then I would setup
a local VM and try to reproduce the issue.
Thank you for your help,
Best regards,
Michael