GNOME Bugzilla – Bug 525283
handle short reads in ftp
Last modified: 2009-02-24 08:50:50 UTC
Please describe the problem: This bug is thoroughly explained and reported at: http://bugs.launchpad.net/bugs/208750 If I try to open ftp://dasher.sh3lls.net/ using the gvfs backend in nautilus, I get an error without a login prompt: Couldn't display "ftp://dasher.sh3lls.net/". Error: Invalid reply Please select another viewer and try again. This happens to a lot of *.sh3lls.net servers to my knowledge, if not all, vortex.sh3lls.net astro.sh3lls.net dasher.sh3lls.net and eclipse.sh3lls.net. This happens even if I provide a username: nautilus ftp://test@dasher.sh3lls.net/ I can connect to these using ftp, lftp and gftp. I noticed some difference in the output of gvfsd -r in the banner of the pure-ftpd server that this servers use as ftp daemon. Steps to reproduce: 1. nautilus ftp://dasher.sh3lls.net 2. no login prompt 3. error "invalid reply" Actual results: A window "Error: Invalid reply" shows up. Expected results: I don't get a login prompt, asking me for a username and password, as it does with other websites, i.e. ftp://ftp.mozilla.org Does this happen every time? Yes Other information: At first, I thought it was a problem linked to pure-ftpd until I found another website that had pure-ftpd where it did actually ask me to login: ftp://ftp.greek-fun.com This error is normal and you can get the same error in any ftp server only if you select to "connect anonymously" from the login prompt. It looks like gvfsd -r sees and parses the ftp banner differently. If you see below, I compared the output of "/usr/lib/gvfs/gvfsd -r" (and tried to connect using the gvfs backend) with the corresponding "telnet" connection on port 21. Notice the difference in the end of the pure-ftp banner: "<-- [TLS]" or "----<-- ------" 1) nautilus ftp://test@dasher.sh3lls.net Added new job source 0x642010 (GVfsBackendFtp) Queued new job 0x643030 (GVfsJobMount) <-- 220---------- Welcome to Pure-FTPd [privsep] <-- [TLS] ---------- send_reply, failed: 1 2) nautilus ftp://test@astro.sh3lls.net Added new job source 0x642010 (GVfsBackendFtp) Queued new job 0x643030 (GVfsJobMount) <-- 220---------- Welcome to Pure-FTPd [TLS] ----<-- ------ send_reply, failed: 1 3)(the working one) nautilus ftp://test@ftp.greek-fun.com Added new job source 0x642010 (GVfsBackendFtp) Queued new job 0x643030 (GVfsJobMount) <-- 220---------- Welcome to Pure-FTPd [TLS] ---------- <-- 220-You are user number 1 of 50 allowed. <-- 220-Local time is now 20:22. Server port: 21. <-- 220-IPv6 connections are also welcome on this server. <-- 220 You will be disconnected after 15 minutes of inactivity. (I hit cancel at the login prompt) send_reply, failed: 1 ..with the results of their corresponding telnet: 1) $ telnet dasher.sh3lls.net 21 Trying 66.252.13.2... Connected to dasher.sh3lls.net. Escape character is '^]'. 220---------- Welcome to Pure-FTPd [privsep] [TLS] ---------- 220-You are user number 1 of 50 allowed. 220-Local time is now 12:26. Server port: 21. 220-This is a private system - No anonymous login 220-IPv6 connections are also welcome on this server. 220 You will be disconnected after 15 minutes of inactivity. 2) $ telnet astro.sh3lls.net 21 Trying 69.42.213.130... Connected to astro.sh3lls.net. Escape character is '^]'. 220---------- Welcome to Pure-FTPd [TLS] ---------- 220-You are user number 1 of 50 allowed. 220-Local time is now 17:27. Server port: 21. 220-This is a private system - No anonymous login 220-IPv6 connections are also welcome on this server. 220 You will be disconnected after 15 minutes of inactivity. 3) $ telnet ftp.greek-fun.com 21 Trying 72.52.215.141... Connected to ftp.greek-fun.com. Escape character is '^]'. 220---------- Welcome to Pure-FTPd [TLS] ---------- 220-You are user number 1 of 50 allowed. 220-Local time is now 12:29. Server port: 21. 220-IPv6 connections are also welcome on this server. 220 You will be disconnected after 15 minutes of inactivity.
Another person has commented about this weird occurance, it could be linked to the fact that the server are running FreeBSD, I quote what they said at launchpad: "I too have this error. I have a working ftp server that does not accept anonymous connections. My system is fully up-to-date with with all the updates @ 22:00 GMT My server I connect to is ProFTPD 1.3.1 Server running on FreeBSD. Only nautilus gives the error Invalid reply." "Interestingly enough, I installed proftpd locally and it works fine. First is the Ubuntu server, then the BSD one I used the same daemon version for comparison purposes. No idea what the difference in response is apart from the custom server name. Still the Ubuntu one works, the BSD one does not. Connected to localhost. 220 ProFTPD 1.3.1 Server (Debian) [127.0.0.1] Name (localhost:xxx): xxx 331 Password required for xxx Password: 230 User xxx logged in Remote system type is UNIX. Using binary mode to transfer files. ftp> bye 221 Goodbye. Connected to tokra 220 ProFTPD 1.3.1 Server (BSD) [192.168.0.6] Name (tokra:xxx): xxx 331 Password required for xxx Password: 230 User xxx logged in Remote system type is UNIX. Using binary mode to transfer files. ftp> " "Forgot to add: If I use Firefox to connect to the BSD server, it all works perfectly to the remote server"
As an addition, I tried the release candidate of ubuntu hardy heron 8.04 resulting to same problem. I also tried to clear some problems by removing the contents of the .gconf/* folder, it still causes the same problem.
"I tried the release candidate of ubuntu hardy heron 8.04 resulting to same problem." <- I meant as a live cd
Confirming in Ubuntu Hardy 8.04: azatoth@azatoth-laptop:~$ /usr/lib/gvfs/gvfsd -r Added new job source 0x642010 (GVfsBackendFtp) Queued new job 0x643030 (GVfsJobMount) <-- 220---------- Welcome to Pure-FTPd [privsep] <-- [TLS] ---------- send_reply, failed: 1
Confirming in Ubuntu Hardy 8.04 LTS too. Package versions: ----------------- gvfs -- 0.2.4-0ubuntu1 gvfs-backends -- 0.2.4-0ubuntu1 gvfs-bin -- 0.2.4-0ubuntu1 nautilus -- 1:2.22.3-0ubuntu2 Nautilus gives error message: ----------------------------- Couldn't display "ftp://example.com" Error: Invalid reply Please select another viewer and try again. Output from gvfsd ----------------- yjwong@yjwong:~/Desktop/build$ /usr/lib/gvfs/gvfsd --replace Added new job source 0x807a800 (GVfsBackendFtp) Queued new job 0x807bc18 (GVfsJobMount) <-- 220---------- Welcome to Pure-FTPd [TLS] ----<-- ------ send_reply, failed: 1
Alright, I've traced the problem further, but with my limited knowledge of C and GVFS, I was unable to fix the bug. I have identified the codeblock that was failing, in that case the code is located in: daemon/gvfsbackendftp.c From line 403 to line 411: if (n_bytes < 4 || last_line[0] <= '0' || last_line[0] > '5' || last_line[1] < '0' || last_line[1] > '9' || last_line[2] < '0' || last_line[2] > '9') { g_set_error (&conn->error, G_IO_ERROR, G_IO_ERROR_FAILED, _("Invalid reply")); return 0; } From my previous Pure-FTPd output, the last_line variable contained "------", which is shown in the output of GVFSD after the second "<--" debug output. The value of last_line obviously returns true in the "if" clause. I'm tracing this using Ubuntu 8.04 (Hardy Heron), GVFS 0.2.4-0ubuntu1. To get the sources, do: apt-get source gvfs Any hackers willing to investigate further?
I can also confirm this. What I think is happening is that last_line only contains the last data read from the server, not the whole line. I believe this line is responsible: last_line = conn->read_buffer + conn->read_bytes; (line 369 in gvfsbackendftp.c the gvfsd in hardy, 0.2.5) the last_line pointer is being moved to the next point soup_socket_read_until should put its data. Since you have received the banner in two frames, the soup_socket_read_until function has been called twice and even though there is a string which contains the whole line, the pointer last_line now points only at the final part of it. I'm not familiar with the rest of the code, but my quick reading suggests that if another pointer is kept, which points always at the start of the line, this will work. FWIW I reproduced this with the ftp server built into DataCase, an application for the iPhone. I am very happy to provide further testing information, either by email or IRC (I am "Ng" on gimpnet, freenode, mozillanet and others)
Specifically, just inside this check: if (reply_state == FIRST_LINE) it looks for the first 3 bytes of the line to see what the response code is. I tried repointing this at conn->read_buffer and it does now accept the banner, but it gets pretty confused later on and without a lot more headscratching at the code, my rusty old C isn't going to be able to fix this, I suspect.
Created attachment 116623 [details] [review] Patch to fix response code handling in gvfs ftp backend
I just attached a patch which I think will fix this, but I have no idea if is the correct solution or not. For that we need someone from gnome (perhaps Company?) to comment, someone who knwos the code.
I applied the patch to gvfs (0.25-0ubuntu2) from Ubuntu 8.04 Hardy Heron, but that does not seem to fix the issue. I'm not sure whether I've used dpkg-buildpackage with debian/patches correctly, but it should be correct. Output is the same: yjwong@yjwong:~/Desktop/build/active$ /usr/lib/gvfs/gvfsd --replace Added new job source 0x807a800 (GVfsBackendFtp) Queued new job 0x807bc18 (GVfsJobMount) <-- 220---------- Welcome to Pure-FTPd [TLS] ----<-- ------ send_reply, failed: 1 Have you tested your own patch yet? Does it work for you? Thanks for your efforts; my rusty old C++ is no better.
Ah just remembered that I forgot to install the backends Debian package that was generated as well. Anyway, the patch works to a certain extent; it passes through the initial banner display, but it seems to fail to authenticated, although I'm very sure that my password is correct. The output: yjwong@yjwong:~/Desktop/build/active$ /usr/lib/gvfs/gvfsd --replace Added new job source 0x807a800 (GVfsBackendFtp) Queued new job 0x807bc18 (GVfsJobMount) <-- 220---------- Welcome to Pure-FTPd [TLS] ----<-- ------ <-- 220-You are user number 4 of 50 allowe<-- d. <-- 220-Local time is now 17:42. Server port: <-- 21. <-- 220-IPv6 connections are also welcome on <-- this server. <-- 220 You will be disconnected aft<-- er 15 minutes of inactivity. <-- --> USER yjwong <-- 331 User yjwong OK. Password required --> PASS *** <-- 230-User yjwong has group access to: yjwong <-- send_reply, failed: 1 Hmm.
Wong: I'm not sure what that is, I'm afraid. It does look like the multiple-frame lines are being handled correctly though, and that was my main focus here! I'd suggest adding some DEBUG("foo"); calls in ftp_connection_sendv(), the password is sent in there and the response is read at the bottom with a call to ftp_connection_receive(), so some debugging in there would be good too (although it's a pretty hairy function!)
I just had another look at your debut output and it kinda seems like you get a blank line at the end. I wonder if this is the problem? I don't know if this is my fault or not :/
I can confirm this bug is still present in Gnome 2.24/Ubuntu Intrepid. It's sporadic, in that it's only a bug for some people & not others. I'm not sure what the difference in configuration is.
I now (gnome 2.24 and ubuntu 8.10) see this error only on: ftp://astro.sh3lls.net ftp://viper.sh3lls.net ftp://shark.sh3lls.net ftp://orbit.sh3lls.net I cannot see this error and can connect normally on: ftp://dasher.sh3lls.net ftp://viper.sh3lls.net ftp://eclipse.sh3lls.net $ apt-cache policy gvfs-backends gnome-about gvfs-backends: Installed: 1.0.2-0ubuntu1 Candidate: 1.0.2-0ubuntu1 Version table: *** 1.0.2-0ubuntu1 0 500 http://de.archive.ubuntu.com intrepid/main Packages 100 /var/lib/dpkg/status gnome-about: Installed: 1:2.24.1-0ubuntu1 Candidate: 1:2.24.1-0ubuntu1 Version table: *** 1:2.24.1-0ubuntu1 0 500 http://de.archive.ubuntu.com intrepid/main Packages 100 /var/lib/dpkg/status The ones that show the error seem to have this banner/reply: <-- 220---------- Welcome to Pure-FTPd [TLS] ---------- <-- 220-You are user number 1 of 50 allowed. <-- 220-Local time is now 08:30. Server port: 21. <-- 220-This is a private system - No anonymous login <-- 220-IPv6 connections are also welcome on this server. <-- 220 You will be disconnected after 15 minutes of inactivity. send_reply, failed: 1 or this: <-- 220---------- Welcome to Pure-FTPd [privsep] <-- [TLS] ---------- send_reply, failed: 1
Created attachment 126356 [details] [review] Slightly different patch If anyone with a sh3lls.net account could test this, that would be great.
*** Bug 541737 has been marked as a duplicate of this bug. ***
Found the site ftp://ftp.aist-nara.ac.jp/ which seems to have this problem. gvfs 1.0.3 can't connect to it, but it works with gvfs 1.0.3 + daemon/gvfsbackendftp.c from svn + my patch above. Also found ftp1.freebsd.org which gvfsd-ftp can't connect to (works with lftp), but it seems like some other issue causing that.
I have worries that it might be a problem with a misconfigured ftpd server? Before ftp://dasher.sh3lls.net didn't work, but now does. In the meantime, I know they upgraded their FreeBSD servers. As mentioned above, these don't work: ftp://astro.sh3lls.net ftp://shark.sh3lls.net ftp://orbit.sh3lls.net and these work properly: ftp://dasher.sh3lls.net ftp://viper.sh3lls.net ftp://eclipse.sh3lls.net Andreas, you don't need an account in sh3lls to test it. Just execute: nautilus ftp://astro.sh3lls.net It fails and shows the error message instantly, without showing the "Enter Password" dialog: Could not display "ftp://astro.sh3lls.net/". Error: Invalid reply Please select another viewer and try again.
(In reply to comment #20) > I have worries that it might be a problem with a misconfigured ftpd server? The server is certainly not behaving optimally, but it's not a protocol violation so gvfsd-ftp should be able to handle it. [...] > Andreas, you don't need an account in sh3lls to test it. Just execute: > nautilus ftp://astro.sh3lls.net This part works perfectly with my patch.... Not failing instantly isn't the same as working properly though! Hopefully ftp://ftp.aist-nara.ac.jp/ is a good enough testcase though, as mentioned previously. (Otherwise I'll just blame the ones with accounts for not helping out testing! ;] )
Ah yes, but I'm not keen with compiling, I'll just wait for someone to test it. Good testcase though!
Thanks to Savvas the patch has now been tested and it was successful in resolving the problem. The author of the ftp backend is currently travelling, but I'll make sure to poke him for review as soon as he returns (mid. feb. AFAIK). Here are some debug logs: With plain gvfs 1.0.3: gem@amd64:~$ /usr/lib/gvfs/gvfsd -r Added new job source 0x1ec70c0 (GVfsBackendFtp) Queued new job 0x1ec8030 (GVfsJobMount) <-- 220---------- Welcome to Pure-FTPd [privsep] <-- [TLS] ---------- send_reply, failed: 1 Hangup gem@amd64:~$ With gvfs 1.0.3 + daemon/gvfsbackendftp.c from trunk/master + http://bugzilla.gnome.org/attachment.cgi?id=126356 gem@amd64:~$ /usr/lib/gvfs/gvfsd -r Added new job source 0x19fe0c0 (GVfsBackendFtp) Queued new job 0x19ff030 (GVfsJobMount) <-- 220---------- Welcome to Pure-FTPd [privsep] [TLS] ---------- <-- 220-You are user number 1 of 50 allowed. <-- 220-Local time is now 15:55. Server port: 21. <-- 220-This is a private system - No anonymous login <-- 220-IPv6 connections are also welcome on this server. <-- 220 You will be disconnected after 15 minutes of inactivity. --> FEAT <-- 211-Extensions supported: <-- EPRT <-- IDLE <-- MDTM <-- SIZE <-- REST STREAM <-- MLST type*;size*;sizd*;modify*;UNIX.mode*;UNIX.uid*;UNIX.gid*;unique*; <-- MLSD <-- ESTP <-- AUTH TLS <-- PBSZ <-- PROT <-- PASV <-- EPSV <-- SPSV <-- ESTA <-- 211 End. feature MDTM supported feature SIZE supported feature EPSV supported --> USER hellnet <-- 331 User hellnet OK. Password required --> PASS *** <-- 230-User hellnet has group access to: hellnet <-- 230 OK. Current restricted directory is / --> TYPE I <-- 200 TYPE is now 8-bit binary --> SYST <-- 215 UNIX Type: L8 system is 1 send_reply, failed: 0 register_mount_callback, mount_reply: 0x19f65a0, error: (nil) backend_dbus_handler org.gtk.vfs.Mount:QueryInfo Queued new job 0x1a0b820 (GVfsJobQueryInfo) --> NOOP <-- 200 Zzz... send_reply(0x1a0b820), failed=0 () backend_dbus_handler org.gtk.vfs.Mount:QueryInfo Queued new job 0x1a0b8c0 (GVfsJobQueryInfo) --> NOOP <-- 200 Zzz... send_reply(0x1a0b8c0), failed=0 () backend_dbus_handler org.gtk.vfs.Mount:Enumerate Queued new job 0x1a120c0 (GVfsJobEnumerate) --> NOOP <-- 200 Zzz... --> CWD / <-- 250 OK. Current directory is / --> EPSV <-- 229 Extended Passive mode OK (|||36496|) --> LIST -a <-- 150 Accepted data connection --- drwx--x--x 4 hellnet hellnet 512 Jan 29 14:29 . --- drwx--x--x 4 hellnet hellnet 512 Jan 29 14:29 .. --- -rw------- 1 hellnet hellnet 22 Jan 29 14:29 .bash_history --- -rw-r--r-- 1 hellnet hellnet 767 Mar 10 2008 .cshrc --- -rw-r--r-- 1 hellnet hellnet 248 Mar 10 2008 .login --- -rw-r--r-- 1 hellnet hellnet 158 Mar 10 2008 .login_conf --- -rw------- 1 hellnet hellnet 2075 Sep 22 21:31 .lsof_vortex --- -rw------- 1 hellnet hellnet 373 Mar 10 2008 .mail_aliases --- -rw-r--r-- 1 hellnet hellnet 331 Mar 10 2008 .mailrc --- -rw-r--r-- 1 hellnet hellnet 797 Mar 10 2008 .profile --- -rw------- 1 hellnet hellnet 276 Mar 10 2008 .rhosts --- -rw-r--r-- 1 hellnet hellnet 975 Mar 10 2008 .shrc --- drwx------ 2 hellnet hellnet 512 Mar 10 2008 tmp --- drwxr-xr-x 2 hellnet hellnet 512 Mar 10 2008 www <-- 226-ASCII <-- 226-Options: -a -l <-- 226 14 matches total send_reply(0x1a120c0), failed=0 () backend_dbus_handler org.gtk.vfs.Mount:QueryInfo Queued new job 0x1a0b960 (GVfsJobQueryInfo) --> NOOP <-- 200 Zzz... send_reply(0x1a0b960), failed=0 () backend_dbus_handler org.gtk.vfs.Mount:QueryInfo Queued new job 0x1a0ba00 (GVfsJobQueryInfo) --> NOOP <-- 200 Zzz... send_reply(0x1a0ba00), failed=0 () backend_dbus_handler org.gtk.vfs.Mount:QueryInfo Queued new job 0x1a0baa0 (GVfsJobQueryInfo) --> NOOP <-- 200 Zzz... send_reply(0x1a0baa0), failed=0 () backend_dbus_handler org.gtk.vfs.Mount:Unmount g_vfs_job_unmount_new request: 0x1a54c20 Queued new job 0x19fc580 (GVfsJobUnmount) send_reply, failed: 0 unregister_mount_callback, unmount_reply: (nil), error: 0x19ed600 send_reply(0x19fc580), failed=0 ()
2009-02-19 Benjamin Otte <otte@gnome.org> reviewed by: Andreas Henriksson <andreas@fatal.se> Bug 525283 - handle short reads in ftp * daemon/gvfsbackendftp.c: (ftp_connection_receive): account for cases where soup_socket_read_until() would not read up to the boundary on the first read.
I believe there is still an issue with small chunks. After reading up to the boundary there are a couple of checks that validate last_line assuming that n_bytes is its length but now it is just the size of the last chunk read so it still gives invalid reply if the chunk is too small (n_bytes < 4).
Created attachment 129388 [details] [review] fix last line validation checking its real length and not last chunk size Tested on a local bftpd instance that returned invalid reply with a response like: <-- 220 bftpd send_reply, failed: 1 last line is 11 bytes long while n_bytes is 3.
Hehe, I managed to write and commit a different fix in the 3 minutes between you reopening and submitting the bug. Please make sure this one really works. 2009-02-24 Benjamin Otte <otte@gnome.org> Bug 525283 - handle short reads in ftp * daemon/gvfsbackendftp.c: (ftp_connection_receive): fix usage of n_bytes variable that changed meaning with the last ftp fixes. Spotted by Filippo Argiolas <filippo.argiolas@gmail.com>
Turns out I didn't. I just can't get used to GMail threading of multiple new messages.
(In reply to comment #28) > Turns out I didn't. I just can't get used to GMail threading of multiple new > messages. Hehe you're not alone, I won't ever understand why GMail doesn't have a classic tree view for threads :) Anyway I confirm your fix works here, thanks.