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-08-2010, 06:46 AM   #46
Silly
Junior Member
ioFTPD Registered User
 
Join Date: Oct 2003
Posts: 27
Default

just upgraded....let's see...how's it going..
Silly is offline   Reply With Quote
Old 04-08-2010, 10:02 AM   #47
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

o_dog: I took a look around and didn't see anything obvious. It looked like all possible paths ended up resetting the flag no matter how the connection ended. The only suspicious thing I saw was the race condition on the bit field that could only occur if your client timed it out and tried to abort it which I presume you would see in the logs. I fixed that possibility in the 7.3.2 release just in case. If you're using that or newer and it's still happening I can always gin up a special debug version to record some info to the debug log or you can generate minidumps.

Can you double check that your client didn't try to abort the transfer on it's own before it got stuck? And upgrade to 7.3.3 to rule out the race condition I fixed.
Yil is offline   Reply With Quote
Old 04-08-2010, 10:12 AM   #48
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

Yil; I tried your extra service configuration, but I had some problems with it. I copied the existing ftp service, renamed it, and change port, then added that Active_Services. At some point it appeared that only the latest service got loaded, essentially only opening one port. I also had problems getting the service to allow connections alltogether, also after reverting config, as if some bindings where still active. Reverting, manually killing the ioftpd.exe process, wait for a few, then starting it again appears to get things back to normal.

It's likely that the above problems is entirely my fault, however I find it curious that nothing (at all) showed up in logs when attempting to start ioftpd.exe. I could clearly see the process running, and spawning ioftpd-watch.exe - but not able to log in, and nothing is written in logs, not even startup events.
pion is offline   Reply With Quote
Old 04-08-2010, 01:09 PM   #49
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

pion: I've seen once or twice locally and had people tell me they would start the server and not be able to connect to it, but restarting it fixed it so it wasn't a .ini file issue. I scratched my head since everything looked OK at first glance when I got it into the debugger but then I got the idea it might have something to do with the scheduler race condition on startup so I fixed that. If you see that problem again and you aren't playing with the config file let me know as it means the problem is still in there...

"Added" Active_Services? You mean replaced/modified the line under [Network] that was already there? If you can login you can use "site services" to see a list of configured services and their status. Use "site devices" to see configured devices although you won't need multiple of those since services can share them.
Yil is offline   Reply With Quote
Old 04-09-2010, 08:22 AM   #50
monk-
Member
 
Join Date: Oct 2007
Posts: 32
Default

i also have problems with io just hanging at the startup
i figured out its hangs on directory caching
im used to putting all paths in the default.vfs
but with these hangs, it seams nessesary to disable cache on some paths

edit: i think it hangs on paths that are already cached
like:
"W:\FTP\MP3-ARCHIVE\OLDIES" /MP3-ARCHIVE/OLDIES
"w:" /STAFF/PROGRAMME/_HDD/W-drive
etc

and another question: is it possible to surpress log errors/warnings like: VFS WARNING: file '..\etc\default.vfs', line #59 has a real path that is invalid (error = No such file or directory): "y:" /STAFF/PROGRAMME/_HDD/Y-drive




edit2: hmm, i thought it would be anough to only put the sections in a seperate vfs file, and remove them from default.vfs
but then the sections dont show up on ftp
so now i wonder what the function is of this extra vfs file, when paths dont get loaded to the ftp anyway

Last edited by monk-; 04-09-2010 at 09:21 AM.
monk- is offline   Reply With Quote
Old 04-09-2010, 08:56 AM   #51
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

Startup bug appears to be more severe that I thought. I now have it on configs that has been static. ioftpd.exe is running and spawn ioftpd-watch.exe after a few seconds. I can also see io steadily growing in memory size for a few minutes, I'm guessing this is directory cache? After it reaches some final memory consumption it just sits there doing nothing. Not writing logs, not accepting connections.

Error.log are created showing: 04-09-2010 16:19:31 Unable to open/parse pre-load VFS file: ../etc/sections.vfs
04-09-2010 16:19:31 VFS WARNING: file '..\etc\default.vfs', line #45 has a real path that is invalid (error = No such file or directory): "mylocation" /mylocation

ioFTPD.log:
04-09-2010 16:19:31 PRELOAD: "begin" "..\etc\default.vfs"
04-09-2010 16:19:31 PRELOAD: "points=29" "..\etc\default.vfs"
04-09-2010 16:19:47 SSL: "Found certificate" "name=aaaa" "Service=FTP_Service" "(Certificate_name)"
04-09-2010 16:19:47 START: "PID=2836" "CmdLine="

