Author Topic: LIST -a is broken in 1.3.3b when mod_tls is loaded  (Read 3743 times)

Offline gnb

  • New user
  • *
  • Posts: 4
    • View Profile
LIST -a is broken in 1.3.3b when mod_tls is loaded
« on: September 19, 2010, 04:56:17 pm »
Hi,

I'm seeing the following issue on a number of servers running ProFTPd 1.3.3b:

Quote
$ ftp xxxxxx@xxxxxx
Connected to xxxxxx.
220 ProFTPD 1.3.3b Server (FTP Server) [::ffff:78.46.10.232]
331 Password required for xxxxxx
Password:
230 User xxxxxx logged in
Remote system type is UNIX.
Using binary mode to transfer files.
ftp> ls -a
229 Entering Extended Passive Mode (|||41005|)
150 Opening ASCII mode data connection for file list
450  MFF -a: No such file or directory
ftp> ls -a
229 Entering Extended Passive Mode (|||21074|)
150 Opening ASCII mode data connection for file list
drwxr-xr-x   2 xxxxxx   xxxxxx          2 Sep 13 12:59 .
drwxr-xr-x   2 xxxxxx   xxxxxx          2 Sep 13 12:59 ..
226 Transfer complete
ftp> ls -a
229 Entering Extended Passive Mode (|||45077|)
150 Opening ASCII mode data connection for file list
450  MFF -a: No such file or directory
ftp>

Here's what tcpflow says about it:

Quote
LIST -a
150 Opening ASCII mode data connection for file list
450  MFF -a: No such file or directory

Note that there are two spaces after '450'.

Config:
Quote
ServerName                        "FTP Server"
ServerType                        standalone
DefaultServer                     off

UseIPv6                           on

MaxInstances                      100

CommandBufferSize                 512

User                              nobody
Group                             nogroup

Port                              21

RequireValidShell                 off
DefaultRoot                       ~

AllowOverwrite                    on

TLSEngine                         on
TLSProtocol                       SSLv23
TLSRequired                       off
TLSVerifyClient                   off
TLSRSACertificateFile             /usr/local/etc/proftpd_cert/cert
TLSRSACertificateKeyFile          /usr/local/etc/proftpd_cert/key
TLSRenegotiate                    required off

Removing the TLS* lines appears to fix the issue. Also, this problem only seems to happen in the top-level directory.
Changing to another directory permanently fixes this issue (at least for this FTP session). The problem does not occur
when there are no parameters for LIST.

Here's the log file:

Quote
2010-09-19T12:51:51+02:00 rootbackup4  proftpd-log: |xxxxxx| remote: ::ffff:xxxxxx | DIR:  | "LIST -a" | sended bytes: 0
2010-09-19T12:51:52+02:00 xxxxxx  proftpd-log: |xxxxxx| remote: ::ffff:xxxxxx | DIR:  | "LIST -a" | sended bytes: 299
2010-09-19T12:51:53+02:00 xxxxxx  proftpd-log: |xxxxxx| remote: ::ffff:xxxxxx | DIR:  | "LIST -a" | sended bytes: 0
2010-09-19T13:00:41+02:00 xxxxxx  proftpd-log: |xxxxxx| remote: ::ffff:xxxxxx | DIR:  | "LIST -a" | sended bytes: 299
2010-09-19T13:00:41+02:00 xxxxxx  proftpd-log: |xxxxxx| remote: ::ffff:xxxxxx | DIR:  | "LIST -a" | sended bytes: 0
2010-09-19T13:00:42+02:00 xxxxxx  proftpd-log: |xxxxxx| remote: ::ffff:xxxxxx | DIR:  | "LIST -a" | sended bytes: 299
2010-09-19T13:00:42+02:00 xxxxxx  proftpd-log: |xxxxxx| remote: ::ffff:xxxxxx | DIR:  | "LIST -a" | sended bytes: 0

Anyone got an idea what's happening here? :)

