I have only now noticed that I had been running an unpatched
ftp-proxy 1.7 instead of 1.7p6 (I had been mis-lead by the recent
file date on the 1.7 tarball, which is the same as the patch).
My problem with the passive client and sysmbolic directory link
under Netscape persists.
I append an updated debug logfile, which is now from 1.7p6
The location of the bug is marked with 'here comes the bug'
where the port 20 connection is opened by the proxy.
14:44:01 < 6281> accepted 5=192.53.104.46 wanting to go to 195.49.62.59
14:44:01 < 6281> config_int: s='(nil)' n='ForkLimit' d=40
14:44:01 < 6281> config_int: s='(nil)' n='MaxClients' d=512
14:44:01 < 6281> config_int: result=64
14:44:01 < 6281> client pid=6415 (192.53.104.46) added
14:44:01 < 6415> {{{{{ ftp-child client-fork
14:44:01 < 6415> config_int: s='(nil)' n='TimeOut' d=900
14:44:01 < 6415> config_int: result=300
14:44:01 < 6415> config_str: s='(nil)' n='DenyMessage' d='(nil)'
14:44:01 < 6415> alloc 68 (com-socket.c:351): 0x8060158
14:44:01 < 6415> created HLS for 0=192.53.104.46:4449
14:44:01 < 6415> USER-INF connect from 192.53.104.46
14:44:01 < 6415> config_str: s='(nil)' n='WelcomeString' d='(nil)'
14:44:01 < 6415> config_str: result='Welcome to Astrodienst'
14:44:01 < 6415> config_str: s='(nil)' n='WelcomeMessage' d='(nil)'
14:44:01 < 6415> printf Cli-Ctrl 0=192.53.104.46: 29 bytes '220 Welcome to Astrodienst.'
14:44:01 < 6415> alloc 53 (com-socket.c:712): 0x80601a0
14:44:01 < 6415> config_str: s='(nil)' n='ServerRoot' d='(nil)'
14:44:01 < 6415> FD_SET Cli-Ctrl for W
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:01 < 6415> free 0x80601a0 (com-socket.c:1070)
14:44:01 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 29 bytes
14:44:01 < 6415> client-loop ...
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:01 < 6415> alloc 40 (com-socket.c:980): 0x80601a0
14:44:01 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 16 bytes
14:44:01 < 6415> client-loop ...
14:44:01 < 6415> free 0x80601a0 (com-socket.c:562)
14:44:01 < 6415> gets Cli-Ctrl 0=192.53.104.46: 14 bytes 'USER anonymous'
14:44:01 < 6415> from User-PI (0): cmd='USER' arg='anonymous'
14:44:01 < 6415> config_str: s='(nil)' n='ValidCommands' d='(nil)'
14:44:01 < 6415> allowed: '(all)'
14:44:01 < 6415> config_bool: s='(nil)' n='AllowTransProxy' d=0
14:44:01 < 6415> config_bool: result=1
14:44:01 < 6415> interface lo has ip-address: 127.0.0.1
14:44:01 < 6415> interface eth0 has ip-address: 10.1.1.254
14:44:01 < 6415> interface eth1 has ip-address: 195.49.62.58
14:44:01 < 6415> interface eth1:0 has ip-address: 195.49.62.59
14:44:01 < 6415> found local ip addr: 195.49.62.59
14:44:01 < 6415> USER-WRN requested transparent proxy dest 195.49.62.59 is local
14:44:01 < 6415> config_bool: s='(nil)' n='AllowMagicUser' d=0
14:44:01 < 6415> config_str: s='(nil)' n='DestinationAddress' d='(nil)'
14:44:01 < 6415> config_str: result='w1'
14:44:01 < 6415> USER-INF 'USER anonymous' from 192.53.104.46
14:44:01 < 6415> alloc 10 (ftp-cmds.c:489): 0x80601a0
14:44:01 < 6415> USER-INF reading data for 'anonymous' from cfg-file
14:44:01 < 6415> config_addr: s='anonymous' n='DestinationAddress' d='255.255.255.255'
14:44:01 < 6415> config_addr: s='(nil)' n='DestinationAddress' d='255.255.255.255'
14:44:01 < 6415> str2addr: in='w1'
14:44:01 < 6415> config_addr: result='10.1.1.1'
14:44:01 < 6415> DestAddr for 192.53.104.46: '10.1.1.1'
14:44:01 < 6415> config_port: s='anonymous' n='DestinationPort' d=21
14:44:01 < 6415> config_port: s='(nil)' n='DestinationPort' d=21
14:44:01 < 6415> DestPort for 192.53.104.46: 21
14:44:01 < 6415> config_str: s='anonymous' n='DestinationTransferMode' d='client'
14:44:01 < 6415> config_str: s='(nil)' n='DestinationTransferMode' d='client'
14:44:01 < 6415> config_str: result='passive'
14:44:01 < 6415> DestMode for 192.53.104.46: passive
14:44:01 < 6415> config_port: s='anonymous' n='DestinationMinPort' d=0
14:44:01 < 6415> config_port: s='(nil)' n='DestinationMinPort' d=0
14:44:01 < 6415> config_port: s='anonymous' n='DestinationMaxPort' d=0
14:44:01 < 6415> config_port: s='(nil)' n='DestinationMaxPort' d=0
14:44:01 < 6415> DestRange for 192.53.104.46: 0-0
14:44:01 < 6415> config_port: s='anonymous' n='ActiveMinDataPort' d=0
14:44:01 < 6415> config_port: s='(nil)' n='ActiveMinDataPort' d=0
14:44:01 < 6415> config_port: s='anonymous' n='ActiveMaxDataPort' d=0
14:44:01 < 6415> config_port: s='(nil)' n='ActiveMaxDataPort' d=0
14:44:01 < 6415> ActiveRange for 192.53.104.46: 20-20
14:44:01 < 6415> config_port: s='anonymous' n='PassiveMinDataPort' d=0
14:44:01 < 6415> config_port: s='(nil)' n='PassiveMinDataPort' d=0
14:44:01 < 6415> config_port: result=41000
14:44:01 < 6415> config_port: s='anonymous' n='PassiveMaxDataPort' d=0
14:44:01 < 6415> config_port: s='(nil)' n='PassiveMaxDataPort' d=0
14:44:01 < 6415> config_port: result=41999
14:44:01 < 6415> PassiveRange for 192.53.104.46: 41000-41999
14:44:01 < 6415> config_bool: s='anonymous' n='SameAddress' d=1
14:44:01 < 6415> config_bool: s='(nil)' n='SameAddress' d=1
14:44:01 < 6415> config_int: s='anonymous' n='TimeOut' d=900
14:44:01 < 6415> config_int: s='(nil)' n='TimeOut' d=900
14:44:01 < 6415> config_int: result=300
14:44:01 < 6415> SameAddress for 192.53.104.46: yes
14:44:01 < 6415> TimeOut for 192.53.104.46: 300
14:44:01 < 6415> config_str: s='anonymous' n='ValidCommands' d='(nil)'
14:44:01 < 6415> config_str: s='(nil)' n='ValidCommands' d='(nil)'
14:44:01 < 6415> allowed: '(all)'
14:44:01 < 6415> config_int: s='(nil)' n='SockBindRand' d=0
14:44:01 < 6415> alloc 68 (com-socket.c:351): 0x8060810
14:44:01 < 6415> created HLS for 4=10.1.1.1:21
14:44:01 < 6415> Srv-Ctrl is 10.1.1.1:21
14:44:01 < 6415> FD_SET Srv-Ctrl for R
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:01 < 6415> alloc 68 (com-socket.c:980): 0x8060858
14:44:01 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 44 bytes
14:44:01 < 6415> client-loop ...
14:44:01 < 6415> free 0x8060858 (com-socket.c:562)
14:44:01 < 6415> gets Srv-Ctrl 4=10.1.1.1: 42 bytes '220 ProFTPD 1.2.2rc2 Server (ProFTPD) [w1]'
14:44:01 < 6415> from Server-PI (4): '220 ProFTPD 1.2.2rc2 Server (ProFTPD) [w1]'
14:44:01 < 6415> printf Srv-Ctrl 4=10.1.1.1: 16 bytes 'USER anonymous'
14:44:01 < 6415> alloc 40 (com-socket.c:712): 0x8060858
14:44:01 < 6415> FD_SET Srv-Ctrl for W
14:44:01 < 6415> FD_SET Srv-Ctrl for R
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:01 < 6415> free 0x8060858 (com-socket.c:1070)
14:44:01 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 16 bytes
14:44:01 < 6415> client-loop ...
14:44:01 < 6415> FD_SET Srv-Ctrl for R
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:01 < 6415> alloc 100 (com-socket.c:980): 0x8061150
14:44:01 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 76 bytes
14:44:01 < 6415> client-loop ...
14:44:01 < 6415> free 0x8061150 (com-socket.c:562)
14:44:01 < 6415> gets Srv-Ctrl 4=10.1.1.1: 74 bytes '331 Anonymous login ok, send your complete email address as your password.'
14:44:01 < 6415> from Server-PI (4): '331 Anonymous login ok, send your complete email address as your password.'
14:44:01 < 6415> printf Cli-Ctrl 0=192.53.104.46: 76 bytes '331 Anonymous login ok, send your complete email address as your password.'
14:44:01 < 6415> alloc 100 (com-socket.c:712): 0x8061150
14:44:01 < 6415> FD_SET Srv-Ctrl for R
14:44:01 < 6415> FD_SET Cli-Ctrl for W
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:01 < 6415> free 0x8061150 (com-socket.c:1070)
14:44:01 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 76 bytes
14:44:01 < 6415> client-loop ...
14:44:01 < 6415> FD_SET Srv-Ctrl for R
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:01 < 6415> alloc 39 (com-socket.c:980): 0x8060858
14:44:01 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 15 bytes
14:44:01 < 6415> client-loop ...
14:44:01 < 6415> free 0x8060858 (com-socket.c:562)
14:44:01 < 6415> gets Cli-Ctrl 0=192.53.104.46: 13 bytes 'PASS mozilla@'
14:44:01 < 6415> from User-PI (0): cmd='PASS' arg='mozilla@'
14:44:01 < 6415> printf Srv-Ctrl 4=10.1.1.1: 15 bytes 'PASS mozilla@'
14:44:01 < 6415> alloc 39 (com-socket.c:712): 0x8060858
14:44:01 < 6415> USER-INF 'PASS XXXX' from 192.53.104.46
14:44:01 < 6415> FD_SET Srv-Ctrl for W
14:44:01 < 6415> FD_SET Srv-Ctrl for R
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:01 < 6415> free 0x8060858 (com-socket.c:1070)
14:44:01 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 15 bytes
14:44:01 < 6415> client-loop ...
14:44:01 < 6415> FD_SET Srv-Ctrl for R
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:01 < 6415> alloc 75 (com-socket.c:980): 0x8060858
14:44:01 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 51 bytes
14:44:01 < 6415> client-loop ...
14:44:01 < 6415> free 0x8060858 (com-socket.c:562)
14:44:01 < 6415> gets Srv-Ctrl 4=10.1.1.1: 49 bytes '230 Anonymous access granted, restrictions apply.'
14:44:01 < 6415> from Server-PI (4): '230 Anonymous access granted, restrictions apply.'
14:44:01 < 6415> printf Cli-Ctrl 0=192.53.104.46: 51 bytes '230 Anonymous access granted, restrictions apply.'
14:44:01 < 6415> alloc 75 (com-socket.c:712): 0x8060858
14:44:01 < 6415> FD_SET Srv-Ctrl for R
14:44:01 < 6415> FD_SET Cli-Ctrl for W
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:01 < 6415> free 0x8060858 (com-socket.c:1070)
14:44:01 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 51 bytes
14:44:01 < 6415> client-loop ...
14:44:01 < 6415> FD_SET Srv-Ctrl for R
14:44:01 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 32 (com-socket.c:980): 0x8060858
14:44:02 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 8 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8060858 (com-socket.c:562)
14:44:02 < 6415> gets Cli-Ctrl 0=192.53.104.46: 6 bytes 'REST 0'
14:44:02 < 6415> from User-PI (0): cmd='REST' arg='0'
14:44:02 < 6415> printf Srv-Ctrl 4=10.1.1.1: 8 bytes 'REST 0'
14:44:02 < 6415> alloc 32 (com-socket.c:712): 0x8060858
14:44:02 < 6415> USER-INF 'REST 0' from 192.53.104.46
14:44:02 < 6415> FD_SET Srv-Ctrl for W
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8060858 (com-socket.c:1070)
14:44:02 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 8 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 91 (com-socket.c:980): 0x8060858
14:44:02 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 67 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8060858 (com-socket.c:562)
14:44:02 < 6415> gets Srv-Ctrl 4=10.1.1.1: 65 bytes '350 Restarting at 0. Send STORE or RETRIEVE to initiate transfer.'
14:44:02 < 6415> from Server-PI (4): '350 Restarting at 0. Send STORE or RETRIEVE to initiate transfer.'
14:44:02 < 6415> printf Cli-Ctrl 0=192.53.104.46: 67 bytes '350 Restarting at 0. Send STORE or RETRIEVE to initiate transfer.'
14:44:02 < 6415> alloc 91 (com-socket.c:712): 0x8060858
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for W
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8060858 (com-socket.c:1070)
14:44:02 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 67 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 30 (com-socket.c:980): 0x8060858
14:44:02 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 6 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8060858 (com-socket.c:562)
14:44:02 < 6415> gets Cli-Ctrl 0=192.53.104.46: 4 bytes 'SYST'
14:44:02 < 6415> from User-PI (0): cmd='SYST' arg=''
14:44:02 < 6415> printf Srv-Ctrl 4=10.1.1.1: 6 bytes 'SYST'
14:44:02 < 6415> alloc 30 (com-socket.c:712): 0x8060858
14:44:02 < 6415> USER-INF 'SYST' from 192.53.104.46
14:44:02 < 6415> FD_SET Srv-Ctrl for W
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8060858 (com-socket.c:1070)
14:44:02 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 6 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 43 (com-socket.c:980): 0x8060858
14:44:02 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 19 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8060858 (com-socket.c:562)
14:44:02 < 6415> gets Srv-Ctrl 4=10.1.1.1: 17 bytes '215 UNIX Type: L8'
14:44:02 < 6415> from Server-PI (4): '215 UNIX Type: L8'
14:44:02 < 6415> printf Cli-Ctrl 0=192.53.104.46: 19 bytes '215 UNIX Type: L8'
14:44:02 < 6415> alloc 43 (com-socket.c:712): 0x8060858
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for W
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8060858 (com-socket.c:1070)
14:44:02 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 19 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 30 (com-socket.c:980): 0x8060858
14:44:02 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 6 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8060858 (com-socket.c:562)
14:44:02 < 6415> gets Cli-Ctrl 0=192.53.104.46: 4 bytes 'PASV'
14:44:02 < 6415> from User-PI (0): cmd='PASV' arg=''
14:44:02 < 6415> config_int: s='(nil)' n='SockBindRand' d=0
14:44:02 < 6415> bind 195.49.62.59:41000 status: Success
14:44:02 < 6415> bound socket to port 41000
14:44:02 < 6415> alloc 68 (com-socket.c:351): 0x8060858
14:44:02 < 6415> created HLS for -1=:0
14:44:02 < 6415> listen: Cli-Data (fd=5) 195.49.62.59:41000
14:44:02 < 6415> config_str: s='(nil)' n='TranslatedAddress' d='(nil)'
14:44:02 < 6415> printf Cli-Ctrl 0=192.53.104.46: 50 bytes '227 Entering Passive Mode (195,49,62,59,160,40).'
14:44:02 < 6415> alloc 74 (com-socket.c:712): 0x8061150
14:44:02 < 6415> USER-INF PASV set to 195.49.62.59:41000 for 192.53.104.46
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for W
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061150 (com-socket.c:1070)
14:44:02 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 50 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> accept Cli-Data (6) from 192.53.104.46
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 32 (com-socket.c:980): 0x8061150
14:44:02 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 8 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061150 (com-socket.c:562)
14:44:02 < 6415> gets Cli-Ctrl 0=192.53.104.46: 6 bytes 'TYPE I'
14:44:02 < 6415> from User-PI (0): cmd='TYPE' arg='I'
14:44:02 < 6415> printf Srv-Ctrl 4=10.1.1.1: 8 bytes 'TYPE I'
14:44:02 < 6415> alloc 32 (com-socket.c:712): 0x8061150
14:44:02 < 6415> USER-INF 'TYPE I' from 192.53.104.46
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for W
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061150 (com-socket.c:1070)
14:44:02 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 8 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 44 (com-socket.c:980): 0x8061150
14:44:02 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 20 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061150 (com-socket.c:562)
14:44:02 < 6415> gets Srv-Ctrl 4=10.1.1.1: 18 bytes '200 Type set to I.'
14:44:02 < 6415> from Server-PI (4): '200 Type set to I.'
14:44:02 < 6415> printf Cli-Ctrl 0=192.53.104.46: 20 bytes '200 Type set to I.'
14:44:02 < 6415> alloc 44 (com-socket.c:712): 0x8061150
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for W
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061150 (com-socket.c:1070)
14:44:02 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 20 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 51 (com-socket.c:980): 0x8061150
14:44:02 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 27 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061150 (com-socket.c:562)
14:44:02 < 6415> gets Cli-Ctrl 0=192.53.104.46: 25 bytes 'SIZE /pub/swisseph/my_doc'
14:44:02 < 6415> from User-PI (0): cmd='SIZE' arg='/pub/swisseph/my_doc'
14:44:02 < 6415> printf Srv-Ctrl 4=10.1.1.1: 27 bytes 'SIZE /pub/swisseph/my_doc'
14:44:02 < 6415> alloc 51 (com-socket.c:712): 0x8061150
14:44:02 < 6415> USER-INF 'SIZE /pub/swisseph/my_doc' from 192.53.104.46
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for W
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061150 (com-socket.c:1070)
14:44:02 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 27 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 71 (com-socket.c:980): 0x8061150
14:44:02 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 47 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061150 (com-socket.c:562)
14:44:02 < 6415> gets Srv-Ctrl 4=10.1.1.1: 45 bytes '550 /pub/swisseph/my_doc: not a regular file.'
14:44:02 < 6415> from Server-PI (4): '550 /pub/swisseph/my_doc: not a regular file.'
14:44:02 < 6415> printf Cli-Ctrl 0=192.53.104.46: 47 bytes '550 /pub/swisseph/my_doc: not a regular file.'
14:44:02 < 6415> alloc 71 (com-socket.c:712): 0x8061150
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for W
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061150 (com-socket.c:1070)
14:44:02 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 47 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 51 (com-socket.c:980): 0x8061150
14:44:02 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 27 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061150 (com-socket.c:562)
14:44:02 < 6415> gets Cli-Ctrl 0=192.53.104.46: 25 bytes 'MDTM /pub/swisseph/my_doc'
14:44:02 < 6415> from User-PI (0): cmd='MDTM' arg='/pub/swisseph/my_doc'
14:44:02 < 6415> printf Srv-Ctrl 4=10.1.1.1: 27 bytes 'MDTM /pub/swisseph/my_doc'
14:44:02 < 6415> alloc 51 (com-socket.c:712): 0x8061150
14:44:02 < 6415> USER-INF 'MDTM /pub/swisseph/my_doc' from 192.53.104.46
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for W
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061150 (com-socket.c:1070)
14:44:02 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 27 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 69 (com-socket.c:980): 0x8061150
14:44:02 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 45 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061150 (com-socket.c:562)
14:44:02 < 6415> gets Srv-Ctrl 4=10.1.1.1: 43 bytes '550 /pub/swisseph/my_doc: not a plain file.'
14:44:02 < 6415> from Server-PI (4): '550 /pub/swisseph/my_doc: not a plain file.'
14:44:02 < 6415> printf Cli-Ctrl 0=192.53.104.46: 45 bytes '550 /pub/swisseph/my_doc: not a plain file.'
14:44:02 < 6415> alloc 69 (com-socket.c:712): 0x8061150
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for W
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061150 (com-socket.c:1070)
14:44:02 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 45 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 51 (com-socket.c:980): 0x8061150
14:44:02 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 27 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061150 (com-socket.c:562)
14:44:02 < 6415> gets Cli-Ctrl 0=192.53.104.46: 25 bytes 'RETR /pub/swisseph/my_doc'
14:44:02 < 6415> from User-PI (0): cmd='RETR' arg='/pub/swisseph/my_doc'
14:44:02 < 6415> USER-INF 'RETR /pub/swisseph/my_doc' from 192.53.104.46
14:44:02 < 6415> printf Srv-Ctrl 4=10.1.1.1: 6 bytes 'PASV'
14:44:02 < 6415> alloc 30 (com-socket.c:712): 0x8061150
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for W
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061150 (com-socket.c:1070)
14:44:02 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 6 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 71 (com-socket.c:980): 0x8061150
14:44:02 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 47 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061150 (com-socket.c:562)
14:44:02 < 6415> gets Srv-Ctrl 4=10.1.1.1: 45 bytes '227 Entering Passive Mode (10,1,1,1,214,119).'
14:44:02 < 6415> from Server-PI (4): '227 Entering Passive Mode (10,1,1,1,214,119).'
14:44:02 < 6415> config_int: s='(nil)' n='SockBindRand' d=0
14:44:02 < 6415> alloc 68 (com-socket.c:351): 0x8061150
14:44:02 < 6415> created HLS for 5=10.1.1.1:54903
14:44:02 < 6415> connect: Srv-Data fd=5
14:44:02 < 6415> config_int: s='(nil)' n='SockBindRand' d=0
14:44:02 < 6415> printf Srv-Ctrl 4=10.1.1.1: 27 bytes 'RETR /pub/swisseph/my_doc'
14:44:02 < 6415> alloc 51 (com-socket.c:712): 0x8061198
14:44:02 < 6415> TECH-INF 'RETR /pub/swisseph/my_doc' sent for 192.53.104.46
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for W
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061198 (com-socket.c:1070)
14:44:02 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 27 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 70 (com-socket.c:980): 0x8061198
14:44:02 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 46 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061198 (com-socket.c:562)
14:44:02 < 6415> gets Srv-Ctrl 4=10.1.1.1: 44 bytes '550 /pub/swisseph/my_doc: Not a regular file'
14:44:02 < 6415> from Server-PI (4): '550 /pub/swisseph/my_doc: Not a regular file'
14:44:02 < 6415> printf Cli-Ctrl 0=192.53.104.46: 46 bytes '550 /pub/swisseph/my_doc: Not a regular file'
14:44:02 < 6415> alloc 70 (com-socket.c:712): 0x8061198
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for W
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061198 (com-socket.c:1070)
14:44:02 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 46 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 50 (com-socket.c:980): 0x8061198
14:44:02 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 26 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061198 (com-socket.c:562)
14:44:02 < 6415> gets Cli-Ctrl 0=192.53.104.46: 24 bytes 'CWD /pub/swisseph/my_doc'
14:44:02 < 6415> from User-PI (0): cmd='CWD' arg='/pub/swisseph/my_doc'
14:44:02 < 6415> printf Srv-Ctrl 4=10.1.1.1: 26 bytes 'CWD /pub/swisseph/my_doc'
14:44:02 < 6415> alloc 50 (com-socket.c:712): 0x8061198
14:44:02 < 6415> USER-INF 'CWD /pub/swisseph/my_doc' from 192.53.104.46
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for W
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061198 (com-socket.c:1070)
14:44:02 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 26 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 53 (com-socket.c:980): 0x8061198
14:44:02 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 29 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061198 (com-socket.c:562)
14:44:02 < 6415> gets Srv-Ctrl 4=10.1.1.1: 27 bytes '250 CWD command successful.'
14:44:02 < 6415> from Server-PI (4): '250 CWD command successful.'
14:44:02 < 6415> printf Cli-Ctrl 0=192.53.104.46: 29 bytes '250 CWD command successful.'
14:44:02 < 6415> alloc 53 (com-socket.c:712): 0x8061198
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for W
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061198 (com-socket.c:1070)
14:44:02 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 29 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 30 (com-socket.c:980): 0x8061198
14:44:02 < 6415> ll_read Cli-Ctrl 0=192.53.104.46: 6 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8061198 (com-socket.c:562)
14:44:02 < 6415> gets Cli-Ctrl 0=192.53.104.46: 4 bytes 'LIST'
14:44:02 < 6415> from User-PI (0): cmd='LIST' arg=''
14:44:02 < 6415> USER-INF 'LIST' from 192.53.104.46
14:44:02 < 6415> printf Srv-Ctrl 4=10.1.1.1: 6 bytes 'PASV'
14:44:02 < 6415> alloc 30 (com-socket.c:712): 0x8061198
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for W
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061198 (com-socket.c:1070)
14:44:02 < 6415> ll_write Srv-Ctrl 4=10.1.1.1: 6 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Cli-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> closed: Srv-Data -1=10.1.1.1
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> about to destroy Srv-Data
14:44:02 < 6415> deleting HLS Srv-Data -1=10.1.1.1:54903
14:44:02 < 6415> free 0x8061150 (com-socket.c:497)
14:44:02 < 6415> FD_CLR Cli-Data
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> about to destroy Cli-Data
14:44:02 < 6415> USER-INF Transfer for 192.53.104.46: LIST '' 1 sec
14:44:02 < 6415> deleting HLS Cli-Data -1=192.53.104.46:4450
14:44:02 < 6415> free 0x8060858 (com-socket.c:497)
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> alloc 71 (com-socket.c:980): 0x8060858
14:44:02 < 6415> ll_read Srv-Ctrl 4=10.1.1.1: 47 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x8060858 (com-socket.c:562)
14:44:02 < 6415> gets Srv-Ctrl 4=10.1.1.1: 45 bytes '227 Entering Passive Mode (10,1,1,1,214,120).'
14:44:02 < 6415> from Server-PI (4): '227 Entering Passive Mode (10,1,1,1,214,120).'
14:44:02 < 6415> config_int: s='(nil)' n='SockBindRand' d=0
14:44:02 < 6415> alloc 68 (com-socket.c:351): 0x8060858
14:44:02 < 6415> created HLS for 5=10.1.1.1:54904
14:44:02 < 6415> connect: Srv-Data fd=5
14:44:02 < 6415> config_int: s='(nil)' n='SockBindRand' d=0
**** here comes the bug
14:44:02 < 6415> Cli-Data: about to bind to 195.49.62.59:range(20-20)
14:44:02 < 6415> bind 195.49.62.59:20 status: Success
14:44:02 < 6415> bound socket to port 20
14:44:02 < 6415> Cli-Data: connect failed with 'No route to host'
14:44:02 < 6415> TECH-ERR can't connect Cli-Data for 192.53.104.46 (errno=113 [No route to host])
14:44:02 < 6415> printf Cli-Ctrl 0=192.53.104.46: 33 bytes '425 Can't open data connection.'
14:44:02 < 6415> alloc 57 (com-socket.c:712): 0x8061150
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for W
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> free 0x8061150 (com-socket.c:1070)
14:44:02 < 6415> ll_write Cli-Ctrl 0=192.53.104.46: 33 bytes
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> FD_SET Srv-Data for R
14:44:02 < 6415> FD_SET Srv-Ctrl for R
14:44:02 < 6415> FD_SET Cli-Ctrl for R
14:44:02 < 6415> closed: Cli-Ctrl -1=192.53.104.46
14:44:02 < 6415> client-loop ...
14:44:02 < 6415> free 0x80601a0 (ftp-client.c:398)
14:44:02 < 6415> }}}}} ftp-child client-exit
14:44:02 < 6415> deleting HLS Srv-Data 5=10.1.1.1:54904
14:44:02 < 6415> free 0x8060858 (com-socket.c:497)
14:44:02 < 6415> deleting HLS Srv-Ctrl 4=10.1.1.1:21
14:44:02 < 6415> free 0x8060810 (com-socket.c:497)
14:44:02 < 6415> deleting HLS Cli-Ctrl -1=192.53.104.46:4449
14:44:02 < 6415> free 0x8060158 (com-socket.c:497)
14:44:02 < 6415> free 0x8060138 (com-syslog.c:534)
14:44:02 < 6415> config_cleanup
14:44:02 < 6415> free 0x805fc38 (com-config.c:124)
14:44:02 < 6415> free 0x805fc50 (com-config.c:126)
14:44:02 < 6415> free 0x805fc28 (com-config.c:127)
14:44:02 < 6415> free 0x805fc70 (com-config.c:124)
14:44:02 < 6415> free 0x805fc88 (com-config.c:126)
14:44:02 < 6415> free 0x805fc60 (com-config.c:127)
14:44:02 < 6415> free 0x805fca8 (com-config.c:124)
14:44:02 < 6415> free 0x805fcc8 (com-config.c:126)
14:44:02 < 6415> free 0x805fc98 (com-config.c:127)
14:44:02 < 6415> free 0x805fce8 (com-config.c:124)
14:44:02 < 6415> free 0x805fcf8 (com-config.c:126)
14:44:02 < 6415> free 0x805fcd8 (com-config.c:127)
14:44:02 < 6415> free 0x805fd18 (com-config.c:124)
14:44:02 < 6415> free 0x805fd30 (com-config.c:126)
14:44:02 < 6415> free 0x805fd08 (com-config.c:127)
14:44:02 < 6415> free 0x805ffe8 (com-config.c:124)
14:44:02 < 6415> free 0x805fff8 (com-config.c:126)
14:44:02 < 6415> free 0x805fd50 (com-config.c:127)
14:44:02 < 6415> free 0x8060018 (com-config.c:124)
14:44:02 < 6415> free 0x8060030 (com-config.c:126)
14:44:02 < 6415> free 0x8060008 (com-config.c:127)
14:44:02 < 6415> free 0x80600a8 (com-config.c:124)
14:44:02 < 6415> free 0x80600c0 (com-config.c:126)
14:44:02 < 6415> free 0x8060098 (com-config.c:127)
14:44:02 < 6415> free 0x8060070 (com-config.c:124)
14:44:02 < 6415> free 0x8060088 (com-config.c:126)
14:44:02 < 6415> free 0x8060060 (com-config.c:127)
14:44:02 < 6415> free 0x80600e0 (com-config.c:124)
14:44:02 < 6415> free 0x80600f8 (com-config.c:126)
14:44:02 < 6415> free 0x80600d0 (com-config.c:127)
14:44:02 < 6415> free 0x8060118 (com-config.c:124)
14:44:02 < 6415> free 0x8060128 (com-config.c:126)
14:44:02 < 6415> free 0x8060108 (com-config.c:127)
14:44:02 < 6415> free 0x80602d8 (com-config.c:124)
14:44:02 < 6415> free 0x80602e8 (com-config.c:126)
14:44:02 < 6415> free 0x80602c8 (com-config.c:127)
14:44:02 < 6415> free 0x8060308 (com-config.c:124)
14:44:02 < 6415> free 0x8060320 (com-config.c:126)
14:44:02 < 6415> free 0x80602f8 (com-config.c:127)
14:44:02 < 6415> free 0x805fc18 (com-config.c:131)
14:44:02 < 6415> ------------- ftp-child exiting -------------
14:44:02 < 6281> client pid=6415 (192.53.104.46) gone