* Originally in BINKD
Hello Michiel!
VC>> I will now set this up with your node addr and full debugging so
VC>> please poll me.
Post by Michiel van der Vlist29 Mar 22:19:34 [7012] BEGIN standalone, binkd/1.1a-49/Win32 -p
-P250/1 binkd.cfg 29 Mar 22:19:34 [7012] creating a poll for
29 Mar 22:19:34 [6336] trying f1.n250.z2.binkp.net [81.179.6.57]...
29 Mar 22:19:34 [6336] connected
+ 29 Mar 22:19:34 [6336] outgoing session with 81.179.6.57
? 29 Mar 22:19:34 [6336] recv: connection closed by foreign host
(0/0 bytes)) 29 Mar 22:19:34 [6336] session closed, quitting... 29 Mar
22:19:35 [7012] the queue is empty, quitting...
?????
These are from my logs:
--------------------------
29-Mar-2014 19:17:40 mbcico[3504] MBCICO v1.0.2
29-Mar-2014 19:17:40 mbcico[3504] Cmd: mbcico f5555.n280.z2.fidonet
+ 29-Mar-2014 19:17:40 mbcico[3504] Options: Call WaZOO EMSI Freqs Zmodem
ZedZapHydra PLZ GZ/BZ2 NoNR
+ 29-Mar-2014 19:17:40 mbcico[3504] Calling 2:280/***@fidonet (Blijf Tonijn,
phone (null))
+ 29-Mar-2014 19:17:40 mbcico[3504] Open TCP connection to
"fido.vlist.eu:24554"
+ 29-Mar-2014 19:17:40 mbcico[3504] Trying IPv4 83.82.233.201 port 24554
+ 29-Mar-2014 19:17:40 mbcico[3504] Established IBN/TCP IPv4 connection with
83.82.233.201, port 24554
+ 29-Mar-2014 19:17:40 mbcico[3504] GeoIP location: Netherlands, NL EU
+ 29-Mar-2014 19:17:40 mbcico[3504] Start outbound Binkp session with
2:280/5555
@fidonet
+ 29-Mar-2014 19:17:40 mbcico[3504] Binkp: start session
+ 29-Mar-2014 19:17:40 mbcico[3504] Binkp: node 2:280/***@fidonet
+ 29-Mar-2014 19:17:40 mbcico[3504] Options :
CRAM-MD5-397fce50ba666c5094d36421df3c22ee
+ 29-Mar-2014 19:17:40 mbcico[3504] System : Blijf Tonijn
+ 29-Mar-2014 19:17:40 mbcico[3504] Sysop : Michiel van der Vlist
+ 29-Mar-2014 19:17:40 mbcico[3504] Location: Driebergen, NL
+ 29-Mar-2014 19:17:40 mbcico[3504] Flags :
CM,MO,IBN:fido.vlist.eu,U,RPK,NPK,ENC,NC
+ 29-Mar-2014 19:17:40 mbcico[3504] Time : Sat, 29 Mar 2014 20:17:27 +0100
+ 29-Mar-2014 19:17:40 mbcico[3504] Uses : binkd/1.1a-49/Win32 binkp/1.1
+ 29-Mar-2014 19:17:40 mbcico[3504] address : 2:280/***@fidonet
+ 29-Mar-2014 19:17:40 mbcico[3504] address : 2:2/***@fifonet
+ 29-Mar-2014 19:17:40 mbcico[3504] address : 2:28/***@fidonet
+ 29-Mar-2014 19:17:41 mbcico[3504] Options : EXTCMD
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: EXTCMD is active
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: MD5 unprotected session
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: forcing downgrade to binkp/1.0
protocol
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: mail 2761, files 0 bytes
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: send
"/home/mbse/var/bso/outbound/011815b3.cut" as "4754c9ce.pkt"
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: size 2761 bytes, dated Mar 29
19:17:17, comp No
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: OK 2761 bytes sent in 0.001 seconds
(2696.289 Kb/s)
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: M_GOT
"4754c9ce.pkt 2761 1396120637"
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: remote GOT "4754c9ce.pkt"
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: session finished, rc=0
+ 29-Mar-2014 19:17:43 mbcico[3504] Closing TCP connection, connected 3.00s
+ 29-Mar-2014 19:17:43 mbcico[3504] Call to 2:280/***@fidonet successful
(rc=0)
+ 29-Mar-2014 19:17:43 mbcico[3504] Sent 2761 bytes, received 0 bytes, avg
2761
cps
+ 29-Mar-2014 19:17:43 mbcico[3504] Connected 3.00s
29-Mar-2014 19:17:43 mbcico[3504] MBCICO finished in 3.00s
--------------------------
I have NO other log records for your system or for any log transactions for
that time frame (21:19 UTC or even 22:19) eg:
------------------------
+ 29-Mar-2014 20:39:24 mbcico[13096] Connected 3.00s
29-Mar-2014 20:39:24 mbcico[13096] MBCICO finished in 4.00s
29-Mar-2014 22:00:01 mbfido[22019]
29-Mar-2014 22:00:01 mbfido[22019] MBFIDO v1.0.2
29-Mar-2014 22:00:01 mbfido[22019] Cmd: mbfido ne -q
.................. heavy debug records for above last line then:
+ 29-Mar-2014 22:00:34 mbcico[22082] Connected 3.00s
29-Mar-2014 22:00:34 mbcico[22082] MBCICO finished in 4.00s
29-Mar-2014 23:43:51 mbfido[858]
29-Mar-2014 23:43:51 mbfido[858] MBFIDO v1.0.2
29-Mar-2014 23:43:51 mbfido[858] Cmd: mbfido to
------------------------
The first block was when I sent you a message direct and if you look at the
block within:
---------------------------
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: EXTCMD is active
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: MD5 unprotected session
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: forcing downgrade to binkp/1.0
protocol
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: mail 2761, files 0 bytes
---------------------------
and this is from my debug log for the entire connection (it is long):
--------------------------
29-Mar-2014 19:17:40 mbcico[3504] MBCICO v1.0.2
29-Mar-2014 19:17:40 mbcico[3504] Cmd: mbcico f5555.n280.z2.fidonet
s 29-Mar-2014 19:17:40 mbcico[3504] rdoptions node Michiel van der Vlist
2:280/5
***@fidonet
+ 29-Mar-2014 19:17:40 mbcico[3504] Options: Call WaZOO EMSI Freqs Zmodem
ZedZap
Hydra PLZ GZ/BZ2 NoNR
? 29-Mar-2014 19:17:40 mbtask[11607] TCP/IP session registered (3504), now 1
ses
sions
s 29-Mar-2014 19:17:40 mbcico[3504] Inbound set to
"/home/mbse/var/inbound/tmp.2
.280.5555.0"
+ 29-Mar-2014 19:17:40 mbcico[3504] Calling 2:280/***@fidonet (Blijf Tonijn,
ph
one (null))
+ 29-Mar-2014 19:17:40 mbcico[3504] Open TCP connection to
"fido.vlist.eu:24554"
+ 29-Mar-2014 19:17:40 mbcico[3504] Trying IPv4 83.82.233.201 port 24554
+ 29-Mar-2014 19:17:40 mbcico[3504] Established IBN/TCP IPv4 connection with
83.
82.233.201, port 24554
s 29-Mar-2014 19:17:40 mbcico[3504] IPv4 TCP connection: len=16, port=24554,
add
r=83.82.233.201
+ 29-Mar-2014 19:17:40 mbcico[3504] GeoIP location: Netherlands, NL EU
+ 29-Mar-2014 19:17:40 mbcico[3504] Start outbound Binkp session with
2:280/5555
@fidonet
+ 29-Mar-2014 19:17:40 mbcico[3504] Binkp: start session
s 29-Mar-2014 19:17:40 mbcico[3504] SM (orgbinkp): Start => ConnInit
s 29-Mar-2014 19:17:40 mbcico[3504] SM (orgbinkp): ConnInit => WaitConn
+ 29-Mar-2014 19:17:40 mbcico[3504] Binkp: node 2:280/***@fidonet
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_NUL SYS Air Applewood BBS
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_NUL ZYZ Vince Coen
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_NUL LOC Roydon, Essex, UK
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_NUL NDL CM,XA,IBN
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_NUL TIME Sat, 29 Mar 2014
19:17:40 +0000
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_NUL VER
mbcico/1.0.2/GNU/Linux-x86_64 binkp/1.0
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_NUL PHN applewood.dtdns.net
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_NUL OPM Air Applewood BBS
Linux System
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: binkp_send_comp_opts(TRUE) NRwe=Can
NRthey=Can
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_NUL OPT EXTCMD GZ BZ2 PLZ
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_ADR 2:250/***@fidonet
2:25/***@fidonet 2:250/***@fidonet
s 29-Mar-2014 19:17:40 mbcico[3504] SM (orgbinkp): WaitConn => WaitAddr
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: rcvd M_NUL OPT
CRAM-MD5-397fce50ba666c5094d36421df3c22ee
+ 29-Mar-2014 19:17:40 mbcico[3504] Options :
CRAM-MD5-397fce50ba666c5094d36421df3c22ee
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: rcvd M_NUL SYS Blijf Tonijn
+ 29-Mar-2014 19:17:40 mbcico[3504] System : Blijf Tonijn
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: rcvd M_NUL ZYZ Michiel van der
Vlist
+ 29-Mar-2014 19:17:40 mbcico[3504] Sysop : Michiel van der Vlist
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: rcvd M_NUL LOC Driebergen, NL
+ 29-Mar-2014 19:17:40 mbcico[3504] Location: Driebergen, NL
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: rcvd M_NUL NDL
CM,MO,IBN:fido.vlist.eu,U,RPK,NPK,ENC,NC
+ 29-Mar-2014 19:17:40 mbcico[3504] Flags :
CM,MO,IBN:fido.vlist.eu,U,RPK,NPK,ENC,NC
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: rcvd M_NUL TIME Sat, 29 Mar 2014
20:17:27 +0100
+ 29-Mar-2014 19:17:40 mbcico[3504] Time : Sat, 29 Mar 2014 20:17:27 +0100
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: rcvd M_NUL VER binkd/1.1a-49/Win32
binkp/1.1
+ 29-Mar-2014 19:17:40 mbcico[3504] Uses : binkd/1.1a-49/Win32 binkp/1.1
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: rcvd M_NUL 2:280/***@fidonet
2:2/***@fifonet 2:28/***@fidonet
+ 29-Mar-2014 19:17:40 mbcico[3504] address : 2:280/***@fidonet
+ 29-Mar-2014 19:17:40 mbcico[3504] address : 2:2/***@fifonet
+ 29-Mar-2014 19:17:40 mbcico[3504] address : 2:28/***@fidonet
s 29-Mar-2014 19:17:40 mbcico[3504] SM (orgbinkp): WaitAddr => SendPasswd
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: send M_PWD
CRAM-MD5-89aeacd2c28706313938a839a81ba42e
s 29-Mar-2014 19:17:40 mbcico[3504] SM (orgbinkp): SendPasswd => AuthRemote
s 29-Mar-2014 19:17:40 mbcico[3504] SM (orgbinkp): AuthRemote => IfSecure
s 29-Mar-2014 19:17:40 mbcico[3504] SM (orgbinkp): IfSecure => WaitOk
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: rcvd M_NUL OPT EXTCMD
+ 29-Mar-2014 19:17:41 mbcico[3504] Options : EXTCMD
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: remote wants EXTCMD mode
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: EXTCMD they=Want we=Want
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: EXTCMD is active
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: BZ2 they=Can we=Want
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: GZ they=Can we=Want
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: PLZ they=Can we=Want
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: NR they=Can we=Can
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: rcvd M_NUL non-secure
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: M_OK "non-secure"
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: MD5 unprotected session
s 29-Mar-2014 19:17:41 mbcico[3504] SM (orgbinkp): WaitOk => Opts
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: EXTCMD they=Act. we=Act.
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: BZ2 they=Can we=Want
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: GZ they=Can we=Want
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: PLZ they=Can we=Want
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: NR they=Can we=Can
s 29-Mar-2014 19:17:41 mbcico[3504] SM (orgbinkp): Opts => Success
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: forcing downgrade to binkp/1.0
protocol
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: last session was 0
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: rcvd M_EOB
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: receiver RxWaitF
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp/1.0 mode and got M_EOB, goto RxEOB
t 29-Mar-2014 19:17:41 mbcico[3504] tty_waitputget: timeout=300
b 29-Mar-2014 19:17:41 mbcico[3504] Creating filelist
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: mail 2761, files 0 bytes
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: send M_NUL TRF 2761 0
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: send
"/home/mbse/var/bso/outbound/011815b3.cut" as "4754c9ce.pkt"
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: size 2761 bytes, dated Mar 29
19:17:17, comp No
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: send M_FILE 4754c9ce.pkt 2761
1396120637 0
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: send data (2761)
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: OK 2761 bytes sent in 0.001 seconds
(2696.289 Kb/s)
t 29-Mar-2014 19:17:41 mbcico[3504] tty_waitputget: timeout=300
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: send M_EOB
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: 1 pending files on queue
t 29-Mar-2014 19:17:41 mbcico[3504] tty_waitputget: timeout=300
Lots of duplicate messages for the above last two lines and then:
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: rcvd M_GOT 4754c9ce.pkt 2761
1396120637
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: receiver RxEOB
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: add message M_GOT 4754c9ce.pkt 2761
1396120637
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: Process The Messages Queue Start
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: M_GOT "4754c9ce.pkt 2761
1396120637"
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: remote GOT "4754c9ce.pkt"
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: binkp/1.0 session seems complete
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: binkp_clear_filelist(0)
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: session finished, rc=0
s 29-Mar-2014 19:17:43 mbcico[3504] Closing temp inbound after a good session
s 29-Mar-2014 19:17:43 mbcico[3504] inbound_close(): /home/mbse/var/inbound
locked
s 29-Mar-2014 19:17:43 mbcico[3504] inbound_close(): /home/mbse/var/inbound
unlocked
s 29-Mar-2014 19:17:43 mbcico[3504] inbound_close(): removed
/home/mbse/var/inbound/tmp.2.280.5555.0/tmp
s 29-Mar-2014 19:17:43 mbcico[3504] inbound_close(): removed
/home/mbse/var/inbound/tmp.2.280.5555.0
+ 29-Mar-2014 19:17:43 mbcico[3504] Closing TCP connection, connected 3.00s
+ 29-Mar-2014 19:17:43 mbcico[3504] Call to 2:280/***@fidonet successful
(rc=0)
+ 29-Mar-2014 19:17:43 mbcico[3504] Sent 2761 bytes, received 0 bytes, avg
2761
cps
m 29-Mar-2014 19:17:43 mbtask[11607] MIB set mailer 6,0,2,1,1,4,0;
m 29-Mar-2014 19:17:43 mbtask[11607] MIB mailer: rcvd=23765029 sent=24171406
in=60742 out=207347 sec=191049 unsec=55039 bad=22001 ftsc=0 yoohoo=308
emsi=168
binkp=248865 freq=3
+ 29-Mar-2014 19:17:43 mbcico[3504] Connected 3.00s
29-Mar-2014 19:17:43 mbcico[3504] MBCICO finished in 3.00s
--------------------------
The lines to note are:
++++++++++++++++++++++
+ 29-Mar-2014 19:17:40 mbcico[3504] Time : Sat, 29 Mar 2014 20:17:27 +0100
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: rcvd M_NUL VER binkd/1.1a-49/Win32
binkp/1.1
+ 29-Mar-2014 19:17:40 mbcico[3504] Uses : binkd/1.1a-49/Win32 binkp/1.1
b 29-Mar-2014 19:17:40 mbcico[3504] Binkp: rcvd M_NUL 2:280/***@fidonet
2:2/***@fifonet 2:28/***@fidonet
++++++++++++++++++++++
Shows that you are v1.1 but will force v1.0 see these lines but specifically
line 3:
++++++++++++++++++++++++
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: NR they=Can we=Can
s 29-Mar-2014 19:17:41 mbcico[3504] SM (orgbinkp): Opts => Success
+ 29-Mar-2014 19:17:41 mbcico[3504] Binkp: forcing downgrade to binkp/1.0
protocol
b 29-Mar-2014 19:17:41 mbcico[3504] Binkp: last session was 0
++++++++++++++++++++++++
Not sure what happened when you polled me but please try again.
After which I must thurn debug off as I am getting a heck of a lot of logging:
Vince