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-25-2010, 03:01 PM   #46
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

Flow: Well, creating the .cache type files would be optional of course. It would also only happen when a configurable threshold of say 100 subdirs were in a directory which would mean it wouldn't happen for most dirs just large daily dirs or something like /XVID. This is far trickier than the start/stop cache bit anyway because you wouldn't want to update these .cache files on every change, but say every 15 minutes if there had been any changes to the dir...

Update, I see your trailer says 7.4.3. How's it working for you?
Yil is offline   Reply With Quote
Old 04-25-2010, 03:24 PM   #47
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

This box use 5 minutes+ before allowing connections

(22:02:14) [io_745] 200- Buckets (num=100, size=1000):
(22:02:14) [io_745] 200- 37 39 46 50 37 48
(22:02:14) [io_745] 200- 42 53 45 34 52 47
(22:02:14) [io_745] 200- 42 56 45 45 45 49
(22:02:14) [io_745] 200- 33 48 55 49 38 47
(22:02:14) [io_745] 200- 53 43 45 46 35 37
(22:02:14) [io_745] 200- 46 50 44 41 50 52
(22:02:14) [io_745] 200- 62 53 39 42 48 48
(22:02:14) [io_745] 200- 52 45 41 47 46 40
(22:02:14) [io_745] 200- 36 52 55 39 44 52
(22:02:14) [io_745] 200- 35 57 58 49 48 48
(22:02:14) [io_745] 200- 49 44 61 55 51 50
(22:02:14) [io_745] 200- 41 47 50 47 34 54
(22:02:14) [io_745] 200- 35 49 59 50 45 48
(22:02:14) [io_745] 200- 51 51 51 50 41 46
(22:02:14) [io_745] 200- 56 50 39 64 48 38
(22:02:14) [io_745] 200- 45 39 51 43 44 47
(22:02:14) [io_745] 200- 46 49 52 46
(22:02:14) [io_745] 200-
(22:02:14) [io_745] 200- Total: Dirs = 4676, InUse = 0, Locked = 0, Shared = 0
(22:02:14) [io_745] 200- Total: FileInfos = 173337, InfosUsed = 0, NoInfo = 0
(22:02:14) [io_745] 200 'dircache' Command successful.

I fail to attach to process on two different boxes, one where I had AV installed (tried to remove without success), and one without. Both places I also fail to start it using "open executable". io never starts proper, nor spawn ioftpd-watch.exe, and they both crash right away (refuse to allow any connections) when I attach to process.
pion is offline   Reply With Quote
Old 04-25-2010, 03:35 PM   #48
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

100 buckets of 1000 length and your length is 70ish tops. Nothing being flushed from the cache, it's fine. The real piece of info is the total FileInfos in use though. Perhaps I should separate out file, directory, and fake dir fileinfos into multiple counters so we can get a better handle on what is going on. If it's mostly dirs and fake dirs then 100K directory opens under windows is going to take a bit no matter what but I would have guess more like a minute or two...

What kind of machine is this? Are these just plain drives? Not remote filesystems? This whole thing isn't running inside a VM? Drives aren't truecrypted? How much memory is in the machine?
Yil is offline   Reply With Quote
Old 04-25-2010, 03:37 PM   #49
Flow
Senior Member
FlashFXP Beta Tester
ioFTPD Foundation User
 
Flow's Avatar
 
Join Date: Dec 2001
Posts: 306
Default

Yil, is a clean 7.4.3 version with 2 script addon. nxTools and nxHelp. Right now im satisfied with no complains

Are thare anymore biggies to be fixed till -stable release? I feel like after this lockup SSL buggsquash hunt is over would be a time for a development line. Maybe you could posibly re-open the ioYil case again?
Flow is offline   Reply With Quote
Old 04-25-2010, 04:20 PM   #50
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

Flow: I'm REALLY hoping that this switch to OpenSSL will fix the loader lock problem. I'm not aware of any other showstopping issues like that left in the plain no-addon server configuration. In fact I think nxTools and ioNiNJA are pretty happy these days as well. Pion's nxMyDB troubles from libmysql is annoying because I was hoping to offer MySQL as an option in ioYil for larger sites so I really do have an incentive to figure out what is going on...
Yil is offline   Reply With Quote
Old 04-26-2010, 02:47 AM   #51
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

Athlon XP 2600+ on 512 ram, but I've never seen io take up more than 80mb?. The harddrives are new sata in a hardware raid5 array.

I tried turning off SSL for nxmydb in config, and I hit another error:

(09:33:59) [io_745] CPSV
(09:33:59) [io_745] 226-Transferred: 0.
(09:33:59) [io_745] 426 Connection closed: Connection timed out.
(09:33:59) [io_745] 226 ABOR command successful.
(09:33:59) [io_745] 227 Entering Passive Mode (1,1,1,1,60,255)
(09:33:59) [glftpd] PORT 1,1,1,1,60,255
(09:33:59) [glftpd] 200 PORT command successful.
(09:33:59) [io_745] STOR file21.rar
(09:33:59) [io_745] 150 Opening BINARY mode data connection for file21.rar using SSL/TLS.
(09:33:59) [glftpd] RETR file21.rar
(09:34:00) [glftpd] 150 Opening BINARY mode data connection for file21.rar (15000000 bytes) using SSL/TLS.
(09:34:19) [glftpd] 435 Failed TLS negotiation on data channel (using SSL_accept()), disconnected: Connection reset by peer.
(09:34:19) [glftpd] Reversed FXP started
(09:34:19) [io_745] CPSV
(09:34:19) [io_745] 226-Transferred: 0.
(09:34:19) [io_745] 426 Connection closed: Connection timed out.
(09:34:19) [io_745] 226 ABOR command successful.
(09:34:19) [io_745] 227 Entering Passive Mode (1,1,1,1,65,229)
(09:34:19) [glftpd] PORT 1,1,1,1,65,229
(09:34:19) [glftpd] 200 PORT command successful.
(09:34:19) [io_745] STOR file21.rar
(09:34:20) [io_745] 150 Opening BINARY mode data connection for file21.rar using SSL/TLS.
(09:34:20) [glftpd] RETR file21.rar
(09:34:20) [glftpd] 150 Opening BINARY mode data connection for file21.rar (15000000 bytes) using SSL/TLS.
(09:34:39) [glftpd] 435 Failed TLS negotiation on data channel (using SSL_accept()), disconnected: Connection reset by peer.

then io hanged like the lockup bug. The weird part about this, is that it hanged more or less excactly at the same time I logged in through remote desktop to look up box details.. most likely random, but the process is really stuck like always. And windbg is having trouble connecting:

Break-in sent, waiting 30 seconds...
WARNING: Break-in timed out, suspending.
This is usually caused by another thread holding the loader lock

But I was able to connect and create a dump after. I also noticed io eating up 30mb more ram when I ran the dump, I've seen it before also.. is it supposed to do that? And io implodes, and process dies when I shut down windbg again. That happends regardless of what state the ioftpd.exe process is in atm.
pion is offline   Reply With Quote
Old 04-26-2010, 11:50 AM   #52
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

pion: Is App Verifier running and all the options it can check enabled? I'd really like to see if it's spotting something...

Regarding extra memory usage during dumps... Most processes in the computer don't have all their pages in memory all the time. Unused or rarely used memory pages are swapped to disk to make room for more commonly used pages in other applications. The size of the memory used by looking at the default "memory" column in task manager is not the applications true size. There are at least 5 ways to measure memory but committed pages should be closest to its complete memory footprint. So what happens when you create a dump? You have to write to the dump file all the memory of the process which means the system will swap in all those unused pages from disk and even the shared .dll files. Thus the memory footprint during dump creation is essentially it's committed size and would appear to you to be growing if you just looked at task manager's default column. On a low memory computer it might actually have to swap in some pages and out some already written pages so it's memory size might never equal it's commit size at any point in time, but trust me it would if it could.

During the generation of CrashLog.txt however ioFTPD loads parts of the .pdb files so it can print function names instead of memory addresses on the stack traces. So it's true that it also consumes more memory during dump generation from within ioFTPD. This should not happen when done via windbg or any other debugger though.

I'll have to look into why windbg is having issues connecting to the process. It's interesting to me that it mentions the loader lock, but obviously it isn't completely stuck as that should be caught now. I should also point out that if the loader lock really was stuck we would see that by doing an analysis of the dumpfile and this is not the case in any of your dumps thus far unlike other people who really did have this problem.

My guess is this is a windows socket/handle problem. ioFTPD could be doing something wrong and I'll try and review the code, but Application Verifier should be the first line of attack to determine this... It's also possible my attempt to fix libmysql didn't work or I missed something.
Yil is offline   Reply With Quote
Old 04-26-2010, 12:53 PM   #53
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

I might add that ioftpd hangs with ssl disabled in nxmydb config aswell.

I was having some problems with application verifier. I couldn't get io started proper due to io taking up all the ram on the box (about 400mb, and then it started paging), so I decided to kill the process. I tried it on a faster box, there it has the same behaviour, but the process dies during startup.. it does however spawn ioftpd-watch.exe, and start consuming ram, before it dies.

Last edited by pion; 04-26-2010 at 01:35 PM.
pion is offline   Reply With Quote
Old 04-26-2010, 05:51 PM   #54
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

Application verifier with some of the memory features enables does dramatically increase the application's memory footprint. You can try turning off some of the memory related settings and it should make far less of an impact...
Yil is offline   Reply With Quote
Old 04-27-2010, 07:04 AM   #55
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

All the boxes I've tried it on behaves somewhat the same, by crashing. So not really easy to debug :P
pion is offline   Reply With Quote
Old 04-27-2010, 10:35 AM   #56
Yil
Too much time...
FlashFXP Beta Tester
ioFTPD Administrator
 
Join Date: May 2005
Posts: 1,194
Default

Hey pion, I've got something for you to try.