Regards,
Gunnar Beutner

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5015
    • View Profile
    • http://www.castaglia.org/
Re: LIST -a is broken in 1.3.3b when mod_tls is loaded
« Reply #1 on: September 20, 2010, 08:51:11 pm »
What does the TLSLog show?

Offline gnb

  • New user
  • *
  • Posts: 4
    • View Profile
Re: LIST -a is broken in 1.3.3b when mod_tls is loaded
« Reply #2 on: September 21, 2010, 08:06:46 am »
Hi,

What does the TLSLog show?

apart from the following line the TLS log is empty (probably because I'm not actually using an encrypted FTP session):

Quote
Sep 21 09:55:01 mod_tls/2.4.1[7542]: using default OpenSSL verification locations (see $SSL_CERT_DIR environment variable)

However, I think I've narrowed down this problem even further: This only seems to happen with FreeBSD's ftp client - which apparently using EPSV. Here's the transcript of a test FTP session:

Quote
220 ProFTPD 1.3.3b Server (FTP Server) [::ffff:xxxxxx]

USER xxxxxx
331 Password required for xxxxxx

PASS xxxxxx
230 User xxxxxx logged in

SYST
215 UNIX Type: L8

FEAT
211-Features:
 MDTM
 MFMT
 TVFS
 AUTH TLS
 MFF modify;UNIX.group;UNIX.mode;
 MLST modify*;perm*;size*;type*;unique*;UNIX.group*;UNIX.mode*;UNIX.owner*;
 PBSZ
 PROT
 REST STREAM
 SIZE
211 End
PWD
257 "/" is the current directory

EPSV
229 Entering Extended Passive Mode (|||31214|)

LIST -a
150 Opening ASCII mode data connection for file list
450  MFF -a: No such file or directory

EPSV
229 Entering Extended Passive Mode (|||39585|)

LIST -a
150 Opening ASCII mode data connection for file list
226 Transfer complete

EPSV
229 Entering Extended Passive Mode (|||29668|)

LIST -a
150 Opening ASCII mode data connection for file list
450  MFF -a: No such file or directory

Using telnet I've observed that the data connections for the failed LIST -a commands are immediately closed by the server without sending any results. On the other hand successful LIST commands return a proper file list:

Quote
$ telnet xxxxxx 21648
Trying xxxxxx...
Connected to xxxxxx.
Escape character is '^]'.
drwxr-xr-x   2 xxxxxx   xxxxxx          2 Sep 13 12:59 .
drwxr-xr-x   2 xxxxxx   xxxxxx          2 Sep 13 12:59 ..
Connection closed by foreign host.

Best regards
Gunnar Beutner

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5015
    • View Profile
    • http://www.castaglia.org/
Re: LIST -a is broken in 1.3.3b when mod_tls is loaded
« Reply #3 on: September 21, 2010, 05:59:22 pm »
This line:

  450  MFF -a: No such file or directory

makes it looks like your client is also sending an MFF (Modify File Fact) command, in addition to the EPSV.  And with an '-a' option (which isn't supported by MFF), too.  Weird.

Do you have any routers, NAT, or firewalls in between the client and the server?

Offline gnb

  • New user
  • *
  • Posts: 4
    • View Profile
Re: LIST -a is broken in 1.3.3b when mod_tls is loaded
« Reply #4 on: September 22, 2010, 06:49:57 am »
Hi,

while there are in fact some routers between those two boxes they aren't running any NAT/firewall stuff.

In fact, the session transcript in my last post was obtained with 'tcpflow' on the target server. Just to make sure there's no funny stuff going on locally (local firewall, connection tracking, who knows...) I've run ktrace against proftpd:

Quote
  6466 proftpd  CALL  select(0x1,0x7fffffffdd60,0x7fffffffdce0,0,0x7fffffffdde0)
  6466 proftpd  RET   select 1
  6466 proftpd  CALL  read(0,0x8012ba020,0x406)
  6466 proftpd  GIO   fd 0 read 6 bytes
       "EPSV\r
       "
  6466 proftpd  RET   read 6
  6466 proftpd  CALL  setitimer(0,0x7fffffffe270,0x7fffffffe250)
  6466 proftpd  RET   setitimer 0
<snip>

  6466 proftpd  RET   write 108/0x6c
  6466 proftpd  CALL  select(0x2,0x7fffffffd890,0x7fffffffd810,0,0x7fffffffd910)
  6466 proftpd  RET   select 1
  6466 proftpd  CALL  write(0x1,0x7fffffffd980,0x30)
  6466 proftpd  GIO   fd 1 wrote 48 bytes
       "229 Entering Extended Passive Mode (|||59399|)\r
       "
  6466 proftpd  RET   write 48/0x30
  6466 proftpd  CALL  select(0x1,0x7fffffffdd60,0x7fffffffdce0,0,0x7fffffffdde0)
  6466 proftpd  RET   select 1
  6466 proftpd  CALL  read(0,0x8012ba020,0x406)
  6466 proftpd  GIO   fd 0 read 9 bytes
       "LIST -a\r
       "
  6466 proftpd  RET   read 9
  6466 proftpd  CALL  setitimer(0,0x7fffffffe270,0x7fffffffe250)
  6466 proftpd  RET   setitimer 0
<snip>

  6466 proftpd  CALL  write(0x1,0x7fffffffcf10,0x36)
  6466 proftpd  GIO   fd 1 wrote 54 bytes
       "150 Opening ASCII mode data connection for file list\r
       "
  6466 proftpd  RET   write 54/0x36
  6466 proftpd  CALL  gettimeofday(0x5f4ba8,0)
  6466 proftpd  RET   gettimeofday 0
  6466 proftpd  CALL  sigaction(SIGURG,0x7fffffffd8f0,0)
  6466 proftpd  RET   sigaction 0
  6466 proftpd  CALL  sigaction(SIGURG,0,0x7fffffffd8a0)
  6466 proftpd  RET   sigaction 0
  6466 proftpd  CALL  sigaction(SIGURG,0x7fffffffd8a0,0)
  6466 proftpd  RET   sigaction 0
  6466 proftpd  CALL  stat(0x8012afcf3,0x7fffffffd880)
  6466 proftpd  NAMI  " MFF -a"
  6466 proftpd  RET   stat -1 errno 2 No such file or directory
  6466 proftpd  CALL  stat(0x7fffffffd500,0x7fffffffd950)
  6466 proftpd  NAMI  "/ MFF -a"
  6466 proftpd  RET   stat -1 errno 2 No such file or directory
<snip>

  6466 proftpd  GIO   fd 5 wrote 111 bytes
       "proftpd-log: |test06| remote: xxxxxx | DIR:  | "LIST -a" | sended bytes: 0
       "
  6466 proftpd  RET   write 111/0x6f
  6466 proftpd  CALL  select(0x2,0x7fffffffd890,0x7fffffffd810,0,0x7fffffffd910)
  6466 proftpd  RET   select 1
  6466 proftpd  CALL  write(0x1,0x7fffffffd980,0x28)
  6466 proftpd  GIO   fd 1 wrote 40 bytes
       "450  MFF -a: No such file or directory\r
       "
  6466 proftpd  RET   write 40/0x28
  6466 proftpd  CALL  select(0x1,0x7fffffffdd60,0x7fffffffdce0,0,0x7fffffffdde0)
  6466 proftpd  RET   select 1

So apparently ProFTPd is getting the 'LIST -a' command and something else is going wrong elsewhere. :)

Best regards,
Gunnar Beutner

Offline castaglia

  • Administrator
  • Support Hero
  • *****
  • Posts: 5015
    • View Profile
    • http://www.castaglia.org/
Re: LIST -a is broken in 1.3.3b when mod_tls is loaded
« Reply #5 on: September 22, 2010, 06:30:33 pm »
What does proftpd debug logging, at debug level 10, show?

  http://www.proftpd.org/docs/howto/Debugging.html

Offline gnb

  • New user
  • *
  • Posts: 4
    • View Profile
Re: LIST -a is broken in 1.3.3b when mod_tls is loaded
« Reply #6 on: September 23, 2010, 06:27:14 am »
Hello,

here's the log you requested:

Quote
# # proftpd -nd10
 - using TCP receive buffer size of 65536 bytes
 - using TCP send buffer size of 32768 bytes
 - mod_tls/2.4.1: using OpenSSL 0.9.8n 24 Mar 2010
 - mod_sftp/0.9.7: using OpenSSL 0.9.8n 24 Mar 2010
 - retrieved UID 65534 for user 'nobody'
 - retrieved GID 65533 for group 'nogroup'
 - ROOT PRIVS at mod_log.c:537
 - RELINQUISH PRIVS at mod_log.c:542
xxxxxx -
xxxxxx - Config for FTP Server:
xxxxxx - CommandBufferSize
xxxxxx - UserID
xxxxxx - UserName
xxxxxx - GroupID
xxxxxx - GroupName
xxxxxx - RequireValidShell
xxxxxx - DefaultRoot
xxxxxx - AllowOverwrite
xxxxxx - TLSEngine
xxxxxx - TLSRequired
xxxxxx - TLSVerifyClient
xxxxxx - TLSRSACertificateFile
xxxxxx - TLSRSACertificateKeyFile
xxxxxx - TLSRenegotiate
xxxxxx - TLSLog
xxxxxx - ExtendedLog
xxxxxx - DebugLevel
xxxxxx -
xxxxxx - Config for FTP Server:
xxxxxx - TransferLog
xxxxxx - SFTPEngine
xxxxxx - SFTPHostKey
xxxxxx - SFTPHostKey
xxxxxx - SFTPAuthMethods
xxxxxx - SFTPAuthorizedUserKeys
xxxxxx - SFTPClientMatch
xxxxxx - SFTPDHParamFile
xxxxxx - SFTPKeyBlacklist
xxxxxx - RequireValidShell
xxxxxx - DefaultRoot
xxxxxx - AllowOverwrite
xxxxxx - ROOT PRIVS at mod_delay.c:354
xxxxxx - RELINQUISH PRIVS at mod_delay.c:359
xxxxxx - ROOT PRIVS at mod_tls.c:1663
xxxxxx - RELINQUISH PRIVS at mod_tls.c:1665
xxxxxx - ROOT PRIVS at mod_tls.c:1747
xxxxxx - mod_tls/2.4.1: passphrase locked into memory
xxxxxx - RELINQUISH PRIVS at mod_tls.c:1753
xxxxxx - ROOT PRIVS at keys.c:552
xxxxxx - RELINQUISH PRIVS at keys.c:554
xxxxxx - ROOT PRIVS at keys.c:552
xxxxxx - RELINQUISH PRIVS at keys.c:554
xxxxxx - retrieved group ID: 65534
xxxxxx - setting group ID: 65534
xxxxxx - SETUP PRIVS at main.c:3127
xxxxxx - ROOT PRIVS at main.c:2151
xxxxxx - RELINQUISH PRIVS at main.c:2158
xxxxxx - ROOT PRIVS at main.c:2486
xxxxxx - opening scoreboard '/var/run/proftpd.scoreboard'
xxxxxx - RELINQUISH PRIVS at main.c:2512
xxxxxx - ROOT PRIVS at inet.c:238
xxxxxx - RELINQUISH PRIVS at inet.c:256
xxxxxx - ROOT PRIVS at inet.c:350
xxxxxx - RELINQUISH PRIVS at inet.c:413
xxxxxx - ROOT PRIVS at inet.c:238
xxxxxx - RELINQUISH PRIVS at inet.c:256
xxxxxx - ROOT PRIVS at inet.c:350
xxxxxx - RELINQUISH PRIVS at inet.c:413
xxxxxx - ProFTPD 1.3.3b (maint) (built Sun Sep 19 2010 12:07:05 CEST) standalone mode STARTUP
xxxxxx - ROOT PRIVS at pidfile.c:48
xxxxxx - RELINQUISH PRIVS at pidfile.c:50
xxxxxx - ROOT PRIVS at main.c:1238
xxxxxx - RELINQUISH PRIVS at main.c:1242
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at main.c:1086
xxxxxx (xxxxxx[::ffff:xxxxxx]) - SETUP PRIVS at main.c:1091
xxxxxx (xxxxxx[::ffff:xxxxxx]) - session requested from client in unknown class
xxxxxx (xxxxxx[::ffff:xxxxxx]) - performing module session initializations
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at mod_tls.c:5444
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_tls.c:5446
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at mod_tls.c:1776
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_tls.c:1791
xxxxxx (xxxxxx[::ffff:xxxxxx]) - mod_tls/2.4.1: supporting SSLv3, TLSv1 protocols
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at mod_tls.c:2372
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_tls.c:2544
xxxxxx (xxxxxx[::ffff:xxxxxx]) - mod_ident/1.0: ident lookup disabled
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at mod_delay.c:1447
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_delay.c:1452
xxxxxx (xxxxxx[::ffff:xxxxxx]) - mod_log: opening ExtendedLog '/var/log/proftpd-transfer.log'
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at mod_log.c:1390
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_log.c:1392
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at mod_auth.c:133
xxxxxx (xxxxxx[::ffff:xxxxxx]) - opening scoreboard '/var/run/proftpd.scoreboard'
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_auth.c:135
xxxxxx (xxxxxx[::ffff:xxxxxx]) - connected - local  : ::ffff:xxxxxx:21
xxxxxx (xxxxxx[::ffff:xxxxxx]) - connected - remote : ::ffff:xxxxxx:11842
xxxxxx (xxxxxx[::ffff:xxxxxx]) - FTP session opened.
xxxxxx (xxxxxx[::ffff:xxxxxx]) - setting CommandBufferSize to 512
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'USER test06' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'USER test06' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'USER test06' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'USER test06' to mod_delay
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'USER test06' to mod_auth
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching CMD command 'USER test06' to mod_auth
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching POST_CMD command 'USER test06' to mod_delay
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'USER test06' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'PASS (hidden)' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'PASS (hidden)' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'PASS (hidden)' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'PASS (hidden)' to mod_wrap2
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'PASS (hidden)' to mod_delay
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'PASS (hidden)' to mod_auth
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching CMD command 'PASS (hidden)' to mod_auth
xxxxxx (xxxxxx[::ffff:xxxxxx]) - retrieved UID 10006 for user 'test06'
xxxxxx (xxxxxx[::ffff:xxxxxx]) - retrieved group IDs: 10006, 1001
xxxxxx (xxxxxx[::ffff:xxxxxx]) - retrieved group names: test06, samba
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at mod_auth_pam.c:312
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_auth_pam.c:482
xxxxxx (xxxxxx[::ffff:xxxxxx]) - user 'test06' authenticated by mod_auth_pam.c
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at auth.c:1252
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at auth.c:1254
xxxxxx (xxxxxx[::ffff:xxxxxx]) - USER PRIVS 10006 at mod_auth.c:1079
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_auth.c:1081
xxxxxx (xxxxxx[::ffff:xxxxxx]) -
xxxxxx (xxxxxx[::ffff:xxxxxx]) - Config for FTP Server:
xxxxxx (xxxxxx[::ffff:xxxxxx]) - CommandBufferSize
xxxxxx (xxxxxx[::ffff:xxxxxx]) - UserID
xxxxxx (xxxxxx[::ffff:xxxxxx]) - UserName
xxxxxx (xxxxxx[::ffff:xxxxxx]) - GroupID
xxxxxx (xxxxxx[::ffff:xxxxxx]) - GroupName
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RequireValidShell
xxxxxx (xxxxxx[::ffff:xxxxxx]) - DefaultRoot
xxxxxx (xxxxxx[::ffff:xxxxxx]) - AllowOverwrite
xxxxxx (xxxxxx[::ffff:xxxxxx]) - TLSEngine
xxxxxx (xxxxxx[::ffff:xxxxxx]) - TLSRequired
xxxxxx (xxxxxx[::ffff:xxxxxx]) - TLSVerifyClient
xxxxxx (xxxxxx[::ffff:xxxxxx]) - TLSRSACertificateFile
xxxxxx (xxxxxx[::ffff:xxxxxx]) - TLSRSACertificateKeyFile
xxxxxx (xxxxxx[::ffff:xxxxxx]) - TLSRenegotiate
xxxxxx (xxxxxx[::ffff:xxxxxx]) - TLSLog
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ExtendedLog
xxxxxx (xxxxxx[::ffff:xxxxxx]) - DebugLevel
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at mod_auth.c:1169
xxxxxx (xxxxxx[::ffff:xxxxxx]) - opening TransferLog '/var/log/xferlog'
xxxxxx (xxxxxx[::ffff:xxxxxx]) - setting group IDs: 10006, 1001
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_auth.c:1209
xxxxxx (xxxxxx[::ffff:xxxxxx]) - USER PRIVS 10006 at mod_auth.c:612
xxxxxx (xxxxxx[::ffff:xxxxxx]) - retrieved UID 10006 for user 'test06'
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_auth.c:616
xxxxxx (xxxxxx[::ffff:xxxxxx]) - Preparing to chroot to directory '/backup/test06'
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at auth.c:1356
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at auth.c:1358
xxxxxx (xxxxxx[::ffff:xxxxxx]) - Environment successfully chroot()ed
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at mod_auth.c:1250
xxxxxx (xxxxxx[::ffff:xxxxxx]) - SETUP PRIVS at mod_auth.c:1262
xxxxxx (xxxxxx[::ffff:xxxxxx]) - in dir_check_full(): path = '/', fullpath = '/backup/test06/'.
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching POST_CMD command 'PASS (hidden)' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching POST_CMD command 'PASS (hidden)' to mod_wrap2
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching POST_CMD command 'PASS (hidden)' to mod_delay
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching POST_CMD command 'PASS (hidden)' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching POST_CMD command 'PASS (hidden)' to mod_ls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching POST_CMD command 'PASS (hidden)' to mod_auth
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_auth.c:1623
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching POST_CMD command 'PASS (hidden)' to mod_xfer
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching POST_CMD command 'PASS (hidden)' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'PASS (hidden)' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'PASS (hidden)' to mod_auth
xxxxxx (xxxxxx[::ffff:xxxxxx]) - USER test06: Login successful.
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'SYST' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'SYST' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'SYST' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching CMD command 'SYST' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'SYST' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'FEAT' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'FEAT' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'FEAT' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching CMD command 'FEAT' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - in dir_check_full(): path = '/', fullpath = '/backup/test06/'.
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'FEAT' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'PWD' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'PWD' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'PWD' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching CMD command 'PWD' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - in dir_check_full(): path = '/', fullpath = '/backup/test06/'.
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'PWD' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'EPSV' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'EPSV' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'EPSV' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching CMD command 'EPSV' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - in dir_check_full(): path = '/', fullpath = '/backup/test06/'.
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at inet.c:238
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at inet.c:256
xxxxxx (xxxxxx[::ffff:xxxxxx]) - Entering Extended Passive Mode (|||45188|)
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'EPSV' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'LIST -a' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'LIST -a' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'LIST -a' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching CMD command 'LIST -a' to mod_ls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - passive data connection opened - local  : ::ffff:xxxxxx:45188
xxxxxx (xxxxxx[::ffff:xxxxxx]) - passive data connection opened - remote : ::ffff:xxxxxx:61996
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD_ERR command 'LIST -a' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD_ERR command 'LIST -a' to mod_ls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'EPSV' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'EPSV' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'EPSV' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching CMD command 'EPSV' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - in dir_check_full(): path = '/', fullpath = '/backup/test06/'.
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at inet.c:238
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at inet.c:256
xxxxxx (xxxxxx[::ffff:xxxxxx]) - Entering Extended Passive Mode (|||17772|)
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'EPSV' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'LIST -a' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'LIST -a' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'LIST -a' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching CMD command 'LIST -a' to mod_ls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - passive data connection opened - local  : ::ffff:xxxxxx:17772
xxxxxx (xxxxxx[::ffff:xxxxxx]) - passive data connection opened - remote : ::ffff:xxxxxx:12821
xxxxxx (xxxxxx[::ffff:xxxxxx]) - in dir_check_full(): path = '/', fullpath = '/backup/test06/'.
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'LIST -a' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'LIST -a' to mod_ls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'QUIT' to mod_tls
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'QUIT' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching PRE_CMD command 'QUIT' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching CMD command 'QUIT' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'QUIT' to mod_log
xxxxxx (xxxxxx[::ffff:xxxxxx]) - dispatching LOG_CMD command 'QUIT' to mod_core
xxxxxx (xxxxxx[::ffff:xxxxxx]) - mod_sftp/0.9.7: scrubbing 2 passphrases from memory
xxxxxx (xxxxxx[::ffff:xxxxxx]) - mod_tls/2.4.1: scrubbing 1 passphrase from memory
xxxxxx (xxxxxx[::ffff:xxxxxx]) - ROOT PRIVS at mod_auth_pam.c:173
xxxxxx (xxxxxx[::ffff:xxxxxx]) - RELINQUISH PRIVS at mod_auth_pam.c:207
xxxxxx (xxxxxx[::ffff:xxxxxx]) - FTP session closed.
xxxxxx - ProFTPD terminating (signal 2)
xxxxxx - ROOT PRIVS at main.c:2014
xxxxxx - ROOT PRIVS at mod_delay.c:1328
xxxxxx - RELINQUISH PRIVS at mod_delay.c:1333
xxxxxx - mod_tls/2.4.1: scrubbing 1 passphrase from memory
xxxxxx - mod_sftp/0.9.7: scrubbing 2 passphrases from memory
xxxxxx - RELINQUISH PRIVS at main.c:2036
xxxxxx - ProFTPD 1.3.3b standalone mode SHUTDOWN
xxxxxx - ROOT PRIVS at main.c:2043
xxxxxx - deleting existing scoreboard '/var/run/proftpd.scoreboard'
xxxxxx - RELINQUISH PRIVS at main.c:2045

And here's what i tried in my FTP client:

Quote
$ ftp xxxxxx
Connected to xxxxxx.
220 ProFTPD 1.3.3b Server (FTP Server) [::ffff:xxxxxx]
Name (xxxxxx:root): test06
331 Password required for test06
Password:
230 User test06 logged in
Remote system type is UNIX.
Using binary mode to transfer files.
ftp> ls -a
229 Entering Extended Passive Mode (|||45188|)
150 Opening ASCII mode data connection for file list
450  MFF -a: No such file or directory
ftp> ls -a
229 Entering Extended Passive Mode (|||17772|)
150 Opening ASCII mode data connection for file list
drwxr-xr-x   2 test06   test06          2 Sep 13 12:59 .
drwxr-xr-x   2 test06   test06          2 Sep 13 12:59 ..
226 Transfer complete
ftp> quit
221 Goodbye.

Regards,
Gunnar Beutner

 

sighted planning