Hi Yutaka,

Yutaka Sato wrote:
> Seeing what the difference is between the case of the failure and the
>  success will be helpful.

Please find the following two logs that hopefully will start to explain
what I'm troubled with. I'm pretty sure the problem _only_ occurs when
Delegate negotiates a TLS FTP session with the remote. It doesn't seem
to happen if the remote is plain FTP. The IP addresses have been
sanitised; hopefully they still make sense.

Delegate is started (on port 221) like this:

#!/bin/bash
~delegate/TEST/delegated -P221  SERVER=ftp CACHE=no STLS=-fsv -v \
 AUTH="anonftp:*:*" \
 OWNER='delegate/delegate' \
 DGROOT='/home/delegate/TEST' \
 LOGDIR='logs' \
 LOGFILE='[date+%Y-%m.ftp]' \
 PROTOLOG='xferlog.[date+%Y-%m.ftp]' \
 WORKDIR='work' \
 CACHEDIR='cache' \
 MAXIMA='listen:64' \
 PERMIT="ftp:*:*"


Here is a successful connect with ftp.demon.co.uk which does _not_ have
TLS support.

11/30 13:05:38.11 [32524] 0+0: --INITIALIZATION DONE-06113013+0100: 9.4.0-pre17 on Linux/2.6.8-2-386--
11/30 13:05:43.86 [32526] 1+0: -- Fork(OnetimeServer): 32524 -> 32526
11/30 13:05:43.86 [32526] 1+0: (0) accepted [25] -@[127.0.0.1]localhost:2447 (0.003s)(1)
11/30 13:05:43.86 [32526] 1+0: PATH: ftp://-:21!localhost:221!localhost:2447!anonymous@localhost;1164891943
11/30 13:05:43.87 [32526] 1+0: FTP server ftp://-:21/
11/30 13:05:43.87 [32526] 1+0: *** / => file://localhost/-stab-/ ***
11/30 13:05:43.87 [32526] 1+0: MOUNTED-TO-STAB: file://localhost/-stab-/
11/30 13:05:43.87 [32526] 1+0: -- putBuiltinHTML: empty ftp-banner-postfix.dhtml
11/30 13:05:43.88 [32526] 1+0: bind_insock(18,127.0.0.1,0) = 0, errno=0
11/30 13:05:43.89 [32526] 1+0: #### no authorization required
11/30 13:05:49.43 [32526] 1+0/1: #### AUTH SSL
11/30 13:05:49.45 [32526] 1+0/2: FTP LOGIN FROM localhost TO ftp@demon..uk
11/30 13:05:49.45 [32526] 1+0/2: rewritten to: CWD //ftp@demon..uk^M
11/30 13:05:52.25 [32526] 1+0/3: FTP LOGIN FROM localhost TO ftp@demon..uk
11/30 13:05:52.25 [32526] 1+0/3: PATH: ftp://ftp.demon.co.uk:21!localhost:221!localhost:2447!anonymous@localhost;1164891943
11/30 13:05:52.26 [32526] 1+0/3: FTP server ftp://ftp.demon.co.uk:21/
11/30 13:05:52.26 [32526] 1+0/3: FTPHOPS: 1 [11/25 - -1/-1]
11/30 13:05:52.26 [32526] 1+0/3: ConnectToServer: DFLT=ftp://ftp.demon.co.uk:21 REAL=://:0
11/30 13:05:52.29 [32526] 1+0/3: ConnectToServer connected [19] {194.159.255.135:21 <- 192.168.21.7:2450} [0.027s]
11/30 13:05:52.29 [32526] 1+0/3: willSTLS_SV: ServerFlags=70
11/30 13:05:52.29 [32526] 1+0/3: inherited AsProxy: 10010
11/30 13:05:52.33 [32526] 1+0/3: willSTLS_SV: ServerFlags=70
11/30 13:05:52.55 [32526] 1+0/3: LoginPWD: "/"
11/30 13:05:54.31 [32526] 1+0/5/2: ftp_conndata: connected 192.168.2.17:2449->disabuse.ftp.demon.net/194.159.255.135:61257 [20](0.0)
11/30 13:05:54.31 [32526] 1+0/5/2: -- with PASV
11/30 13:05:54.31 [32526] 1+0/5/2: PORT [127,0,0,1,9,147] >> 200 PORT command successful [translated to PASV by DeleGate].^M
11/30 13:05:54.33 [32526] 1+0/6/3: --SU NONE /home/delegate/TEST/sudo/port/P
11/30 13:05:54.33 [32526] 1+0/6/3: ## dgbind = /home/delegate/TEST/subin/dgbind
11/30 13:05:54.34 [32526] 1+0/6/3: ftp_conndata: connected 127.0.0.1:220->localhost/127.0.0.1:2451 [21](0.0)
11/30 13:05:54.34 [32526] 1+0/6/3: DATA 194.159.255.135:61257 -> 192.168.2.17:2449 .. 127.0.0.1:220 -> 127.0.0.1:2451
11/30 13:05:54.34 [32526] 1+0/6/3: FTP data-relay([20]15554b -> [21]c594b) 486b / 1/ (1A) 0.00s (read-EOF)
11/30 13:05:56.18 [32526] 1+0/7/4: disconnected [25] -@[127.0.0.1]localhost:2447 (12.326s)(0)
11/30 13:05:59.39 [32524] 1+0: DeleGate SERVER EXITS: caught SIGINT [2]