nxMyDb.log:
04-09-2010 16:19:32 ------------------------------------------------------------

and that's it. No more logs to debug what's going on

Using io 7.3.3


I tried creating an empty file called sections.vfs - but same error came in log, however the ftpd started :S Looks somewhat random

Last edited by pion; 04-09-2010 at 09:34 AM.
pion is offline   Reply With Quote
Old 04-09-2010, 09:50 AM   #52
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

Thanks for the observation. I'll take a quick look at the directory caching during preloading stuff which during startup is handled a little differently because the server isn't actually entirely configured at that point. It's possible I missed something being initialized and that's where the randomness is coming from.

I'll also add an option to completely disable it in the next build to see if that makes a difference as well.
Yil is offline   Reply With Quote
Old 04-09-2010, 12:07 PM   #53
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

04-09-2010 17:02:23 Color #2 bad in .ini theme: '+ 2 Light-Full -1 2 2 2 -1 -1 -1 -1 -1 -1 2 2 2 2 2 2 2 2 2 -1 -1 -1 -1 -1 -1 -1 -1 5000 -1 5000 -1 5000 -1 5047 1 5 6 3 -1 -1 -1 -1 -1 -1 -1 -1 2 2 -1 -1 2'
04-09-2010 17:06:42 VFS WARNING: file '..\etc\default.vfs', line #28 has a real path that is invalid (error = No such file or direct..

I'm assuming it's directory caching taking so much time?
Is it possible to speed up that directory caching by specifying max folder depth or set some max execution time or similar? That time is on a core2 system with plenty free ram, and idle disk IO..

Basicly the problem is that the server is refusing any connection until that VFS WARNING log entry is written
pion is offline   Reply With Quote
Old 04-09-2010, 01:59 PM   #54
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

Not sure if this is nxMyDb or ioftpd problem, but I've seen groups disappear for no aparent reason, and the user is left in NoGroup. Anyone else seen this problem?
pion is offline   Reply With Quote
Old 04-09-2010, 02:39 PM   #55
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

Server stopping to accept files: Site 1 = drftpd, site2 = io 7.0.3


