Go Back   FlashFXP Forums > > > >

ioFTPD General New releases, comments, questions regarding the latest version of ioFTPD.

Reply
 
Thread Tools Rate Thread Display Modes
Old 04-21-2010, 02:06 PM   #16
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

I got some weird transfer errors now, after I upgraded. From one particular site I got a lot of faulty files. There has not been any problems previously in between these two sites, but now it's close to 30% failed files..

(20:55:43) [io742] CPSV
(20:55:43) [io742] 227 Entering Passive Mode (1,1,1,1,60,83)
(20:55:43) [glftpd] PORT 1,1,1,1,60,83
(20:55:43) [glftpd] 200 PORT command successful.
(20:55:43) [io742] STOR file.r12
(20:55:43) [io742] 150 Opening BINARY mode data connection for file.r12 using SSL/TLS.
(20:55:43) [glftpd] RETR file.r12
(20:55:43) [glftpd] 150 Opening BINARY mode data connection for file.r12 (15000000 bytes) using SSL/TLS.
(20:55:49) [glftpd] 426 Data connection: Broken pipe.
(20:55:49) [io742] CWD /dir1/dir3/Subdir/
(20:55:49) [glftpd] STAT -l
(20:55:49) [io742] 426-250- .----== ioNiNJA v0.8 ==----------------------------.
(20:55:49) [io742] 426-250- | + CRC-Check: FaileD! |
(20:55:49) [io742] 426-250- `--------------------------------=====-------------'
(20:55:49) [io742] 226-Transferred: 8863744.
(20:55:49) [io742] 426 Connection closed: SSL library returned a failure code.
(20:55:49) [glftpd] List Complete: 3*742 bytes in 0,08 seconds (47,97KB/s)
(20:55:49) [io742] 226 ABOR command successful.
(20:55:49) [io742] PWD

Why does io think there's an ABOR sendt? Why wouldn't the transfer complete, even if there's packetloss on the network, as it aborts after half the transfer? I might add that I got a io703->io742 transfer running in another session without any problems.

Is there a way to be sure who's at fault here? I can't seem to find any records in logs about what failiure code the ssl library returns..

*Edit: Just updated another server, experiencing the same weird dropped transfers, from multiple sources that never had such problems before update

Last edited by pion; 04-21-2010 at 02:22 PM.
pion is offline   Reply With Quote
Old 04-21-2010, 02:16 PM   #17
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

You where dead on about the Encryption_Protocol. I commented it out now, and both SSL and TLS worked fine. No more complaints from client.
pion is offline   Reply With Quote
Old 04-21-2010, 03:07 PM   #18
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

Ah! Finally! There IS a problem with SSL transferring files and loosing up to the last 100k or so of the file. I can't seem to reproduce it at the moment, but other people trying the release found the same thing. Hence the extra line of output showing how many bytes got written...

I am working on figuring out what is going on right now and hopefully should have a fix soon. At least we figured out all your other issues, and perhaps highlighted the fact that I should double check that SSL or TLS has not been disabled in the config file before responding to the command
Yil is offline   Reply With Quote
Old 04-21-2010, 03:37 PM   #19
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

I looked over your latest logfile... It's weird. I agree I can't see a reference to the ABOR command anywhere, but why is the client issuing a CWD command after starting a transfer and before it's finished? And the server not complaining? You sure this isn't a combined logfile from more than one session? Like FlashFXP writing to a unified logfile?
Yil is offline   Reply With Quote
Old 04-21-2010, 03:42 PM   #20
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

Oh, just for the record. The new transfer engine is picky about errors, whereas the old one silently ignored most of them. The new one records and aborts on all errors. This is a little annoying right now, but once I understand how and where certain errors occur I'll make sure they are handled correctly and silently which will highlight the real ones later on rather than masking them.

I've already found one instance where the error returned isn't supposedly possible in a particular situation according to MS but online people seem to handle it and get it as well so it's not just me. It's that kind of thing I want to uncover...
Yil is offline   Reply With Quote
Old 04-21-2010, 07:07 PM   #21
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default ioFTPD v7.4.3 Changelog

Code:
v7.4.3 Release Notes:

1) Files in \System:
   Changed : ioFTPD.[exe,pdb] - Version 7.4.3.0


*** New Features

2) Modified command (AUTH {TLS|SSL}).  The server will no longer accept
   "AUTH TLS" or "AUTH SSL" if that particular protocol is not supported by
   the service because of the Encryption_Protocol setting in the .ini
   configuration file.


*** Bug Fixes

3) Fixed secure socket read routine to consume as much as possible from the
   read buffer before requesting more data.  This should prevent truncated
   and/or corrupt file uploads.
Yil is offline   Reply With Quote
Old 04-21-2010, 07:11 PM   #22
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

Try this one. Works fine for me locally. If the OpenSSL library returns an error it will record the details into the Debug.log file...
Yil is offline   Reply With Quote
Old 04-22-2010, 04:04 AM   #23
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

io 743 appears to work fine No broken transfers yet.

On a side note, preload is still strangly slow.. this is in io 743 with delay=true:

04-22-2010 09:30:16 PRELOAD: "begin" "../etc/default.vfs"
04-22-2010 09:34:47 PRELOAD: "points=13" "../etc/default.vfs"

After playing around some with it, I'm still confused as to how it's intended to work.

I tried creating ../etc/sections.vfs, and move some of the mountpoints in there, but they don't show up on site!

I also tried adding 1=/mydir/ for every single dir in the / mount, with it still taking equally long time to start up.

Then I have another site with atleast 100x the ammount of dirs and subdirs, which load in 0s

04-22-2010 10:21:20 PRELOAD: "begin" "../etc/sections.vfs"
04-22-2010 10:21:20 PRELOAD: "points=4" "../etc/sections.vfs"
04-22-2010 10:21:20 PRELOAD: "count=141" "../etc/sections.vfs"
04-22-2010 10:21:33 SSL: "Unable to locate default certificate" "name=ioFTPD" "Service=FTP_Service"
04-22-2010 10:21:33 START: "PID=2960" "CmdLine="

(assuming START is where users are able to log in)

in that sections.vfs file, some of the mountpoints are plainly copied from default.vfs

When going back to my trouble site, I attempted to only add 1 single (small) directory to sections.vfs, and leave a copy + rest of mounts in default.vfs:

04-22-2010 10:55:02 PRELOAD: "begin" "../etc/sections.vfs"
04-22-2010 10:55:15 PRELOAD: "points=1" "../etc/sections.vfs"
04-22-2010 11:00:45 SSL: "Found certificate" "name=abcd" "Service=FTP_Service" "(Certificate_name)"
04-22-2010 11:00:45 START: "PID=528" "CmdLine="
04-22-2010 11:00:47 LOGIN: "FTP_Service" "pion"

As you can see, it would appear as if preload finish in a timeframe that looks much more sane, but I still can't log in.

Anyway - I'm fairly confused as to how I'm suppose to use sections.vfs, and the preload settings.. maybe you could clarify? Like what is correct syntax to only go 1 subdir deep during preloading? And debug what directory/harddrive in particular that's causing this very long startup time?

*Edit: to top it off, I tried removing all but one of the mountpoints in default.vfs, then boot ftpd, and add the rest of dirs after. Relogin works instantly, listing all folders as it should instantly..

Last edited by pion; 04-22-2010 at 04:25 AM.
pion is offline   Reply With Quote
Old 04-22-2010, 04:30 AM   #24
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

Also: This is still a problem during fxp:

(11:25:33) [io743] CPSV
(11:25:33) [io743] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.

You added a workaround for PASV command I see, might add it here aswell? I'm not sure how the client would know when to abort transfer during fxp tho, since it has no idea of the actual data transfer.. except for that 550 ofc. During regular download, the client aborts just fine on problems.
pion is offline   Reply With Quote
Old 04-22-2010, 09:48 AM   #25
Flow
Senior Member
FlashFXP Beta Tester
ioFTPD Foundation User
 
Flow's Avatar
 
Join Date: Dec 2001
Posts: 306
Default

Duhhh, had to re-do the command ´site makecert´to make it kickin. Is working for me now

Cool, OpenSSL yey
Flow is offline   Reply With Quote
Old 04-22-2010, 10:06 AM   #26
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

Really good to hear it's working for people now!!!

Here's a special build that is just for o_dog and pion:

Link: ioFTPD-v7.4.4-exe-only.zip

You will now see something like:
550-Init: 1, Aborted: 0, Socket: 752, LastError: 0, Size: 0, Pos: 0
550 Active transfer in progress, terminate transfer with ABOR before proceeding.

The extra line above is the only change from 7.4.3, but it will show a couple of fields from the data transfer structure whenever you would get that 550 message. In particular if Socket is not 0 or -1 then the system has an open data socket and really does think it's transferring a file or waiting to connect/listening. Size is the size of the file (0 for uploads) and Pos is the current position. If you see that increasing then it really is sending/receiving.

Hopefully this can help figure out what you are seeing. I still believe it's the client not sending an ABOR command when required so try to get client logs if possible.
Yil is offline   Reply With Quote
Old 04-22-2010, 01:01 PM   #27
o_dog
Senior Member
 
Join Date: May 2007
Posts: 692
Default

Even if it doesn't send them it should abort if nothing gets sent or if the speed is below 0.1kb/s for a long time. nm, works jsut fine, missed the openssl things.
__________________
ioNiNJA
o_dog is offline   Reply With Quote
Old 04-22-2010, 01:11 PM   #28
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

Bad news: Hangup bug still present...

(19:43:34) [i] [io703 -> io744] file.r24 14,3 Mbytes/13,52(s)/1*109,80Kbps
(19:43:34) [io703] Reversed FXP started
(19:43:34) [io744] CPSV
(19:43:35) [io744] 227 Entering Passive Mode (1,1,1,1,61,236)
(19:43:35) [io703] PORT 1,1,1,1,61,236
(19:43:35) [io703] 200 PORT command successful.
(19:43:35) [io744] STOR file.r23
(19:43:35) [io744] 150 Opening BINARY mode data connection for file.r23 using SSL/TLS.
(19:43:35) [io703] RETR file.r23
(19:43:36) [io703] 150 Opening BINARY mode data connection for file.r23 (14648 bytes) using SSL/TLS.
(19:44:32) [io703] 200 NOOP command successful.
(19:44:37) [io703] 426 Connection closed: The network connection was aborted by the local system.
(19:44:37) [io703] Reversed FXP started
(19:44:37) [io744] CPSV
(19:47:57) [io744] Timeout, Connection closed
(19:47:57) [io703] Reversed FXP started
(19:47:57) [io744] CPSV
(19:51:17) [io744] Timeout, Connection closed
(19:51:17) [io703] Reversed FXP started
(19:51:17) [io744] CPSV
(19:54:37) [io744] Timeout, Connection closed
(19:54:37) [io703] Reversed FXP started





(19:58:02) [glftpd] PORT 1,1,1,1,66,83
(19:58:03) [glftpd] 200 PORT command successful.
(19:58:03) [io744] STOR myfile.r46
(19:58:03) [io744] 150 Opening BINARY mode data connection for myfile.r46 using SSL/TLS.
(19:58:03) [glftpd] RETR myfile.r46
(19:58:03) [glftpd] 150 Opening BINARY mode data connection for myfile.r46 (15000000 bytes) using SSL/TLS.
(19:58:22) [glftpd] 435 Failed TLS negotiation on data channel (using SSL_accept()), disconnected: Connection reset by peer.
(19:58:22) [i] [glftpd -> io744] Transfer Failed: myfile.r46
(19:58:22) [glftpd] Reversed FXP started
(19:58:22) [io744] CPSV
(19:58:22) [io744] 226-Transferred: 0.
(19:58:22) [io744] 426 Connection closed: Connection timed out.
(19:58:22) [io744] 226 ABOR command successful.
(19:58:23) [io744] 227 Entering Passive Mode (1,1,1,1,58,93)
(19:58:23) [glftpd] PORT 1,1,1,1,58,93
(19:58:23) [glftpd] 200 PORT command successful.
(19:58:23) [io744] STOR myfile.r45
(19:58:23) [io744] 150 Opening BINARY mode data connection for myfile.r45 using SSL/TLS.
(19:58:23) [glftpd] RETR myfile.r45
(19:58:23) [glftpd] 150 Opening BINARY mode data connection for myfile.r45 (15000000 bytes) using SSL/TLS.
(20:00:12) [i] (User Abort)
(20:00:12) [glftpd] ABOR
(20:00:12) [io744] ABOR
(timeout)

ioftpd-watch.exe just sits there doing nothing, and manual restart needed. And nothing in logs as usual.
pion is offline   Reply With Quote
Old 04-22-2010, 02:07 PM   #29
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

I'll add some more debugging for you pion... But what you are seeing is not the hardcore lockup bug else it would be caught after like 3 minutes. Does "site crashnow" work for you when your connected but it won't do stuff? I forget if you answered that one already.

o_dog: It should timeout after 20 seconds without a connection happening. It will not however timeout a connection that sends REALLY slow. But I think 10 minutes without any data at all and it does. I remember it being rather long.
Yil is offline   Reply With Quote
Old 04-22-2010, 02:54 PM   #30
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

site crashnow doesn't produce any dumps, or restart site. At the latest crash I had just now, I was able to log in once, and one session even responded to ABOR. But after login+ABOR, no new sessions where accepted. The first thread that hanged, was still dead. Site crashnow did nothing.

It's a pain to debug it, since I have to catch it at the excact couple of minutes it's crashing to be able to issue commands. Would be very helpful to be able to crash/debug externally, for when io stops accepting connections.. which is multiple times a day on some boxes
pion is offline   Reply With Quote
Reply

Tags
case, dir, experimental, ioftpd, link

Thread Tools
Display Modes Rate This Thread
Rate This Thread:

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off

Forum Jump


All times are GMT -5. The time now is 08:17 AM.

Parts of this site powered by vBulletin Mods & Addons from DragonByte Technologies Ltd. (Details)