[nos-bbs] timeouts when incoming command ends with CR only
Michael Fox - N6MEF
n6mef at mefox.org
Tue Apr 19 10:21:26 EDT 2016
I continue to see a few timeouts on INBOUND connections from FBB, when FBB
ends a command with only CR. Note that FBB usually sends CRLF at the end of
each line. But sometimes it only sends CR.
For what it's worth, FBB doesn't seem to care if the other end uses CR or
CRLF at the end of each line. But evidently JNOS does care. When it gets a
line ending with just CR, it can hang, presumably waiting for the LF
character.
Perhaps this is because the "cronly" option in forward.fbb only applies to
outbound connections. It seems to me that if CRONLY is needed for a
partner, then it is needed for both inbound and outbound.
Three examples are provided below, with log and telnet trace.
Michael
N6MEF
EXAMPLE 1:
See 4th to last packet in the telnet trace. FBB sends "F> 80" with only CR
at the end. JNOS sits and waits for 5 minutes. FBB times out after 5
minutes of waiting for JNOS to respond.
Nos.log:
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) login
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) open
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) forwarding
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) incoming
proposal FA B G8MNY WW TECH 1845_GB7CIP 3178
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) incoming
proposal FA B G8MNY WW TECH 1846_GB7CIP 6907
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) incoming
proposal FA B G8MNY WW TECH 1846_GB7CIP 6941
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) our response FS
+++
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) lzhuf uncompress
1582/3253 = 51 percent
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) 1845_GB7CIP
received
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) lzhuf uncompress
3125/6982 = 55 percent
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) 1846_GB7CIP
received
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) lzhuf uncompress
3194/7160 = 55 percent
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) 1846_GB7CIP
received
Tue Apr 19 02:15:19 2016 67.174.37.45:55863 - MBOX (n6rme) incoming
proposal FA B G8MNY WW TECH 1847_GB7CIP 4792
Tue Apr 19 02:20:19 2016 67.174.37.45:55863 - MBOX (n6rme) FBB error, last
read : > 80
Tue Apr 19 02:20:19 2016 67.174.37.45:55863 - MBOX (n6rme) exit
telnet trace:
Date/Time Src
Dst Telnet_Data
Apr 19, 2016 02:15:19.121596000 N6MEF n6rme \x0d\x0a,JNOS
(n6mef.ampr.org)\x0d\x0a,\x0d\x0a,login:
Apr 19, 2016 02:15:19.205587000 n6rme N6MEF
N6RME\x0d\x0a,********\x0d\x0a
Apr 19, 2016 02:15:19.205958000 N6MEF n6rme Password:
Apr 19, 2016 02:15:19.227204000 N6MEF n6rme
\x0d\x0a,[JNOS-2.0j.7v.XSC32.4-BFHIM$]\x0d\x0a,>\x0d\x0a
Apr 19, 2016 02:15:19.308773000 n6rme N6MEF
[FBB-7.05f-ABFHM$]\x0d\x0a,FA B G8MNY WW TECH 1845_GB7CIP 3178\x0d\x0a,FA B
G8MN
Apr 19, 2016 02:15:19.339113000 n6rme N6MEF Y WW TECH 1846_GB7CIP
6907\x0d\x0a,FA B G8MNY WW TECH 1846_GB7CIP 6941\x0d\x0a,F
Apr 19, 2016 02:15:19.360241000 n6rme N6MEF > 89\x0d\x0a
Apr 19, 2016 02:15:19.366717000 N6MEF n6rme FS +++\x0d\x0a
Apr 19, 2016 02:15:19.464559000 n6rme N6MEF \x01(Rotator Hishmann
Hit Ro 250 info
Apr 19, 2016 02:15:19.486556000 n6rme N6MEF
\xcef'k\x0b\x17\xb3\xd1\[.several packets of binary data clipped.]
Apr 19, 2016 02:15:19.884360000 N6MEF n6rme FF\x0d\x0a
Apr 19, 2016 02:15:19.959396000 n6rme N6MEF FA B G8MNY WW TECH
1847_GB7CIP 4792\x0dF> 80\x0d
Apr 19, 2016 02:20:19.037371000 n6rme N6MEF *** Timeout !!\x0d
Apr 19, 2016 02:20:19.038071000 N6MEF n6rme FQ\x0d\x0a
Apr 19, 2016 02:20:19.589168000 N6MEF n6rme FQ\x0d\x0a
EXAMPLE 2:
See 4th to last packet in the telnet trace. FBB sends "FF" with only CR at
the end. JNOS sits and waits for 5 minutes. FBB times out after 5 minutes
of waiting for JNOS to respond.
Nos.log:
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) login
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) open
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) forwarding
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) incoming
proposal FA B G8MNY WW TECH 1847_GB7CIP 4792
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) incoming
proposal FA B F3KT WW PACTOR 53984_F3KT 3103
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) already have
1847_GB7CIP
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) our response FS
-+
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) lzhuf uncompress
1321/3177 = 58 percent
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) 53984_F3KT
received
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) proposal FA B
G8MNY WW TECH 1846_GB7CIP 7381
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) proposal FA B
G8MNY WW TECH 1845_GB7CIP 3734
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) proposal FA B
G8MNY WW TECH 1847_GB7CIP 5398
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) got response FS
---
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) $1846_gb7cip
refused
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) $1845_gb7cip
refused
Tue Apr 19 02:30:14 2016 67.174.37.45:55872 - MBOX (n6rme) $1847_gb7cip
refused
Tue Apr 19 02:35:14 2016 67.174.37.45:55872 - MBOX (n6rme) FBB error, last
read : F
Tue Apr 19 02:35:14 2016 67.174.37.45:55872 - MBOX (n6rme) exit
telnet trace:
Date/Time Src
Dst Telnet_Data
Apr 19, 2016 02:30:14.218177000 N6MEF n6rme \x0d\x0a,JNOS
(n6mef.ampr.org)\x0d\x0a,\x0d\x0a,login:
Apr 19, 2016 02:30:14.301867000 n6rme N6MEF
N6RME\x0d\x0a,********\x0d\x0a
Apr 19, 2016 02:30:14.302268000 N6MEF n6rme Password:
Apr 19, 2016 02:30:14.323855000 N6MEF n6rme
\x0d\x0a,[JNOS-2.0j.7v.XSC32.4-BFHIM$]\x0d\x0a,>\x0d\x0a
Apr 19, 2016 02:30:14.405187000 n6rme N6MEF
[FBB-7.05f-ABFHM$]\x0d\x0a,FA B G8MNY WW TECH 1847_GB7CIP 4792\x0d\x0a,FA B
F3KT
Apr 19, 2016 02:30:14.426575000 n6rme N6MEF WW PACTOR 53984_F3KT
3103\x0d\x0a,F> 10\x0d\x0a
Apr 19, 2016 02:30:14.428840000 N6MEF n6rme FS -+\x0d\x0a
Apr 19, 2016 02:30:14.580874000 n6rme N6MEF \x01\x18F3KT PACTOR
INFO
Apr 19, 2016 02:30:14.602001000 n6rme N6MEF
^\x1e\xfd\x8d\x1a}\[.binary data clipped.]
Apr 19, 2016 02:30:14.664836000 N6MEF n6rme FA B G8MNY WW TECH
1846_GB7CIP 7381\x0d\x0a,FA B G8MNY WW TECH 1845_GB7CIP 3734\x0d\x0a,FA B
G8MNY WW TECH 1847_GB7CIP 5398\x0d\x0a,F>\x0d\x0a
Apr 19, 2016 02:30:14.742650000 n6rme N6MEF FS ---\x0d
Apr 19, 2016 02:30:14.765539000 n6rme N6MEF FF\x0d
Apr 19, 2016 02:35:14.056411000 n6rme N6MEF *** Timeout !!\x0d
Apr 19, 2016 02:35:14.057370000 N6MEF n6rme FQ\x0d\x0a
Apr 19, 2016 02:35:14.608215000 N6MEF n6rme FQ\x0d\x0a
EXAMPLE 3:
See 4th to last packet in the telnet trace. FBB sends "FF" with only CR at
the end. JNOS sits and waits for 5 minutes. FBB times out after 5 minutes
of waiting for JNOS to respond.
Nos.log:
Tue Apr 19 02:45:10 2016 67.174.37.45:55881 - MBOX (n6rme) login
Tue Apr 19 02:45:10 2016 67.174.37.45:55881 - MBOX (n6rme) open
Tue Apr 19 02:45:10 2016 67.174.37.45:55881 - MBOX (n6rme) forwarding
Tue Apr 19 02:45:10 2016 67.174.37.45:55881 - MBOX (n6rme) incoming
proposal FA B GM3YEW WW HUMOUR 28913_GB7YEW 11393
Tue Apr 19 02:45:10 2016 67.174.37.45:55881 - MBOX (n6rme) our response FS
+
Tue Apr 19 02:45:11 2016 67.174.37.45:55881 - MBOX (n6rme) lzhuf uncompress
4832/11788 = 59 percent
Tue Apr 19 02:45:11 2016 67.174.37.45:55881 - MBOX (n6rme) 28913_GB7YEW
received
Tue Apr 19 02:45:11 2016 67.174.37.45:55881 - MBOX (n6rme) proposal FA B
F3KT WW PACTOR 53984_F3KT 3611
Tue Apr 19 02:45:11 2016 67.174.37.45:55881 - MBOX (n6rme) got response FS
-
Tue Apr 19 02:45:11 2016 67.174.37.45:55881 - MBOX (n6rme) $53984_f3kt
refused
Tue Apr 19 02:50:11 2016 67.174.37.45:55881 - MBOX (n6rme) FBB error, last
read : F
Tue Apr 19 02:50:11 2016 67.174.37.45:55881 - MBOX (n6rme) exit
telnet trace:
Date/Time Src
Dst Telnet_Data
Apr 19, 2016 02:45:10.337626000 N6MEF n6rme \x0d\x0a,JNOS
(n6mef.ampr.org)\x0d\x0a,\x0d\x0a,login:
Apr 19, 2016 02:45:10.420166000 n6rme N6MEF
N6RME\x0d\x0a,********\x0d\x0a
Apr 19, 2016 02:45:10.420606000 N6MEF n6rme Password:
Apr 19, 2016 02:45:10.441654000 N6MEF n6rme
\x0d\x0a,[JNOS-2.0j.7v.XSC32.4-BFHIM$]\x0d\x0a,>\x0d\x0a
Apr 19, 2016 02:45:10.524374000 n6rme N6MEF
[FBB-7.05f-ABFHM$]\x0d\x0a,FA B GM3YEW WW HUMOUR 28913_GB7YEW
11393\x0d\x0a,F> 0
Apr 19, 2016 02:45:10.548814000 n6rme N6MEF 4\x0d\x0a
Apr 19, 2016 02:45:10.550171000 N6MEF n6rme FS +\x0d\x0a
Apr 19, 2016 02:45:10.728680000 n6rme N6MEF \x01\x12Jokes 19/4
Apr 19, 2016 02:45:10.749628000 n6rme N6MEF
\xdc\xeb\x8b\xbbY\[.several packets of binary data clipped.]
Apr 19, 2016 02:45:11.032176000 N6MEF n6rme FA B F3KT WW PACTOR
53984_F3KT 3611\x0d\x0a,F>\x0d\x0a
Apr 19, 2016 02:45:11.208111000 n6rme N6MEF FS -\x0d
Apr 19, 2016 02:45:11.229620000 n6rme N6MEF FF\x0d
Apr 19, 2016 02:50:11.015204000 n6rme N6MEF *** Timeout !!\x0d
Apr 19, 2016 02:50:11.016049000 N6MEF n6rme FQ\x0d\x0a
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.tapr.org/pipermail/nos-bbs_lists.tapr.org/attachments/20160419/3c7e6fb5/attachment.html>
More information about the nos-bbs
mailing list