(21:17:05) [Site2] MKD /Mydir
(21:17:06) [Site2] 257 "/Mydir" created.
(21:17:06) [Site2] CWD /Mydir
(21:17:06) [Site2] 250 CWD command successful.
(21:17:06) [Site2] PWD
(21:17:06) [Site2] 257 "/Mydir" is current directory.
(21:17:06) [Site2] STAT -l
(21:17:06) [Site2] List Complete: 33 bytes in 0,11 seconds (0,30KB/s)
(21:17:06) [Site1] PRET RETR my.sfv
(21:17:06) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:06) [Site1] CPSV
(21:17:06) [Site1] 227 Entering Passive Mode (1,1,1,1,165,166).
(21:17:06) [Site2] PORT 1,1,1,1,165,166
(21:17:06) [Site2] 200 PORT command successful.
(21:17:06) [Site2] STOR my.sfv
(21:17:06) [Site2] 150 Opening ASCII mode data connection for my.sfv using SSL/TLS.
(21:17:06) [Site1] RETR my.sfv
(21:17:07) [Site1] 150 File status okay; about to open data connection from SLAVE1.
(21:17:17) [Site1] 426- Read timed out
(21:17:17) [Site1] 426 Read timed out
(21:17:17) [Site1] PRET RETR my.sfv
(21:17:17) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:17) [Site1] CPSV
(21:17:17) [Site1] 227 Entering Passive Mode (1,1,1,1,165,108).
(21:17:17) [Site2] PORT 1,1,1,1,165,108
(21:17:17) [Site2] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(21:17:17) [Site1] PRET RETR my.sfv
(21:17:17) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:17) [Site1] CPSV
(21:17:18) [Site1] 227 Entering Passive Mode (1,1,1,1,164,93).
(21:17:18) [Site2] PORT 1,1,1,1,164,93
(21:17:18) [Site2] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(21:17:18) [Site1] PRET RETR my.sfv
(21:17:18) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:18) [Site1] CPSV
(21:17:18) [Site1] 227 Entering Passive Mode (1,1,1,1,166,82).
(21:17:18) [Site2] PORT 1,1,1,1,166,82
(21:17:18) [Site2] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(21:17:18) [Site1] PRET RETR my.sfv
(21:17:18) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:18) [Site1] CPSV
(21:17:18) [Site1] 227 Entering Passive Mode (1,1,1,1,167,198).
(21:17:18) [Site2] PORT 1,1,1,1,167,198
(21:17:18) [Site2] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(21:17:18) [Site1] PRET RETR my.sfv
(21:17:19) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:19) [Site1] CPSV
(21:17:19) [Site1] 227 Entering Passive Mode (1,1,1,1,165,180).
(21:17:19) [Site2] PORT 1,1,1,1,165,180
(21:17:19) [Site2] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(21:17:19) [Site1] PRET RETR my.sfv
(21:17:19) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:19) [Site1] CPSV
(21:17:19) [Site1] 227 Entering Passive Mode (1,1,1,1,165,218).
(21:17:19) [Site2] PORT 1,1,1,1,165,218
(21:17:19) [Site2] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(21:17:19) [Site1] PRET RETR my.sfv
(21:17:19) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:19) [Site1] CPSV
(21:17:19) [Site1] 227 Entering Passive Mode (1,1,1,1,165,123).
(21:17:19) [Site2] PORT 1,1,1,1,165,123
(21:17:19) [Site2] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(21:17:20) [Site1] PRET RETR my.sfv
(21:17:20) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:20) [Site1] CPSV
(21:17:20) [Site1] 227 Entering Passive Mode (1,1,1,1,165,42).
(21:17:20) [Site2] PORT 1,1,1,1,165,42
(21:17:20) [Site2] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(21:17:20) [Site1] PRET RETR my.sfv
(21:17:20) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:20) [Site1] CPSV
(21:17:20) [Site1] 227 Entering Passive Mode (1,1,1,1,167,125).
(21:17:20) [Site2] PORT 1,1,1,1,167,125
(21:17:20) [Site2] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(21:17:21) [Site1] PRET RETR my.sfv
(21:17:21) [Site1] 200 OK, will use SLAVE1 for upcoming transfer
(21:17:21) [Site1] CPSV
(21:17:21) [Site1] 227 Entering Passive Mode (1,1,1,1,166,158).
(21:17:21) [Site2] PORT 1,1,1,1,166,158
(21:17:21) [Site2] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(21:17:21) [Site1] PRET RETR my.sfv
(21:17:21) [Site1] 200 OK, will use SLAVE1 for upcoming transfer


In addition to this, the server site2 is no longer working with PASV (timeout). So no transfers possible at all.. the ABOR message, sticks around for about 5s before it aparently timeout.

I can log in and out, resulting in the same behaviour.

Now if I restart the ioftpd.exe service all transfers behave proper again (both PORT and PASV).

(as a note, waiting 3-5 minutes for io to start (dir caching?) is a real pain for debugging)

I didn't think about issuing 'site crashnow' - but if it happends again I'll do that also
pion is offline   Reply With Quote
Old 04-09-2010, 02:49 PM   #56
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

SystemError.log: 04-09-2010 21:46:59 Error converting string: /dir/subdir <-- Where is this error from? How to avoid it?
pion is offline   Reply With Quote
Old 04-09-2010, 05:02 PM   #57
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

I finally managed to catch some events leading up to hangup now:

THREAD 1:
(21:51:29) [site] 200 Type set to A.
(21:51:29) [site] PASV
(21:51:29) [site] 227 Entering Passive Mode (1,1,1,1,55,97)
(21:51:29) [site] Opening data connection IP: 1.1.1.1 PORT: 14177
(21:51:29) [site] LIST
(21:51:29) [site] 150 Opening ASCII mode data connection for directory listing using SSL/TLS.

THREAD 2:
(22:43:52) [site] TYPE A
(22:43:52) [site] 200 Type set to A.
(22:43:52) [site] PASV
(22:43:52) [site] 227 Entering Passive Mode (1,1,1,1,67,196)
(22:43:52) [site] Opening data connection IP: 1.1.1.1 PORT: 17348
(22:43:52) [site] LIST
(22:43:52) [site] 150 Opening ASCII mode data connection for directory listing using SSL/TLS.

Thread 1 had a successful transfer just before the hanging dir list.
Thread 2 had one successful transfer at 22:54 which is AFTER thread 1 got stuck. After that, I don't have any successful transfers. In addition, thread had some

