Subject: Re: Lost connection

From: "M B" <[email-masked]>
Date: Sun, 01 Apr 2001 01:34:10 -0500

At the time the problem fall on my lap I had no access to any of the
implicated servers! But I can answer your question: The Sun server is
an E450 running Solaris 2.6. The client is an x86 running NT 4.

On Monday once I get access to these machines, I will put a sniffer
on the NT side, then run a snoop on the Sun server. Here is all the
information I have so far:

LAN1.....T1.....LAN2.....FR.....LAN3

. T1 = T1 link.
. FR = Frame Relay.
. LAN1 = Network where the NT machine resides.
. LAN3 = Network where the Sun machine resides.
. LAN2 = The network between the two Networks. LAN2 and LAN3
         are privately connected. No other possible path from LAN1
         to LAN3 other than LAN2.
. LAN1, LAN2 and LAN 3 are 100Base-T.
. FTP transfers between LAN1 and LAN2 succeed.
. FTP transfers between LAN2 and LAN3 succeed.
. FTP transfers between LAN1 and LAN3 fail.

1- Here is the log of a typical ftp session (look at the time stamps):
<BEGIN>
Mar 30 10:44:54 oh44ux01 ftpd[21340]: FTPD: connection from 172.28.2.7 at 
Fri Mar 30 10:44:54 2001
Mar 30 10:44:54 oh44ux01 ftpd[21340]: <--- 220
Mar 30 10:44:54 oh44ux01 ftpd[21340]: oh44ux01 FTP server (SunOS 5.6) ready.
Mar 30 10:44:59 oh44ux01 ftpd[21340]: FTPD: command: USER test
Mar 30 10:44:59 oh44ux01 ftpd[21340]: <--- 331
Mar 30 10:44:59 oh44ux01 ftpd[21340]: Password required for test.
Mar 30 10:45:04 oh44ux01 ftpd[21340]: FTPD: command: PASS <passwd>
Mar 30 10:45:04 oh44ux01 ftpd[21340]: <--- 230
Mar 30 10:45:04 oh44ux01 ftpd[21340]: User test logged in.
Mar 30 10:45:14 oh44ux01 ftpd[21340]: FTPD: command: TYPE I
Mar 30 10:45:14 oh44ux01 ftpd[21340]: <--- 200
Mar 30 10:45:14 oh44ux01 ftpd[21340]: Type set to I.
Mar 30 10:45:22 oh44ux01 ftpd[21340]: FTPD: command: PORT 172,28,2,7,10,64
Mar 30 10:45:22 oh44ux01 ftpd[21340]: <--- 200
Mar 30 10:45:22 oh44ux01 ftpd[21340]: PORT command successful.
Mar 30 10:45:22 oh44ux01 ftpd[21340]: FTPD: command: STOR 00000100006002.pdf
Mar 30 10:45:23 oh44ux01 ftpd[21340]: <--- 150
Mar 30 10:45:23 oh44ux01 ftpd[21340]: Binary data connection for 
00000100006002.pdf (172.28.2.7,2624).
Mar 30 12:56:51 oh44ux01 ftpd[21340]: lost connection
<END>

2- Another session where several files were transfered then there was a time 
out:

[cut]
Mar 27 17:09:49 oh44ux01 ftpd[6915]: <--- 150
Mar 27 17:09:49 oh44ux01 ftpd[6915]: ASCII data connection for /bin/ls 
(172.28.2.7,2115) (0 bytes).
Mar 27 17:09:49 oh44ux01 ftpd[6915]: <--- 226
Mar 27 17:09:49 oh44ux01 ftpd[6915]: ASCII Transfer complete.
Mar 27 17:12:49 oh44ux01 ftpd[6915]: FTPD: command: NOOP
Mar 27 17:12:49 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:12:49 oh44ux01 ftpd[6915]: NOOP command successful.
Mar 27 17:15:49 oh44ux01 ftpd[6915]: FTPD: command: NOOP
Mar 27 17:15:49 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:49 oh44ux01 ftpd[6915]: NOOP command successful.
Mar 27 17:15:55 oh44ux01 ftpd[6915]: FTPD: command: TYPE I
Mar 27 17:15:55 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:55 oh44ux01 ftpd[6915]: Type set to I.
Mar 27 17:15:55 oh44ux01 ftpd[6915]: FTPD: command: PORT 172,28,2,7,8,214
Mar 27 17:15:55 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:55 oh44ux01 ftpd[6915]: PORT command successful.
Mar 27 17:15:55 oh44ux01 ftpd[6915]: FTPD: command: STOR 00000184159044.pdf
Mar 27 17:15:56 oh44ux01 ftpd[6915]: <--- 150
Mar 27 17:15:56 oh44ux01 ftpd[6915]: Binary data connection for 
00000184159044.pdf (172.28.2.7,2262).
Mar 27 17:15:56 oh44ux01 ftpd[6915]: <--- 226
Mar 27 17:15:56 oh44ux01 ftpd[6915]: Transfer complete.
Mar 27 17:15:56 oh44ux01 ftpd[6915]: FTPD: command: TYPE I
Mar 27 17:15:56 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:56 oh44ux01 ftpd[6915]: Type set to I.
Mar 27 17:15:56 oh44ux01 ftpd[6915]: FTPD: command: PORT 172,28,2,7,8,215
Mar 27 17:15:56 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:56 oh44ux01 ftpd[6915]: PORT command successful.
Mar 27 17:15:56 oh44ux01 ftpd[6915]: FTPD: command: STOR 00000190101016.pdf
Mar 27 17:15:56 oh44ux01 ftpd[6915]: <--- 150
Mar 27 17:15:56 oh44ux01 ftpd[6915]: Binary data connection for 
00000190101016.pdf (172.28.2.7,2263).
Mar 27 17:15:57 oh44ux01 ftpd[6915]: <--- 226
Mar 27 17:15:57 oh44ux01 ftpd[6915]: Transfer complete.
Mar 27 17:15:57 oh44ux01 ftpd[6915]: FTPD: command: TYPE I
Mar 27 17:15:57 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:57 oh44ux01 ftpd[6915]: Type set to I.
Mar 27 17:15:57 oh44ux01 ftpd[6915]: FTPD: command: PORT 172,28,2,7,8,216
Mar 27 17:15:57 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:57 oh44ux01 ftpd[6915]: PORT command successful.
Mar 27 17:15:57 oh44ux01 ftpd[6915]: FTPD: command: STOR 00000192097033.pdf
Mar 27 17:15:57 oh44ux01 ftpd[6915]: <--- 150
Mar 27 17:15:57 oh44ux01 ftpd[6915]: Binary data connection for 
00000192097033.pdf (172.28.2.7,2264).
Mar 27 17:15:58 oh44ux01 ftpd[6915]: <--- 226
Mar 27 17:15:58 oh44ux01 ftpd[6915]: Transfer complete.
Mar 27 17:15:58 oh44ux01 ftpd[6915]: FTPD: command: TYPE I
Mar 27 17:15:58 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:58 oh44ux01 ftpd[6915]: Type set to I.
Mar 27 17:15:58 oh44ux01 ftpd[6915]: FTPD: command: PORT 172,28,2,7,8,217
Mar 27 17:15:58 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:58 oh44ux01 ftpd[6915]: PORT command successful.
Mar 27 17:15:58 oh44ux01 ftpd[6915]: FTPD: command: STOR 00000192213008.pdf
Mar 27 17:15:58 oh44ux01 ftpd[6915]: <--- 150
Mar 27 17:15:58 oh44ux01 ftpd[6915]: Binary data connection for 
00000192213008.pdf (172.28.2.7,2265).
Mar 27 17:15:59 oh44ux01 ftpd[6915]: <--- 226
Mar 27 17:15:59 oh44ux01 ftpd[6915]: Transfer complete.
Mar 27 17:15:59 oh44ux01 ftpd[6915]: FTPD: command: TYPE I
Mar 27 17:15:59 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:59 oh44ux01 ftpd[6915]: Type set to I.
Mar 27 17:15:59 oh44ux01 ftpd[6915]: FTPD: command: PORT 172,28,2,7,8,219
Mar 27 17:15:59 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:15:59 oh44ux01 ftpd[6915]: PORT command successful.
Mar 27 17:15:59 oh44ux01 ftpd[6915]: FTPD: command: STOR 00000196271002.pdf
Mar 27 17:15:59 oh44ux01 ftpd[6915]: <--- 150
Mar 27 17:15:59 oh44ux01 ftpd[6915]: Binary data connection for 
00000196271002.pdf (172.28.2.7,2267).
Mar 27 17:16:00 oh44ux01 ftpd[6915]: <--- 226
Mar 27 17:16:00 oh44ux01 ftpd[6915]: Transfer complete.
Mar 27 17:16:00 oh44ux01 ftpd[6915]: FTPD: command: TYPE I
Mar 27 17:16:00 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:16:00 oh44ux01 ftpd[6915]: Type set to I.
Mar 27 17:16:00 oh44ux01 ftpd[6915]: FTPD: command: PORT 172,28,2,7,8,220
Mar 27 17:16:00 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:16:00 oh44ux01 ftpd[6915]: PORT command successful.
Mar 27 17:16:00 oh44ux01 ftpd[6915]: FTPD: command: STOR 00000198177007.pdf
Mar 27 17:16:00 oh44ux01 ftpd[6915]: <--- 150
Mar 27 17:16:00 oh44ux01 ftpd[6915]: Binary data connection for 
00000198177007.pdf (172.28.2.7,2268).
Mar 27 17:16:01 oh44ux01 ftpd[6915]: <--- 226
Mar 27 17:16:01 oh44ux01 ftpd[6915]: Transfer complete.
Mar 27 17:16:01 oh44ux01 ftpd[6915]: FTPD: command: TYPE I
Mar 27 17:16:01 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:16:01 oh44ux01 ftpd[6915]: Type set to I.
Mar 27 17:16:01 oh44ux01 ftpd[6915]: FTPD: command: PORT 172,28,2,7,8,221
Mar 27 17:16:01 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:16:01 oh44ux01 ftpd[6915]: PORT command successful.
Mar 27 17:16:01 oh44ux01 ftpd[6915]: FTPD: command: STOR 00000198191008.pdf
Mar 27 17:16:01 oh44ux01 ftpd[6915]: <--- 150
Mar 27 17:16:01 oh44ux01 ftpd[6915]: Binary data connection for 
00000198191008.pdf (172.28.2.7,2269).
Mar 27 17:16:02 oh44ux01 ftpd[6915]: <--- 226
Mar 27 17:16:02 oh44ux01 ftpd[6915]: Transfer complete.
Mar 27 17:16:02 oh44ux01 ftpd[6915]: FTPD: command: TYPE I
Mar 27 17:16:02 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:16:02 oh44ux01 ftpd[6915]: Type set to I.
Mar 27 17:16:02 oh44ux01 ftpd[6915]: FTPD: command: PORT 172,28,2,7,8,223
Mar 27 17:16:02 oh44ux01 ftpd[6915]: <--- 200
Mar 27 17:16:02 oh44ux01 ftpd[6915]: PORT command successful.
Mar 27 17:16:02 oh44ux01 ftpd[6915]: FTPD: command: STOR 00000199138008.pdf
Mar 27 17:16:02 oh44ux01 ftpd[6915]: <--- 150
Mar 27 17:16:02 oh44ux01 ftpd[6915]: Binary data connection for 
00000199138008.pdf (172.28.2.7,2271).
Mar 27 19:27:28 oh44ux01 ftpd[6915]: <--- 552
Mar 27 19:27:28 oh44ux01 ftpd[6915]: 00000199138008.pdf: Connection timed 
out.
Mar 27 19:27:28 oh44ux01 ftpd[6915]: FTPD: command: TYPE I
Mar 27 19:27:28 oh44ux01 ftpd[6915]: <--- 200
Mar 27 19:27:28 oh44ux01 ftpd[6915]: Type set to I.
Mar 27 19:27:28 oh44ux01 ftpd[6915]: <--- 221
Mar 27 19:27:28 oh44ux01 ftpd[6915]: You could at least say goodbye.
<END>
_________________________________________________________________
Get your FREE download of MSN Explorer at http://explorer.msn.com

---

From: "Hal F. Gottfried" <[email-masked]>
Date: Sun, 1 Apr 2001 10:23:10 -0400

I am heading out on business all next week, I'll connect from the hotel on
my laptop and look over your session and information. I have Windows and
Solaris on my laptop so maybe I can check a few things I am thinking off.
Also on Monday send me your syslogs from the Scoop and Sniffer if you can so
I check my theories.

- H

---

From: Jon Snader <[email-masked]>
Date: Sun, 1 Apr 2001 12:19:36 -0400

> Mar 30 12:56:51 oh44ux01 ftpd[21340]: lost connection

[another example deleted]

I notice that in both cases the connection drops after about 2 hours into
a data transfer, and that the control connection appears to be idle for
that time.  I have seen examples where stateful firewalls or NAT devices
will time out idle connections after time intervals that are typically
in the 2 hour range.  Have you investigated this possibility?

Jon Snader