Can you see if Log_Exiting_Worker_Threads under [Threads] is enabled, and if not enable it. Then check the debug log to see if you see any "Worker exit: ..." lines. I noticed you only had 5 worker threads and under load that might not be enough (don't change that number now, let's test first). If we find that threads are exiting then that gives me an idea of some things to look into. I already fixed a bug in the original timer design that broke if threads exited...
Yil is offline   Reply With Quote
Old 04-27-2010, 12:13 PM   #57
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

I'll enable it. I also got a couple of crashlogs, but ran out of space when writing them.. anyhow I uploaded what I got, in addition to some dumps using windbg.
pion is offline   Reply With Quote
Old 04-28-2010, 02:22 AM   #58
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

04-27-2010 22:44:07 Worker exit: total=5, free=5, blocking=0, initial=5.
04-27-2010 23:06:35 AsyncSelectCancel flags: 0
04-27-2010 23:37:46 Worker exit: total=5, free=5, blocking=0, initial=5.
..
04-27-2010 22:59:00 Worker exit: total=5, free=5, blocking=0, initial=5.
04-27-2010 22:59:24 AsyncSelectCancel flags: 0
04-27-2010 22:59:34 AsyncSelectCancel flags: 0
04-27-2010 23:01:16 Worker exit: total=5, free=5, blocking=0, initial=5.
04-27-2010 23:02:28 error:14094417:SSL routines:SSL3_READ_BYTES:sslv3 alert illegal parameter
04-27-2010 23:02:39 error:14094417:SSL routines:SSL3_READ_BYTES:sslv3 alert illegal parameter
04-28-2010 00:32:53 Worker exit: total=5, free=4, blocking=0, initial=5.
04-28-2010 00:40:27 Worker exit: total=5, free=4, blocking=0, initial=5.

Also got some new symptoms on lockup bug. It transferred 0 on all transfers, but still appeared to accept the connection. When connecting windbg I got:

WARNING: Break-in timed out, suspending.
This is usually caused by another thread holding the loader lock

then after a minute or two it connected, and I was able to create a dump. After creating dump with windbg, it locked up completely denying login, and implode after I exit windbg as usual.

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

pion: I might have forgot to mention this last time, but if you just exit windbg the process you attached to will exit as well. You need to detach from it to allow it to continue running. There might not be much point in doing that, since the process might be unstable and may have timed out transfers, users, etc, but thought I'd mention the most likely reason for what you were seeing when you exit windbg.

Now that we know that 5 worker threads is too small for you (I was sure it was but wanted proof) go ahead and bump that up to 10 or 15 and see if that makes a difference. Besides consuming a little more memory, it's probably going to be faster for you since the TCL interpreter on the extra thread you appear to need from time to time won't have to keep being created/destroyed.

I still need to put together the test for inherited handles as well. Turns out it was a bit trickier than I thought and I need to install the window's driver kit to do it.
Yil is offline   Reply With Quote
Old 04-29-2010, 04:26 AM   #60
pion
Senior Member
 
Join Date: Feb 2006
Posts: 138
Default

Some new symptoms on hangup: It appeared to happend just as I was compressing the dumpfile, using 100% cpu.. low resource emulation could be something to try, to reproduce?

(11:23:26) [io745] 211 END
(11:23:26) [io745] CLNT FTPRush 1.1.2.19U
(11:23:26) [io745] 200 Noted.
(11:23:26) [io745] PWD
(11:23:26) [io745] 257 "/" is current directory.
(11:23:26) [io745] CWD /mydir/
(11:23:26) [io745] 250 CWD command successful.
(11:23:26) [io745] PWD
(11:23:26) [io745] 257 "/mydir" is current directory.
(11:23:26) [io745] STAT -l
(11:23:26) [io745] List Complete: 1*121 bytes in 0,08 seconds (14,37KB/s)
(11:23:26) [io745] SITE XDUPE 3
(11:23:26) [io745] 200-Extended dupe mode 3 is enabled.
(11:23:26) [io745] 200 Command successful.
(11:23:26) [io745] TYPE I
(11:23:26) [io745] 200 Type set to I.
(11:23:26) [io745] PASV
(11:23:26) [io745] 227 Entering Passive Mode (1,1,1,1,55,147)
(11:23:26) [io745] REST 0
(11:23:26) [io745] 350 Restarting at 0. Send STORE or RETRIEVE to initiate transfer.
(11:23:26) [io745] RETR ioftpd745_hanged_up_state.rar
(11:23:28) [io745] 150 Opening BINARY mode data connection for ioftpd745_hanged_up_state.rar (24619924 bytes) using SSL/TLS.
(11:23:42) [io745] ABOR
(11:23:42) [io745] Can't open data connection
(11:23:42) [io745] PASV
(11:23:42) [io745] 550-Init: 1, Aborted: 1, Socket: -1, LastError: 20500, Size: 24619924, Pos: 240518168576
(11:23:42) [io745] 550 Active transfer in progress, terminate transfer with ABOR before proceeding.
(11:23:42) [io745] Connecting to io745
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 04:11 AM.

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