Connection failure using agwpe implementation

[larsks]

EDIT: Apparently I lied about the situation under which I am seeing this behavior. I've updated the description.

---

I'm trying to use the agwpe transport to establish a connection between two Direwolf instances. The connection is established correctly, but I'm seeing the following behavior:

1. Local system sends SABME frame
2. Remote system sends UA frame
3. Remote system sends several I frames with content (these are received correctly)
4. Remote system sends RR frame
5. Local system replies with DM-.

The code looks broadly like this:

port, err := agwpe.OpenPortTCP(options.TncAddress, 0, options.MyCallsign)
...
conn, err := port.DialContext(context.TODO(), targetCallsign)
...
go func() { io.Copy(os.Stdout, conn) }()
io.Copy(conn, os.Stdin)

Is this...

• A bug in wl2k-go?
• A bug in direwolf?
• A bug in my understand in how this is supposed to work?

---

If it helps, here's are Direwolf logs of the connection:

[0.3] N1LKS-4>N1LKS:(SABME cmd, p=1)
[0L] N1LKS>N1LKS-4:(UA res, f=1)
[0L] N1LKS>N1LKS-4:(I cmd, n(s)=0, n(r)=0, p=0, pid=0xf0)<0xf0><0x0d>ERROR; /var/lib/ax25/node/loggedin: Permission denied<0x0d>
N1LKS audio level = 35(18/22)    6________
[0.0] N1LKS>N1LKS-4:(UA res, f=1)
[0L] N1LKS>N1LKS-4:(I cmd, n(s)=1, n(r)=0, p=0, pid=0xf0)<0xf0>URONode v2.15 - Welcome to XX#XX-#<0x0d>Type "?" for commands or H <command> for more detailed help on a c>
N1LKS audio level = 4(8/10)    3+_______
[0.0] N1LKS>N1LKS-4:(I cmd, n(s)=0, n(r)=0, p=0, pid=0xf0)<0x0d>ERROR; /var/lib/ax25/node/loggedin: Permission denied<0x0d>
[0L] N1LKS>N1LKS-4:(I cmd, n(s)=2, n(r)=0, p=0, pid=0xf0)<0xf0> Please use the Info and ? commands.<0x0d><0x0d>
N1LKS audio level = 0(3/3)    _+_______
[0.1] N1LKS>N1LKS-4:(I cmd, n(s)=1, n(r)=0, p=0, pid=0xf0)URONode v2.15 - Welcome to XX#XX-#<0x0d>Type "?" for commands or H <command> for more detailed help on a comman>
[0L] N1LKS>N1LKS-4:(I cmd, n(s)=3, n(r)=0, p=0, pid=0xf0)<0xf0><0x0d>=><0x20>
[0L] N1LKS>N1LKS-4:(RR cmd, n(r)=0, p=1)<0x01>
N1LKS audio level = 0(2/2)    2________
[0.0] N1LKS>N1LKS-4:(I cmd, n(s)=2, n(r)=0, p=0, pid=0xf0) Please use the Info and ? commands.<0x0d><0x0d>
N1LKS audio level = 0(1/2)    41|______
[0.1] N1LKS>N1LKS-4:(I cmd, n(s)=3, n(r)=0, p=0, pid=0xf0)<0x0d>=><0x20>
N1LKS-4 audio level = 26(16/16)    0000000__
[0.3] N1LKS-4>N1LKS:(XID cmd, p=1) Half-Duplex REJ SREJ Multi-SREJ modulo-128 I-Field-Length-Rx=256 Window-Size-Rx=32 Ack-Timer=3000 Retries=10
N1LKS-4 audio level = 18(14/13)    0000000__
[0.3] N1LKS-4>N1LKS:(DM res, f=1)
N1LKS-4 audio level = 18(12/11)    0000000__
[0.3] N1LKS-4>N1LKS:(DM res, f=1)
N1LKS-4 audio level = 18(11/10)    0000000__

[larsks]

Or like this, trying to connect to a local packet BBS:

[0L] N1LKS>KZ2X-1:(SABME cmd, p=1)
[0.1] N1LKS>KZ2X-1:(SABME cmd, p=1)
[0.3] KZ2X-1>N1LKS:(UA res, f=1)
Stream 5: Connected to KZ2X-1.  (v2.2)
[0.3] KZ2X-1>N1LKS:(I cmd, n(s)=0, n(r)=0, p=0, pid=0xf0)CONNECTED TO KZ2X TIP #1 ON AX.25 FROM N1LKS<0x0d><0x0d>TYPE 'HOSTS' FOR HOSTS, 'EXIT' TO LOGOUT, 'HELP' FOR HELP<0x0d>TYPE 'CONNECT HOSTNAME' TO CONNECT TO A HOST<0x0d><0x0d>Pad><0x20>
[0L] N1LKS>KZ2X-1:(XID cmd, p=1) Half-Duplex REJ SREJ Multi-SREJ modulo-128 I-Field-Length-Rx=256 Window-Size-Rx=32 Ack-Timer=3000 Retries=10
[0L] N1LKS>KZ2X-1:(DM res, f=1)

[larsks]

It looks like this is definitely a direwolf problem; I see the same behavior using agwterm. I've open an issue at wb2osz/direwolf#497.

[larsks]

I'm back. I wanted to share this output from setting AGWPE_DEBUG=true; the response from the remote seems to be handled as a new connection rather than as a reply to an existing connection:

2023/11/03 19:33:33 connecting to tnc at radio.local:8000
2023/11/03 19:33:33 -> Port: 0. Kind: g. From: . To: , Data: ""
2023/11/03 19:33:34 <- Port: 0. Kind: g. From: . To: , Data: "\x00\x01\x19\x04\xc8\x04\a\x00\x01\x00\x00\x00"
2023/11/03 19:33:34 -> Port: 0. Kind: X. From: N1LKS. To: , Data: ""
2023/11/03 19:33:34 <- Port: 0. Kind: X. From: N1LKS. To: , Data: "\x01"
2023/11/03 19:33:34 Port 0 registered as N1LKS. MAXFRAME=7
2023/11/03 19:33:34 -> Port: 0. Kind: R. From: . To: , Data: ""
2023/11/03 19:33:34 <- Port: 0. Kind: R. From: . To: , Data: "\xd5\a\x00\x00\x7f\x00\x00\x00"
2023/11/03 19:33:34 TNC version = 2005.127
2023/11/03 19:33:34 establishing connection with BROCK
2023/11/03 19:33:34 -> Port: 0. Kind: C. From: N1LKS. To: BROCK, Data: ""
2023/11/03 19:33:38 <- Port: 0. Kind: C. From: BROCK. To: N1LKS, Data: "*** CONNECTED With Station BROCK\r\x00"
2023/11/03 19:33:38 inbound connection from BROCK not initiated by remote. ignoring.
2023/11/03 19:33:38 flushing...
2023/11/03 19:33:38 dial completed - context cancellation no longer possible
2023/11/03 19:33:38 flushed
2023/11/03 19:33:38 -> Port: 0. Kind: d. From: N1LKS. To: BROCK, Data: ""
2023/11/03 19:33:42 <- Port: 0. Kind: d. From: BROCK. To: N1LKS, Data: "*** DISCONNECTED From Station BROCK\r\x00"
2023/11/03 19:33:42 inbound connection from BROCK refused
2023/11/03 19:33:42 demux closing (1 clients)...
2023/11/03 19:33:42 demux exited
2023/11/03 19:33:42 disconnect frame received - connection teardown...
2023/11/03 19:33:42 demux closing (1 clients)...
2023/11/03 19:33:42 demux exited
2023/11/03 19:33:42 disconnect frame received - connection teardown...
> ^C
2023/11/03 19:33:45 all done
2023/11/03 19:33:45 -> Port: 0. Kind: x. From: N1LKS. To: , Data: ""
2023/11/03 19:33:45 demux closing (3 clients)...
2023/11/03 19:33:45 demux exited

The related code is here.

[martinhpedersen]

Hi Lars!

Glad you're interested in using the package :)

Which version if Direwolf are you using? Have you tried building the current master/main branch?

[larsks]

I'm using the recently released direwolf 1.7. I see the same behavior with the prior release as well.

[martinhpedersen]

That's weird. I tested the exact with the same setup (two Direwolf instances) when developing this package, and it worked flawlessly. I will have to dig deeper and try to reproduce the error.

[martinhpedersen]

Unless you've already found that the bug is in Direwolf? I'm a bit confused 🤔