[Dxspider-support] Debugging Connection Problems (was: InvalidCommand on Node Connect)

Roger Martin usrdude at centurytel.net
Wed Nov 12 11:45:41 GMT 2008


Dirk

Okay I found the debug folder and am including the error text out of it. We
did get my node connection to VE7CC-1 and PA4JJ-1 fixed. It turned out to be
the connection script filenames were ve7cc and pa4jj instead of -1 on the
end. I had run a set/spider to the call and a set/spider to the call-1 and
that got it working. Then Lee VE7CC looked at my connection scripts and
crontab files and told me what to change and that made it work correctly.
Here is the debug data:

1226419766^DXCommand
1226419766^cmd: invalid characters in 'PC16^GB7DXC^G0WFK'
1226419766^-> D PA4JJ Invalid command
1226419766^-> D PA4JJ PA4JJ de K5RLM-2 11-Nov-2008 1609Z dxspider >
1226419767^<- I WR3D PC92^K3NC^58074^A^^1WA8ZDL^H95^
1226419767^-> D W1NR PC92^K3NC^58074^A^^1WA8ZDL^H94^
1226419767^<- I W1NR PC92^K3NC^58074^A^^1WA8ZDL^H94^
1226419767^<- I PA4JJ PC16^K3NC^WA8ZDL - 1^H25^
1226419767^DXCommand
1226419767^cmd: invalid characters in 'PC16^K3NC^WA8ZDL'
1226419767^-> D PA4JJ Invalid command
1226419767^-> D PA4JJ PA4JJ de K5RLM-2 11-Nov-2008 1609Z dxspider >
1226419770^<- I PA4JJ PC17^SP7AWG^VE7CC-1^H25^
1226419770^DXCommand
1226419770^cmd: invalid characters in 'PC17^SP7AWG^VE7CC-1^H25^'
1226419770^-> D PA4JJ Invalid command
1226419770^-> D PA4JJ PA4JJ de K5RLM-2 11-Nov-2008 1609Z dxspider >
1226419770^<- I WR3D PC92^VE7CC-1^58170^D^^1SP7AWG^H96^
1226419770^-> D W1NR PC92^VE7CC-1^58170^D^^1SP7AWG^H95^
1226419770^<- I W1NR PC92^VE7CC-1^58170^D^^1SP7AWG^H95^
1226419770^<- I WR3D
PC92^IK2DUW-6^58141^C^5IK2DUW-6:5455^5IQ0LT-6^1IK2DUW^6IK2XDE-6^1IZ2CEI^4IK5
ZUK-6^6IQ8PC-6^5IQ2GM-6^4IQ3GO-6^4IK6IHL-6^5IQ0AH-6^1IW2OEV^H95^
1226419770^-> D W1NR
PC92^IK2DUW-6^58141^C^5IK2DUW-6:5455^5IQ0LT-6^1IK2DUW^6IK2XDE-6^1IZ2CEI^4IK5
ZUK-6^6IQ8PC-6^5IQ2GM-6^4IQ3GO-6^4IK6IHL-6^5IQ0AH-6^1IW2OEV^H94^
1226419770^<- I W1NR
PC92^IK2DUW-6^58141^C^5IK2DUW-6:5455^5IQ0LT-6^1IK2DUW^6IK2XDE-6^1IZ2CEI^4IK5
ZUK-6^6IQ8PC-6^5IQ2GM-6^4IQ3GO-6^4IK6IHL-6^5IQ0AH-6^1IW2OEV^H94^
1226419771^<- I PA4JJ PC16^IK1HJS-6^IK2SND - 1^H25^
1226419771^DXCommand
1226419771^cmd: invalid characters in 'PC16^IK1HJS-6^IK2SND'
1226419771^-> D PA4JJ Invalid command
1226419771^-> D PA4JJ PA4JJ de K5RLM-2 11-Nov-2008 1609Z dxspider >
1226419771^<- I WR3D PC92^IK1HJS-6^58196^A^^1IK2SND^H95^
1226419771^-> D W1NR PC92^IK1HJS-6^58196^A^^1IK2SND^H94^
1226419771^<- I W1NR PC92^IK1HJS-6^58196^A^^1IK2SND^H92^
1226419772^<- I WR3D PC92^DB0SUE-7^58173^D^^1DG2YBW^1DK3QJ^H96^
1226419772^-> D W1NR PC92^DB0SUE-7^58173^D^^1DG2YBW^1DK3QJ^H95^
1226419772^<- I PA4JJ PC17^DG2YBW^DB0SUE-7^H25^
1226419772^DXCommand
1226419772^cmd: invalid characters in 'PC17^DG2YBW^DB0SUE-7^H25^'
1226419772^-> D PA4JJ Invalid command
1226419772^-> D PA4JJ PA4JJ de K5RLM-2 11-Nov-2008 1609Z dxspider >
1226419772^<- I PA4JJ PC17^DK3QJ^DB0SUE-7^H25^
1226419772^DXCommand
1226419772^cmd: invalid characters in 'PC17^DK3QJ^DB0SUE-7^H25^'
1226419772^-> D PA4JJ Invalid command
1226419772^-> D PA4JJ PA4JJ de K5RLM-2 11-Nov-2008 1609Z dxspider >
1226419773^<- I PA4JJ PC17^SQ7LQJ^ED7ZAB-5^H25^
1226419773^DXCommand
1226419773^cmd: invalid characters in 'PC17^SQ7LQJ^ED7ZAB-5^H25^'
1226419773^-> D PA4JJ Invalid command
1226419773^-> D PA4JJ PA4JJ de K5RLM-2 11-Nov-2008 1609Z dxspider >
1226419773^<- I WR3D PC11^18130.0^KP2YL^11-Nov-2008^1609Z^
^W4OWY^K8SMC^H95^~
1226419773^-> D PA4JJ DX de W4OWY:     18130.0  KP2YL
1609Z%07%07
1226419773^-> D W1NR PC11^18130.0^KP2YL^11-Nov-2008^1609Z^
^W4OWY^K8SMC^H94^~
1226419773^<- I WR3D PC92^ED7ZAB-5^58174^D^^1SQ7LQJ^H97^
1226419773^-> D W1NR PC92^ED7ZAB-5^58174^D^^1SQ7LQJ^H96^
1226419773^<- I WR3D PC92^ED7ZAB-5^58174.01^A^^1DF2CK^1SP6M^H97^
1226419773^-> D W1NR PC92^ED7ZAB-5^58174.01^A^^1DF2CK^1SP6M^H96^
1226419773^<- I PA4JJ PC16^ED7ZAB-5^DF2CK - 1^SP6M - 1^H25^
1226419773^DXCommand
1226419773^cmd: invalid characters in 'PC16^ED7ZAB-5^DF2CK'
1226419773^-> D PA4JJ Invalid command
1226419773^-> D PA4JJ PA4JJ de K5RLM-2 11-Nov-2008 1609Z dxspider >
1226419773^<- I PA4JJ PC11^18130.0^KP2YL^11-Nov-2008^1609Z^
^W4OWY^K8SMC^H94^~
1226419773^DXCommand
1226419773^cmd: invalid characters in
'PC11^18130.0^KP2YL^11-Nov-2008^1609Z^'
1226419773^-> D PA4JJ Too many concurrent errors, you are being disconnected
1226419773^DXCommand
1226419773^PA4JJ disconnected
1226419773^-> D PA4JJ PA4JJ de K5RLM-2 11-Nov-2008 1609Z dxspider >
1226419773^<- I W1NR PC11^18130.0^KP2YL^11-Nov-2008^1609Z^
^W4OWY^K8SMC^H94^~
1226419773^DXChannel PA4JJ destroyed (4)

Before Lee VE7CC helped me get it fixed every time it tried to connect to
VE7CC-1 or PA4JJ-1 I would get this same data. Thanks for taking a look and
to all who helped with the problem.

Roger
K5RLM



-----Original Message-----
From: dxspider-support-bounces at dxcluster.org
[mailto:dxspider-support-bounces at dxcluster.org] On Behalf Of Dirk Koopman
G1TLH
Sent: Wednesday, November 12, 2008 4:24 AM
To: The DXSpider Support list
Subject: [Dxspider-support] Debugging Connection Problems (was:
InvalidCommand on Node Connect)

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).



_______________________________________________
Dxspider-support mailing list
Dxspider-support at dxcluster.org
http://mailman.tobit.co.uk/mailman/listinfo/dxspider-support






More information about the Dxspider-support mailing list