/
Bugzilla – Bug 3131
Session process uses 100% CPU after aborted transfer
Last modified: 2008-11-21 00:58:28 UTC
proftpd session process rises to 100% cpu after ABOR command while downloading. ftpsrv# proftpd -v ProFTPD Version 1.3.2rc3 ftpsrv# uname -a FreeBSD ftpsrv 7.1-PRERELEASE FreeBSD 7.1-PRERELEASE #1: Tue Nov 11 10:29:42 MSK 2008 root@ftpsrv:/usr/src/sys/amd64/compile/INFY_FTP amd64 Nov 11 19:30:00 ftpsrv proftpd[1899] ftpsrv (192.168.159.82[192.168.159.82]): FT P session opened. Nov 11 19:30:00 ftpsrv proftpd[1899] ftpsrv (192.168.159.82[192.168.159.82]): Pr eparing to chroot to directory '/pub/ftproot' Nov 11 19:30:00 ftpsrv proftpd[1899] ftpsrv (192.168.159.82[192.168.159.82]): AN ON ftp: Login successful. Nov 11 19:30:49 ftpsrv proftpd[1899] ftpsrv (192.168.159.82[192.168.159.82]): no tice: user ftp: aborting transfer: No such file or directory pid 1899 (proftpd), uid 1001, was killed: exceeded maximum CPU limit
Could you provide your full proftpd.conf, and the output from running `proftpd -V' and `proftpd -l', please?
ftpsrv# proftpd -V Compile-time Settings: Version: 1.3.2rc3 Platform: FREEBSD7 (FREEBSD7_1) Built With: configure '--localstatedir=/var/run' '--sysconfdir=/usr/local/etc' '--disab le-sendfile' '--disable-ipv6' '--enable-nls' '--with-includes=:/usr/local/includ e' '--with-libraries=:/usr/local/lib' '--prefix=/usr/local' '--mandir=/usr/local /man' '--infodir=/usr/local/info/' '--build=amd64-portbld-freebsd7.1' 'build_ali as=amd64-portbld-freebsd7.1' 'CC=cc' 'CFLAGS=-O2 -fno-strict-aliasing -pipe' 'LI BS=-lintl -L/usr/local/lib' 'CXX=c++' 'CXXFLAGS=-O2 -fno-strict-aliasing -pipe' CFLAGS: -O2 -fno-strict-aliasing -pipe -Wall LDFLAGS: -L$(top_srcdir)/lib LIBS: -lintl -lpam -lsupp -lcrypt -lintl -L/usr/local/lib -lutil Files: Configuration File: /usr/local/etc/proftpd.conf Pid File: /var/run/proftpd.pid Scoreboard File: /var/run/proftpd/proftpd.scoreboard Features: - Autoshadow support - Controls support + curses support - Developer support - DSO support - IPv6 support + Largefile support - Lastlog support + ncurses support + NLS support - OpenSSL support - POSIX ACL support - Shadow file suppport - Sendfile support + Trace support Tunable Options: PR_TUNABLE_BUFFER_SIZE = 1024 PR_TUNABLE_GLOBBING_MAX = 8 PR_TUNABLE_HASH_TABLE_SIZE = 40 PR_TUNABLE_NEW_POOL_SIZE = 512 PR_TUNABLE_SCOREBOARD_BUFFER_SIZE = 80 PR_TUNABLE_SCOREBOARD_SCRUB_TIMER = 30 PR_TUNABLE_SELECT_TIMEOUT = 30 PR_TUNABLE_TIMEOUTIDENT = 10 PR_TUNABLE_TIMEOUTIDLE = 600 PR_TUNABLE_TIMEOUTLINGER = 180 PR_TUNABLE_TIMEOUTLOGIN = 300 PR_TUNABLE_TIMEOUTNOXFER = 300 PR_TUNABLE_TIMEOUTSTALLED = 3600 PR_TUNABLE_XFER_SCOREBOARD_UPDATES = 10 ftpsrv# proftpd -l Compiled-in modules: mod_core.c mod_xfer.c mod_auth_unix.c mod_auth_file.c mod_auth.c mod_ls.c mod_log.c mod_site.c mod_delay.c mod_facts.c mod_ident.c mod_auth_pam.c mod_lang.c
# Infinity.Net ProFTPd config ServerName "Infinity.Net FTP server" ServerType standalone DefaultServer on Port 21 #UseIPv6 off Umask 022 SystemLog /var/log/proftpd/proftpd.log #SyslogLevel debug TransferLog /var/log/proftpd/transfer.log WtmpLog off MaxInstances 30 #MaxClientsPerHost 1 MaxTransfersPerHost RETR,APPE,STOR 1 RLimitCPU session 10 10 IdentLookups off ServerIdent on "Infinity FTP server ready." PassivePorts 59152 65534 UseEncoding koi8-r cp1251 UseReverseDNS no TimeoutLinger 30 User nobody Group nogroup DefaultRoot ~ AllowOverwrite on AllowStoreRestart on AllowRetrieveRestart on <Limit SITE_CHMOD> DenyAll </Limit> <Class glnet> From 172.28.65.0/24 </Class> <Class baza> From 172.16.100.0/22 </Class> <Class visp> From 10.0.0.0/8 </Class> <Class infy> From 192.168.128.0/19 </Class> <Class tnet> From 192.168.224.0/19 </Class> <Class voce> From 192.168.192.0/19 </Class> <Class comtel> From 172.16.128.0/21 </Class> <Class default> From 0.0.0.0/0 </Class> TransferRate STOR,APPE,RETR 400 class glnet TransferRate STOR,APPE,RETR 2048 class visp TransferRate STOR,APPE,RETR 5120 class voce TransferRate STOR,APPE,RETR 5120 class infy TransferRate STOR,APPE,RETR 1024 class baza TransferRate STOR,APPE,RETR 2048 class tnet TransferRate STOR,APPE,RETR 5120 class comtel TransferRate STOR,APPE,RETR 512 class default <Anonymous /pub/ftproot> User ftp Group ftp RequireValidShell off UserAlias anonymous ftp MaxClients 30 #DisplayLogin welcome.msg #DisplayChdir .message <Limit WRITE> DenyAll </Limit> <Directory games/!New> <Limit STOR APPE MKD XMKD> AllowClass infy voce </Limit> </Directory> <Directory soft/!New> <Limit STOR APPE MKD XMKD> AllowClass infy voce </Limit> </Directory> <Directory video/!New> <Limit STOR APPE MKD XMKD> AllowClass infy voce </Limit> </Directory> <Directory music/!New> <Limit STOR APPE MKD XMKD> AllowClass infy voce </Limit> </Directory> </Anonymous>
Hmm. While I try to reproduce this issue locally, could you add the following to your proftpd.conf, and send me the generated file from such an abort? TraceLog /path/to/trace.log Trace DEFAULT:10
done.
What happens if you comment out the UseEncoding directive from your proftpd.conf?
Created attachment 2899 [details] Adds handling of Telnet IP, DM codes One thing I noticed in the provided trace logs was that some of the Telnet codes used for aborts (as per RFC) were showing up in the buffer of control connection command data. This shouldn't happen. Specifically, the IAC ("Interpret As Command", value 255/FF), IP ("Interrupt Process, value 244/F4) and DM ("Data Mark", value 242/F2) were showing up. The other Telnet codes that proftpd implements are properly filtered out of that command buffer. This patch, then, adds handling of the IP and DM codes, filtering them out as well. The reason I asked about the UseEncoding directive is that, depending on the charsets requested with that directive, proftpd will NOT handle Telnet codes -- this is especially the case for several common Cyrillic charsets which use a value of 255 to mean something else (other than the Telnet IAC code). Anyway, please try this patch and see what happens, both with and without the UseEncoding directive.
Tryed this patch with several settings: #UseEncoding #TimeoutLinger -> binary mode download abort: session process hangs but does not use 100% cpu, client waits about 30 sec and then says timeout and control connection breaks. -> ASCII mode download abort: session process hangs and uses 100$ cpu, clients waits about 5 sec and says that remote closed control connection. #UseEncoding TimeoutLinger 1 -> binary mode download abort: client wait 1 sec after abort and then work fine, control connection doesnt breaks. -> ASCII mode download abort: session process hangs and uses 100$ cpu, clients waits about 5 sec and says that remote closed control connection. UseEncoding koi8-r cp1251 TimeoutLinger 1 -> binary mode download abort: session process hangs and uses 100$ cpu, clients waits about 15 sec(unix console ftp client) and says that remote closed control connection. -> ASCII mode download abort: session process hangs and uses 100$ cpu, clients waits about 5 sec(vista console ftp client) and says that remote closed control connection. ->Upload abort works fine.
Created attachment 2900 [details] Updates previous patch to explicitly check for aborted downloads in pr_data_xfer() This patch updates the previous one, and adds an explicit check in the pr_data_xfer() function for an aborted transfer. From a process trace I saw, there looked to be an edge case where proftpd could get caught in a tight loop calling select(2), over and over, not writing any data but not knowing to stop polling. This should help in all of the aborted download cases, whether or not it's an ASCII or binary download. It sounds like aborted uploads, ASCII or binary, don't cause the CPU usage spike?
I've applyed new patch and problem looks like not solved for me =( Uploads still ok.
Created attachment 2901 [details] Updates previous patch This patch adds one more check for the 'aborted' flag, in a place where it looks like the CPU spinning *might* be happening. I can't reproduce the CPU usage spike, though, so I'll have to keep supplying patches for trials, for now.
with last patch there are no such cpu spike on abort! but control connection still didnt reply after abort =( ftpsrv# ftp ftp> open localhost Trying ::1... Trying 127.0.0.1... Connected to localhost. 220 Infinity FTP server ready. Name (localhost:root): ftp 331 Anonymous login ok, send your complete email address as your password Password: 230 Anonymous access granted, restrictions apply Remote system type is UNIX. Using binary mode to transfer files. ftp> get 100M local: 100M remote: 100M 229 Entering Extended Passive Mode (|||62768|) 150 Opening BINARY mode data connection for 100M (104857600 bytes) 1% | | 1568 KB 519.99 KB/s 03:13 ETA^ C receive aborted. Waiting for remote to finish abort. 426 Transfer aborted. Data connection closed. ^C 421 Service not available, user interrupt. Connection closed. 1966080 bytes received in 00:41 (45.71 KB/s)
And what with SIGABRT message spam? This issue linked with aborting of transfer too but I can reproduce it only using FTP Drive program... Nov 14 09:23:04 ftpsrv proftpd[67737]: ftpsrv (192.168.222.84[192.168.222.84]) - ProFTPD received SIGABRT signal, no core dump Nov 14 09:23:04 ftpsrv last message repeated 5541 times Nov 14 09:23:04 ftpsrv proftpd[67753]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 09:23:04 ftpsrv proftpd[67737]: ftpsrv (192.168.222.84[192.168.222.84]) - ProFTPD received SIGABRT signal, no core dump Nov 14 09:23:31 ftpsrv last message repeated 1052090 times
Without UseEncoding download abort works perfect with last patch... Even without TimeoutLinger 1
SIGABRT occurs after several ABORTS in FTP Drive session i dont know how but its control session doesnt breaks on abort with UseEncoding, all other clients that i tryed(vista/freebsd console clients and Far Manager) cant do that. Nov 14 10:26:39 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - ANON ftp: Login successful. Nov 14 10:26:39 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:26:39 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:26:40 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:26:41 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:26:48 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:26:49 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:26:51 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:27:35 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:27:35 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:27:35 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:27:36 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:27:39 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:27:42 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:27:42 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:27:43 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:27:44 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:27:45 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:27:45 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:27:48 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:27:48 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:27:49 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:29:49 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:29:50 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:29:50 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:29:56 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:29:56 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:29:57 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:01 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:02 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:33 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:34 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:34 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:34 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:36 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:36 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:37 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:38 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:40 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:40 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:43 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:43 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:44 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:45 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:45 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:46 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:48 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:48 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:48 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:49 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:50 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:52 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:54 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:54 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:54 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:56 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:56 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:56 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:58 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:58 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:30:59 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:30:59 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:31:00 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:31:01 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:31:02 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:31:02 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:31:03 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:31:04 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:31:05 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:31:08 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: No such file or directory Nov 14 10:31:08 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - notice: user ftp: aborting transfer: Data connection closed Nov 14 10:31:08 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - ProFTPD received SIGABRT signal, no core dump Nov 14 10:31:14 ftpsrv last message repeated 248180 times Nov 14 10:31:14 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - ProFTPD received SIGABRT signal, no core dump Nov 14 10:31:16 ftpsrv last message repeated 70279 times Nov 14 10:31:16 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - ProFTPD received SIGABRT signal, no core dump Nov 14 10:31:46 ftpsrv last message repeated 1194453 times Nov 14 10:31:16 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - ProFTPD received SIGABRT signal, no core dump Nov 14 10:32:00 ftpsrv last message repeated 499978 times Nov 14 10:32:00 ftpsrv proftpd[744]: ftpsrv (192.168.222.84[192.168.222.84]) - ProFTPD received SIGABRT signal, no core dump Nov 14 10:32:14 ftpsrv last message repeated 539484 times (dmesg) pid 744 (proftpd), uid 1001: exited on signal 11
There are several different bugs/issues involved in this case. The patch supplied addresses two that have been found so far: 1. The handling of certain Telnet codes (IP, DM) was missing 2. A tightly spinning select() loop could happen in pr_netio_write() if a transfer was aborted -- this is now detected properly. The remaining issues to track down are: 3. Determine why the control connection might be closed/dropped for some aborted transfers. 4. Determine why writing to the ScoreboardFile, for some sessions, leads to SIGABRT.
Created attachment 2902 [details] Updates previous patch This version of the patch updates the previous one, and changes the check for aborted transfers slightly. Before, the CPU usage spike happened in pr_netio_write() because an aborted transfer check resulted in an endless while loop. The previous patch fixed this by adding another aborted transfer check in pr_netio_write(). However, this resulted in the case where the ABOR response was NOT being sent to the client. Clients would then wait and wait for this response, which would never happen. To fix this, the aborted transfer checks were moved, in pr_netio_write(), to only be in the case where we're writing to the data stream (used to be happening for writes to both control and data streams).
I opened Bug#3132 to track the SIGABRT issue.
Created attachment 2905 [details] Updates previous patch This patch fixes one additional complication which arises with aborted transfers, when UseEncoding is in effect for Cyrillic charsets. The UseEncoding means that the Telnet abort bytes aren't filtered out of the control connection; these bytes are usually followed by the string "ABOR" for aborting a transfer. This means that proftpd doesn't see an "ABOR" command, it sees something like "????ABOR" (where each '?' is a Telnet control byte). The ABOR command handler usually cleans up the data transfer state, including clearing any 'aborted' flags. But in this case, the ABOR handler is never called. Which means any data transfer which happens after the initlal abort fails -- the 'aborted' flag is still set. The fix, then, is to clear that flag before any new data transfer.
Now Midnight Commander/Far Manager aborts download perfecty. But vista/freebsd console ftp clients still have controll connection timeout when you have UseEncoding in proftpd config. Without this option they work as they should do.
Created attachment 2906 [details] Updates previous patch Another update to the patch. In this, I've added some checks to the response code, so that any Telnet code sequences are stripped from response messages. (Hopefully this helps those clients which don't appear to handle Telnet codes appearing in FTP response strings after an aborted transfer.)
I just tested last and previous patches. vista/freebsd console clients still cant abort download in proper way if we dont have TimeoutLinger 1 or so in config, so responses fix dont matter for them. So with that option they abort as intended even with previuos patch. btw can 1 sec linger timeout drop transfer coz of some network/client lag? meybe its too low for usual setting =) Thank you very much for fixing that annoying for me problem.
Using a low TimeoutLinger value in your proftpd.conf is completely fine; you could argue that the default timeout of 3 minutes, in the proftpd source code, is too long. So if using "TimeoutLinger 1" works for your Vista/FreeBSD clients for aborting transfers, go with that. I'll commit the previous patch (not the last one which filters the response strings) to CVS, then mark this bug fixed.
Patch (http://bugs.proftpd.org/attachment.cgi?id=2906&action=view) committed to CVS. Thanks for all of the help in tracking this down!
Resolved in 1.3.2rc3.