and here is the extract from ftp.qinetiq.com which _does_ have TLS support.

11/30 12:46:45.98 [29960] 1+0: -- Fork(OnetimeServer): 29958 -> 29960
11/30 12:46:45.98 [29960] 1+0: (0) accepted [42] -@[127.0.0.1]localhost:2402 (0.003s)(1)
11/30 12:46:45.98 [29960] 1+0: PATH: ftp://-:21!localhost:221!localhost:2402!anonymous@localhost;1164890805
11/30 12:46:45.99 [29960] 1+0: FTP server ftp://-:21/
11/30 12:46:45.99 [29960] 1+0: *** / => file://localhost/-stab-/ ***
11/30 12:46:45.99 [29960] 1+0: MOUNTED-TO-STAB: file://localhost/-stab-/
11/30 12:46:45.99 [29960] 1+0: -- putBuiltinHTML: empty ftp-banner-postfix.dhtml
11/30 12:46:45.99 [29960] 1+0: bind_insock(18,127.0.0.1,0) = 0, errno=0
11/30 12:46:45.99 [29960] 1+0: #### no authorization required
11/30 12:46:51.45 [29960] 1+0/1: #### AUTH SSL
11/30 12:46:51.45 [29960] 1+0/2: FTP LOGIN FROM localhost TO sbrown@qinetiq..
11/30 12:46:51.45 [29960] 1+0/2: rewritten to: CWD //sbrown@qinetiq..^M
11/30 12:46:55.97 [29960] 1+0/3: FTP LOGIN FROM localhost TO sbrown@qinetiq..
11/30 12:46:55.97 [29960] 1+0/3: PATH: ftp://ftp.qinetiq.com:21!localhost:221!localhost:2402!anonymous@localhost;1164890805
11/30 12:46:55.98 [29960] 1+0/3: FTP server ftp://ftp.qinetiq.com:21/
11/30 12:46:55.98 [29960] 1+0/3: FTPHOPS: 1 [11/42 - -1/-1]
11/30 12:46:55.98 [29960] 1+0/3: ConnectToServer: DFLT=ftp://ftp.qinetiq.com:21 REAL=://:0
11/30 12:46:55.98 [29960] 1+0/3: ConnectToServer connected [19] {192.168.1.14:21 <- 192.168.2.17:2404} [0.001s]
11/30 12:46:55.98 [29960] 1+0/3: willSTLS_SV: ServerFlags=70
11/30 12:46:55.98 [29960] 1+0/3: inherited AsProxy: 10010
11/30 12:46:56.30 [29960] 1+0/3: willSTLS_SV: ServerFlags=70
11/30 12:46:56.30 [29960] 1+0/3: willSTLS_SV: ServerFlags=70
11/30 12:46:56.30 [29962] 1+0/3: -- Fork(FSV): 29960 -> 29962
11/30 12:46:56.30 [29962] 1+0/3: ## SSLway loadSession 0.000146 (0 0) / -1
11/30 12:46:56.40 [29962] 1+0/3: ## SSLway ## 0.102892 connected/accepted
11/30 12:46:56.40 [29962] 1+0/3: ## SSLway server's cert. = **subject<</C=GB/ST= **SNIPPED**
11/30 12:46:56.49 [29960] 1+0/3: LoginPWD: "/sbrown"
11/30 12:46:59.41 [29960] 1+0/5/2: ## viaCFI [mkPASV]: fileno(ts)=19 ToSX=20
11/30 12:46:59.41 [29960] 1+0/5/2: ## viaCFI [mkPASV]: fileno(ts)=19 ToSX=20
11/30 12:46:59.41 [29960] 1+0/5/2: ftp_conndata: connection refused 192.168.2.17:2403->ftp.qinetiq.com/192.168.1.14:48632, errno=111
11/30 12:46:59.41 [29960] 1+0/5/2: ftp_conndata: retry without port# (2403)
11/30 12:46:59.41 [29960] 1+0/5/2: ftp_conndata: connection refused 192.168.2.17:2406->ftp.qinetiq.com/192.168.1.14:48632, errno=111
11/30 12:46:59.41 [29960] 1+0/5/2: ## viaCFI [mkPORT]: fileno(ts)=19 ToSX=20
11/30 12:46:59.41 [29960] 1+0/5/2: FTP-control-remote: 192.168.1.14:21 [20]
11/30 12:46:59.41 [29960] 1+0/5/2: FTP-data-local[21]: 192.168.2.17:2407
11/30 12:46:59.41 [29960] 1+0/5/2: PORT [127,0,0,1,9,101] >> 500 Illegal PORT command^M
11/30 12:47:01.71 [29960] 1+0/6/3: disconnected [42] -@[127.0.0.1]localhost:2402 (15.739s)(0)
11/30 12:47:01.82 [29960] 1+0/6/3: CFI process [29962] done (1/1 AFT-1)
11/30 12:47:07.56 [29958] 1+0: DeleGate SERVER EXITS: caught SIGINT [2]

which you can see doesn't work. I'd be really grateful for any pointers!

Steve