[Dxspider-support] Debugging Connection Problems (was: Invalid Command on Node Connect)
Dirk Koopman G1TLH
gb7tlh at dxcluster.org
Wed Nov 12 10:24:21 GMT 2008
Roger Martin wrote:
> Hey everyone
>
>
>
> I have tried a partner node connection between my node K5RLM-2 and VE7CC
> and now I am trying with Jan’s PA4JJ node and both get the same error.
> My node connects as it should but then gives errors stating:
>
>
>
> DXCommand
>
> Cmd: invalid characters in ‘PC16^DL6IP^H97^
>
> PA4JJ invalid command
>
>
>
> Then after a few of these errors it disconnects due to excess errors. I
> also have WR3D and W1NR connected as nodes and they both work fine and
> have since the day I connected to them. I am fairly pc savy but not
> DXCluster savy at all. I think the problem is on my end but not sure
> where to start. It is a windows 2003 box and I already have done the
> set/spider pa4jj-1 command per Jan’s request. Any suggestions or
> comments would help
>
Roger
In order to diagnose connection problems, one needs to include more
information. This information is available in the debug files which are
located in /spider/data/debug/<year>/<day number>.dat.
What we need to see is the startup conversation which looks rather like
this (for normal, new style PC92, connection):-
1226483341^-> D G1TLH-2 connection to GB7DJK started
1226483341^-> D G1TLH-2 G1TLH-2 de GB7TLH 12-Nov-2008 0949Z dxspider >
1226483341^DXChannel GB7DJK created (3)
1226483341^<- O GB7DJK telnet
1226483341^-> B GB7DJK 0
1226483341^-> E GB7DJK 0
1226483341^GB7DJK channel func state 0 -> init
1226483341^-> D G1TLH-2 Node GB7DJK has logged in
1226483342^<- I GB7DJK PC18^DXSpider Version: 1.55 Build: 0.32 pc9x^5455^
1226483342^GB7DJK channel func state init -> init
1226483342^DXSpider version 1.55 build 0.32
1226483342^Do px9x set on GB7DJK
1226483342^send_local_config: doing pc9x
1226483342^-> D GB7DJK PC92^GB7TLH^35341^A^^5GB7DJK^H99^
1226483342^-> D GB7DJK PC92^GB7TLH^35341.01^K^5GB7TLH:5455:0.32^1^1^H99^
1226483342^-> D GB7DJK PC20^
1226483342^<- I GB7DJK PC92^GB7DJK^35342^A^^5GB7TLH^H99^
1226483342^GB7DJK channel func state init -> init92
1226483342^Do pc9x set on GB7DJK
1226483342^<- I GB7DJK PC92^GB7DJK^35342.01^K^5GB7DJK:5455:0.32^17^45^H99^
1226483342^<- I GB7DJK PC22^
1226483342^GB7DJK channel func state init92 -> normal
This has come out of today's debug file (12Nov2008) which is
/spider/data/debug/2008/317.dat.
In your case either you or Jan did not do a set/spider <node>. I hope to
illustrate what happens in either case so that you can recognise the
problem next time. For the first example I "forget" to set/spider
gb7djk, so that gb7tlh (my node) thinks that gb7djk is still a user.
1226483875^<- I G1TLH-2 conn gb7djk
1226483875^-> D G1TLH-2 connection to GB7DJK started
1226483875^-> D G1TLH-2 G1TLH-2 de GB7TLH 12-Nov-2008 0957Z dxspider >
1226483875^DXChannel GB7DJK created (3)
1226483875^<- O GB7DJK telnet
1226483875^DXCommand
1226483875^GB7DJK connected from gb7djk.dxcluster.net
1226483875^-> D GB7DJK Hello Dirk, this is GB7TLH in Graffham, West Sussex
1226483875^-> D GB7DJK running DXSpider V1.55 build 0.32
1226483875^GB7DJK channel func state 0 -> prompt
1226483875^-> D GB7DJK
************************************************************
1226483875^-> D GB7DJK * please do not use this node - use GB7DJK
instead *********
1226483875^-> D GB7DJK * this is test software and may not be connected
*********
1226483875^-> D GB7DJK
************************************************************
1226483875^-> D G1TLH-2 User GB7DJK has logged in
1226483875^-> D GB7DJK
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
1226483875^-> D GB7DJK 21023.0 XV4BM 12-Nov-2008 0952Z via
RL3BM UP 1 <RN3DY>
1226483875^-> D GB7DJK 7008.0 ZL1CDP 12-Nov-2008 0951Z
<K4ZJ>
1226483875^-> D GB7DJK 14253.0 JY3ZH 12-Nov-2008 0952Z mng
dj9zb <IK6FAW>
1226483875^-> D GB7DJK 7015.0 W5TZC 12-Nov-2008 0950Z Call
Correction - sri <VK7GZ>
1226483875^-> D GB7DJK 3796.0 VP2V/SP7VC 12-Nov-2008 0950Z Good
signal 59 <W2JVM>
1226483875^-> D GB7DJK
-------------------------------------------------------------------------------
1226483875^-> D GB7DJK Date Hour SFI A K Forecast
Logger
1226483875^-> D GB7DJK 11-Nov-2008 12 69 3 1 No Storms -> No
Storms <VE7CC>
1226483875^-> D GB7DJK
+++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
1226483875^-> D GB7DJK Cluster: 165 nodes, 2 local / 77 total users Max
users 77 Uptime 0 00:09
1226483875^-> D GB7DJK GB7DJK de GB7TLH 12-Nov-2008 0957Z dxspider >
1226483875^<- I GB7DJK PC18^DXSpider Version: 1.55 Build: 0.32 pc9x^5455^
1226483875^DXCommand
1226483875^cmd: invalid characters in 'PC18^DXSpider'
1226483875^-> D GB7DJK Invalid command
1226483875^-> D GB7DJK GB7DJK de GB7TLH 12-Nov-2008 0957Z dxspider >
1226483876^<- I GB7DJK PC17^UA4SAW^SM7GVF-6^H10^
1226483876^-> D GB7DJK GB7DJK de GB7TLH 12-Nov-2008 0957Z dxspider >
as you can see, this is completely different to a normal internode
exchange. It is, apart from anything else, much more wordy, but you can
see that it is *my* node gb7tlh that thinks gb7djk is a user. The line
"GB7DJK de GB7TLH 12-Nov-2008 0957Z dxspider >" is the biggest (but to
the experienced eye, not the only) clue here.
Now, switching the set/spider the other way about so that gb7djk thinks
that my node is still a user, we get something a bit different:-
1226484247^-> D G1TLH-2 connection to GB7DJK started
1226484247^-> D G1TLH-2 G1TLH-2 de GB7TLH 12-Nov-2008 1004Z dxspider >
1226484247^DXChannel GB7DJK created (3)
1226484247^<- O GB7DJK telnet
1226484247^-> B GB7DJK 0
1226484247^-> E GB7DJK 0
1226484247^GB7DJK channel func state 0 -> init
1226484247^-> D G1TLH-2 Node GB7DJK has logged in
1226484247^<- I GB7DJK Hello Dirk, this is GB7DJK in Graffham, West Sussex
1226484247^<- I GB7DJK running DXSpider V1.55 build 0.32
1226484247^<- I GB7DJK Welcome to GB7DJK in Graffham, West Sussex
1226484247^<- I GB7DJK Cluster: 414 nodes, 45 local / 1696 total users
Max users 3101 Uptime 2 17:54
1226484247^<- I GB7DJK GB7TLH de GB7DJK 12-Nov-2008 1004Z dxspider >
1226484248^<- I GB7DJK To ALL de IT9FGA: F5LMJ pse spot correct qrg for
A5100A tnx!%07%07
1226484391^<- I GB7DJK DX de RA9CMO: 18081.9 VU3NLG
1006Z%07%07
1226484547^-> D GB7DJK PC51^GB7DJK^GB7TLH^1^
1226484547^<- I GB7DJK PC51^GB7DJK^GB7TLH^1^
1226484547^<- I GB7DJK Invalid command
1226484547^<- I GB7DJK GB7TLH de GB7DJK 12-Nov-2008 1009Z dxspider >
One doesn't get quite so many errors, but the small (and significant)
difference is one just gets "I GB7DJK Invalid command" instead of
1226483876^DXCommand
1226483876^cmd: invalid characters in 'PC17^UA4SAW^SM7GVF-6^H10^'
1226483876^-> D GB7DJK Invalid command
The other, perhaps more obvious, difference is "I GB7DJK GB7TLH de
GB7DJK 12-Nov-2008 1009Z dxspider >". Note the difference in direction
("GB7DJK de GB7TLH" and "GB7TLH de GB7DJK") between this example and the
previous one.
It also helps if one understands the difference between 'D GB7DJK' and
'I GB7DJK'. The first means that this line is being OUTPUT from one's
node and the second that it is arriving as INPUT and the node call is
the node that this line is going to/coming from.
Hope this helps.
Dirk G1TLH
PS (I don't want to get into sterile debates about why input is 'I' and
output is 'D', it's historical and will not be changed).
More information about the Dxspider-support
mailing list