(22:43:30) [site] Can't open data connection
(22:43:30) [site] 426 Connection closed: Connection timed out.

entries on list BEFORE it hanged completely

After that command it hanged for 2 and 1 hours consequently, until I now aborted them both manually in client. No new connections are accepted to the site, and I am unable to send any additional commands. ioftpd.exe is running, without any hints it's crashed/hanged/locked up. This is io 7.0.3
pion is offline   Reply With Quote
Old 04-09-2010, 06:23 PM   #58
o_dog
Senior Member
 
Join Date: May 2007
Posts: 692
Default

pion: same error that i got. the 550 one
__________________
ioNiNJA
o_dog is offline   Reply With Quote
Old 04-10-2010, 12:24 PM   #59
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

Another crash/hangup/lockup where IO was dropping all connections more or less at once:

I had the following three threads connected:

IO -> IO

(19:06:05) [i] [IO_703 -> IO_703] myfile1.r02 4,3 Mbytes/8,41(s)/814,95Kbps
(19:06:05) [IO_703] CPSV
(19:06:05) [IO_703] 227 Entering Passive Mode (1,1,1,1,59,178)
(19:06:05) [IO_703] PORT 1,1,1,1,59,178
(19:06:05) [IO_703] 200 PORT command successful.
(19:06:05) [IO_703] STOR myfile1.r01
(19:06:05) [IO_703] 150 Opening BINARY mode data connection for myfile1.r01 using SSL/TLS.
(19:06:05) [IO_703] RETR myfile1.r01
(19:06:06) [IO_703] 150 Opening BINARY mode data connection for myfile1.r01 (14648 bytes) using SSL/TLS.
(19:06:22) [IO_703] 426 Connection closed: The specified network name is no longer available.
(19:06:22) [IO_703] CPSV
(19:06:22) [IO_703] 227 Entering Passive Mode (1,1,1,1,63,77)
(19:06:22) [IO_703] CPSV
(19:06:22) [IO_703] 227 Entering Passive Mode (1,1,1,1,64,179)
(19:06:22) [IO_703] CPSV
(19:06:22) [IO_703] 227 Entering Passive Mode (1,1,1,1,67,161)
(19:06:22) [IO_703] Connecting to IO_703
(19:06:22) [IO_703] Resolving IO_703.dns.com...
(19:06:22) [IO_703] IO_703.dns.com => 2.2.2.2
(19:06:22) [IO_703] Connecting to 2.2.2.2:21
(19:06:22) [IO_703] Connection Reset by Peer(10054)


DR -> IO

(19:05:25) [i] [DRFTPD -> IO_703] myfile2.r45 4,3 Mbytes/3,91(s)/442,39Kbps
(19:05:25) [DRFTPD] PRET RETR myfile2.r44
(19:05:25) [DRFTPD] 200 OK, will use master for upcoming transfer
(19:05:25) [DRFTPD] CPSV
(19:05:25) [DRFTPD] 227 Entering Passive Mode (1,1,1,1,119,108).
(19:05:25) [IO_703] PORT 1,1,1,1,119,108
(19:05:26) [IO_703] 200 PORT command successful.
(19:05:26) [IO_703] STOR myfile2.r44
(19:05:26) [IO_703] 150 Opening BINARY mode data connection for myfile2.r44 using SSL/TLS.
(19:05:26) [DRFTPD] RETR myfile2.r44
(19:05:26) [DRFTPD] 150 File status okay; about to open data connection from master.
(19:06:21) [DRFTPD] 426- Connection reset by peer: socket write error
(19:06:21) [DRFTPD] 426 Connection reset by peer: socket write error
(19:06:21) [DRFTPD] PRET RETR myfile2.r44
(19:06:21) [DRFTPD] 200 OK, will use master for upcoming transfer
(19:06:21) [DRFTPD] CPSV
(19:06:21) [DRFTPD] 227 Entering Passive Mode (1,1,1,1,125,249).
(19:06:21) [IO_703] Connecting to IO_703
(19:06:21) [IO_703] Resolving IO_703.dns.com...
(19:06:21) [IO_703] IO_703.dns.com => 2.2.2.2
(19:06:21) [IO_703] Connecting to 2.2.2.2:21
(19:06:21) [IO_703] Connection Reset by Peer(10054)



Moving directory

