Strange FTP problem

From: lawries@btinternet.com
Date: Thu Apr 10 2003 - 07:04:03 EDT


I have a strange FTP problem that perhaps someone can shine some light on.
A user of these servers (ES40 Tru64 V5.1 PK3) has been successfully using an FTP script
for many months. They are now looking to change their own internel network IP range.
Stangely, FTP no longer seems to work correctly. (They are using the same username and password)
They are using the WRQ Reflection FTP client. Session log snippets from both server (ftpd -d)
and client are below.

An FTP connection is established and commands like cd and ls work OK.
However, any "action" commands fail, although no error is generated.

We can see from both the session logs below that an FTP connection is sucessfully
made and thatcommands are accepted and performed without error by the FTP server.
There are no O/S derived errors or "permissions refused" It looks as if none of
the action commands are actually performed during the connection from the new subnet.

I believe that this is because, each time an action command is issued, the FTP session
performs a LIST action to ensure that the target file is present.
During the connection from the new sub-net every command seems to get
a "File or directory not found" response, so the action is not taken.

>From the existing (working) subnet client log, using a DELETE section as example:

04/09/2003 14:31:42 mdel NORT*.SWFTYPE A
04/09/2003 14:31:42 200 Type set to A.
04/09/2003 14:31:42 PORT 192,1,6,203,5,197
04/09/2003 14:31:42 200 PORT command successful.
04/09/2003 14:31:42 LIST -d NORT*.SWF
04/09/2003 14:31:42 150 Opening ASCII mode data connection for /bin/ls (10.150.xxx.xxx,28000).
04/09/2003 14:31:42 -rw-rw---- 1 jamfitzh users 3837 Apr 9 14:08 NORT010230.SWF
04/09/2003 14:31:43 226 Transfer complete.
04/09/2003 14:31:43 DELE NORT010230.SWF
04/09/2003 14:31:43 250 DELE command successful.
04/09/2003 14:31:43 PORT 192,1,6,203,5,199
04/09/2003 14:31:43 200 PORT command successful.
04/09/2003 14:31:43 LIST
04/09/2003 14:31:43 150 Opening ASCII mode data connection for /bin/ls (10.150.xxx.xxx,28994).
04/09/2003 14:31:43 total 0
04/09/2003 14:31:44 226 Transfer complete.
04/09/2003 14:31:44 quitQUIT

And the ftpd -d log from the server of same transaction

Apr 9 14:30:32 cap007 ftpd[880509]: command: LIST -d NORT*.SWF^M
Apr 9 14:30:32 cap007 ftpd[880509]: <--- 150 Opening ASCII mode data connection for /bin/ls (10.150.xxx.xxx,28000).
Apr 9 14:30:32 cap007 ftpd[880509]: <--- 226 Transfer complete.
Apr 9 14:30:32 cap007 ftpd[880509]: /bin/ls -lgA -d NORT*.SWF (cwd=/xxx/xxx/xxx/ntrust) succeeded, 69 bytes.
Apr 9 14:30:33 cap007 ftpd[880509]: command: DELE NORT010230.SWF^M
Apr 9 14:30:33 cap007 ftpd[880509]: <--- 250 DELE command successful.
Apr 9 14:30:33 cap007 ftpd[880509]: command: PORT 10,150,11,196,113,66^M
Apr 9 14:30:33 cap007 ftpd[880509]: <--- 200 PORT command successful.

=========================================================================================
And now from the new (failing) subnet client log

04/09/2003 14:23:49 mdel NORT*.SWFPORT 10,70,110,58,4,23
04/09/2003 14:23:49 150 Opening ASCII mode data connection for /bin/ls (10.70.xxx.xxx,1046).
04/09/2003 14:23:49 LIST -d NORT*.SWF
04/09/2003 14:23:49 226 Transfer complete.
04/09/2003 14:23:49 File or directory not found.
04/09/2003 14:23:49 200 PORT command successful.
04/09/2003 14:23:49 PORT 10,70,110,58,4,24
04/09/2003 14:23:49 150 Opening ASCII mode data connection for /bin/ls (10.70.xxx.xxx,1047).
04/09/2003 14:23:49 LIST
04/09/2003 14:23:49 226 Transfer complete.
04/09/2003 14:23:49 quitQUIT

Any the server ftpd -d log of the same:

Apr 9 14:12:30 cap007 ftpd[882395]: /bin/ls -lgA -d NORT*.SWF (cwd=/xxx/xxx/xxx/ntrust) succeeded, 69 bytes.
Apr 9 14:12:30 cap007 ftpd[882395]: command: PORT 10,70,110,58,4,23^M
Apr 9 14:12:30 cap007 ftpd[882395]: <--- 200 PORT command successful.
Apr 9 14:12:30 cap007 ftpd[882395]: command: LIST -d NORT*.SWF^M
Apr 9 14:12:30 cap007 ftpd[882395]: <--- 150 Opening ASCII mode data connection for /bin/ls (10.70.xxx.xxx,1047).
Apr 9 14:12:30 cap007 ftpd[882395]: <--- 226 Transfer complete.
Apr 9 14:12:30 cap007 ftpd[882395]: /bin/ls -lgA -d NORT*.SWF (cwd=/xxx/xxx/xxx/ntrust) succeeded, 69 bytes.
Apr 9 14:12:30 cap007 ftpd[882395]: command: PORT 10,70,110,58,4,24^M
Apr 9 14:12:30 cap007 ftpd[882395]: <--- 200 PORT command successful.
Apr 9 14:12:30 cap007 ftpd[882395]: command: LIST^M
Apr 9 14:12:30 cap007 ftpd[882395]: <--- 425 Can't build data connection: Connection refused.
Apr 9 14:12:30 cap007 ftpd[882395]: /bin/ls -lgA (cwd=/xxx/xxx/xxx/ntrust) failed
Apr 9 14:12:30 cap007 ftpd[882395]: command: QUIT^M

Is anyone able to identify why this is happening?

Lawrie



This archive was generated by hypermail 2.1.7 : Sat Apr 12 2008 - 10:49:15 EDT