(19:04:56) [IO_703] RNFR Subdir
(19:04:56) [IO_703] 350 Directory exists, ready for destination name.
(19:04:56) [IO_703] RNTO /ROOT/Mydir/Subdir
(19:04:56) [IO_703] 250 RNTO command successful.
(19:04:56) [IO_703] PASV
(19:04:57) [IO_703] 227 Entering Passive Mode (2,2,2,2,60,17)
(19:04:57) [IO_703] Opening data connection IP: 2.2.2.2 PORT: 15377
(19:04:57) [IO_703] LIST
(19:04:57) [IO_703] 150 Opening ASCII mode data connection for directory listing using SSL/TLS.
(19:04:57) [IO_703] Encryption algorithm: TLSv1 DES-CBC3-SHA-168
(19:04:59) [IO_703] 226-[UL: 1GB] [DL: 1GB] [Speed: 1.3KB/s] [Free: 1MB]
(19:04:59) [IO_703] 226 [Section: DEFAULT] [Credits: 150.0MB] [Ratio: Leech]
(19:04:59) [IO_703] List Complete: 3*129 bytes in 0,47 seconds (10,67KB/s)
(19:05:05) [IO_703] CWD .
(19:05:06) [IO_703] 250 CWD command successful.
(19:05:06) [IO_703] PWD
(19:05:06) [IO_703] 257 "/ROOT" is current directory.
(19:05:11) [IO_703] RNFR Subdir3
(19:05:11) [IO_703] 350 Directory exists, ready for destination name.
(19:05:11) [IO_703] RNTO /ROOT/Mydir3/Subdir3
(19:05:12) [IO_703] 250 RNTO command successful.
(19:05:12) [IO_703] PASV
(19:05:12) [IO_703] 227 Entering Passive Mode (2,2,2,2,56,136)
(19:05:12) [IO_703] Opening data connection IP: 2.2.2.2 PORT: 14472
(19:05:12) [IO_703] LIST
(19:05:12) [IO_703] 150 Opening ASCII mode data connection for directory listing using SSL/TLS.
(19:05:15) [IO_703] Encryption algorithm: TLSv1 DES-CBC3-SHA-168
(19:05:16) [IO_703] 226-[UL: 1GB] [DL: 1GB] [Speed: 1KB/s] [Free: 1MB]
(19:05:16) [IO_703] 226 [Section: DEFAULT] [Credits: 1MB] [Ratio: 1]
(19:05:16) [IO_703] List Complete: 72*984 bytes in 0,56 seconds (74,77KB/s)
(19:05:36) [IO_703] CWD .
(19:05:36) [IO_703] 250 CWD command successful.
(19:05:36) [IO_703] PWD
(19:05:36) [IO_703] 257 "/ROOT" is current directory.
(19:05:51) [IO_703] CWD .
(19:05:51) [IO_703] 250 CWD command successful.
(19:05:51) [IO_703] PWD
(19:05:51) [IO_703] 257 "/ROOT" is current directory.
(19:06:06) [IO_703] CWD .
(19:06:06) [IO_703] 250 CWD command successful.
(19:06:06) [IO_703] PWD
(19:06:06) [IO_703] 257 "/ROOT" is current directory.
(19:06:17) [IO_703] RNFR Subdir2
(19:06:18) [IO_703] 350 Directory exists, ready for destination name.
(19:06:18) [IO_703] RNTO /ROOT/Mydir2/Subdir2
(19:06:21) [IO_703] Connecting to IO_703
(19:06:21) [IO_703] Resolving IO_703.dns.com...
(19:06:21) [IO_703] IO_703.dns.com => 2.2.2.2
(19:06:21) [IO_703] Connecting to 2.2.2.2:21
(19:06:21) [IO_703] Connection Reset by Peer(10054)


Notice the timestamps, where io decided to just drop all connections, and not allow any new ones to be made..

*Edit: After some minutes, io was back on again - and it had created a crashlog - so now there's something to debug!
pion is offline   Reply With Quote
Old 04-10-2010, 01:24 PM   #60
Zer0Racer
Senior Member
ioFTPD Scripter
 
Join Date: Oct 2002
Posts: 703
Default

What is the point in spamming logs from v7.0.3 when there a newer versions? Have you tried upgrading?
Zer0Racer is offline   Reply With Quote
Reply

Tags
application, bug, download, fix, nxmydb

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 11:30 PM.

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