Groups keyboard shortcuts have been updated
Dismiss
See shortcuts
Pat and Vara issues "Bad Command: Connect:..."
148 views
Skip to first unread message
Craig Landschoot
Nov 19, 2024, 8:42:18 PM11/19/24
to pat-users
Seems that I was doing well... until I wasn't. I had made successful connections with Vara and pat, then something happened.
I'm using Jason (KM4ACK) 73 Linux on Pi5. (Wayland disabled... running x11). Radio is a 991a, connected via USB, controlled by FLrig, and functioning on JS8, WSJT-X, and Fldigi.
Everything seems to be functioning with his Jason's Pat menu link to fire up the Vara modem. Vara starts, pat starts. everything else I verify manually.
Pat will read the radio dial, and qsy the radio. seems to be working properly.
In Vara HF, audio interface is properly configured, and I can key the radio, and the radio gets a carrier tone. The waterfall is showing the current band activity. Vara's I/O and radio control are working properly. Port numbers are set to default. There isn't much more to it.
Back to pat... Connect, VaraHF, set call and freq that I have used before, the radio auto configures itself, and I verify. I press connect. Pat's command terminal monitor indicates the radio is on frequency, and that connection is beginning. Nothing happens.
Over to Vara, the log says something along the lines of:
Bad Command: Connect KM4PVB WC4EOC
(I don't have it in front of me so I cant quote it exactly)
Although that is not great.. that at least confirms to me that Vara is getting something from Pat, but I don't really know where to go from here. The command seems correct.
what am I missing? I'll bet its something dumb like one program has my call in lower case, and vara has it in another. thats about the only thing I haven't checked.
I know a total reinstall will fix it, but if I do that, what did I learn?
-Appreciate you all, and your patience with me. :)
-Craig
KM4PVB
Martin Hebnes Pedersen
Nov 20, 2024, 9:50:53 AM11/20/24
to Craig Landschoot, pat-users
Hi Craig,
That's weird 🤔
Can you please run Pat with vara debut logging enabled, and share this log with us? Set the environment variable VARA_DEBUG=1 when starting Pat. E.g. `VARA_DEBUG=1 pat http`. That should provide a detailed log of all traffic two/from the VARA modem.
--
73 de LA5NTA / Martin
--
You received this message because you are subscribed to the Google Groups "pat-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to pat-users+...@googlegroups.com.
To view this discussion, visit https://groups.google.com/d/msgid/pat-users/3b576523-66dd-45c8-9d91-5cdfb735759an%40googlegroups.com.
J
Nov 20, 2024, 1:34:08 PM11/20/24
to pat-users
Same issue - I believe it's that VARA is expecting a <CR> character after the CONNECT command, but don't know why this behavior would have changed from previously working.
jeremy@pi5-radio:~ $ VARA_DEBUG=1 pat http
2024/11/20 13:28:54 FT-991A ready. Dial frequency is 28.130.00 MHz.
2024/11/20 13:28:54 Starting HTTP service (http://localhost:8080)...
[VARA] 2024/11/20 13:29:03.467729 vara.go:192: Connecting command
[VARA] 2024/11/20 13:29:03.468093 vara.go:192: Connecting data
[VARA] 2024/11/20 13:29:03.468276 vara.go:110: writing cmd: PUBLIC ON
[VARA] 2024/11/20 13:29:03.468313 vara.go:115: writing cmd: CWID ON
[VARA] 2024/11/20 13:29:03.468326 vara.go:120: writing cmd: COMPRESSION TEXT
[VARA] 2024/11/20 13:29:03.468335 vara.go:124: writing cmd: MYCALL KKKKKK
[VARA] 2024/11/20 13:29:03.468344 vara.go:128: writing cmd: LISTEN OFF
[VARA] 2024/11/20 13:29:03.468370 vara.go:350: writing cmd: VERSION
[VARA] 2024/11/20 13:29:03.652924 vara.go:259: got cmd: BUSY ON
[VARA] 2024/11/20 13:29:03.653165 vara.go:259: got cmd: BUSY OFF
[VARA] 2024/11/20 13:29:03.653207 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:03.653276 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:03.653293 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:03.653302 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:03.653356 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:03.653403 vara.go:259: got cmd: VERSION VARA HF v4.8.9
2024/11/20 13:29:03 VARA modem (VARA HF v4.8.9) initialized
[VARA] 2024/11/20 13:29:03.653536 transport.go:132: writing cmd: BW2300
2024/11/20 13:29:03 QSY varahf: 28130
[VARA] 2024/11/20 13:29:03.703537 vara.go:259: got cmd: OK
2024/11/20 13:29:06 Connecting to N3HYM-10 (varahf)...
[VARA] 2024/11/20 13:29:06.683591 transport.go:132: writing cmd: BW2300
[VARA] 2024/11/20 13:29:06.683697 transport.go:51: writing cmd: WINLINK SESSION
[VARA] 2024/11/20 13:29:06.683730 transport.go:61: writing cmd: CONNECT KKKKKK N3HYM-10
[VARA] 2024/11/20 13:29:06.724996 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:06.725048 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:06.725061 vara.go:259: got cmd: WRONG
VARA LOG:
2024-11-20 18:29:06 Wrong command: CONNECT KKKKK N3HYM-10
jeremy@pi5-radio:~ $ VARA_DEBUG=1 pat http
2024/11/20 13:28:54 FT-991A ready. Dial frequency is 28.130.00 MHz.
2024/11/20 13:28:54 Starting HTTP service (http://localhost:8080)...
[VARA] 2024/11/20 13:29:03.467729 vara.go:192: Connecting command
[VARA] 2024/11/20 13:29:03.468093 vara.go:192: Connecting data
[VARA] 2024/11/20 13:29:03.468276 vara.go:110: writing cmd: PUBLIC ON
[VARA] 2024/11/20 13:29:03.468313 vara.go:115: writing cmd: CWID ON
[VARA] 2024/11/20 13:29:03.468326 vara.go:120: writing cmd: COMPRESSION TEXT
[VARA] 2024/11/20 13:29:03.468335 vara.go:124: writing cmd: MYCALL KKKKKK
[VARA] 2024/11/20 13:29:03.468344 vara.go:128: writing cmd: LISTEN OFF
[VARA] 2024/11/20 13:29:03.468370 vara.go:350: writing cmd: VERSION
[VARA] 2024/11/20 13:29:03.652924 vara.go:259: got cmd: BUSY ON
[VARA] 2024/11/20 13:29:03.653165 vara.go:259: got cmd: BUSY OFF
[VARA] 2024/11/20 13:29:03.653207 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:03.653276 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:03.653293 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:03.653302 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:03.653356 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:03.653403 vara.go:259: got cmd: VERSION VARA HF v4.8.9
2024/11/20 13:29:03 VARA modem (VARA HF v4.8.9) initialized
[VARA] 2024/11/20 13:29:03.653536 transport.go:132: writing cmd: BW2300
2024/11/20 13:29:03 QSY varahf: 28130
[VARA] 2024/11/20 13:29:03.703537 vara.go:259: got cmd: OK
2024/11/20 13:29:06 Connecting to N3HYM-10 (varahf)...
[VARA] 2024/11/20 13:29:06.683591 transport.go:132: writing cmd: BW2300
[VARA] 2024/11/20 13:29:06.683697 transport.go:51: writing cmd: WINLINK SESSION
[VARA] 2024/11/20 13:29:06.683730 transport.go:61: writing cmd: CONNECT KKKKKK N3HYM-10
[VARA] 2024/11/20 13:29:06.724996 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:06.725048 vara.go:259: got cmd: OK
[VARA] 2024/11/20 13:29:06.725061 vara.go:259: got cmd: WRONG
VARA LOG:
2024-11-20 18:29:06 Wrong command: CONNECT KKKKK N3HYM-10
Craig Landschoot
Nov 20, 2024, 10:17:13 PM11/20/24
to pat-users
well, I tried a bunch of stuff, got frustrated, and did a total wipe and reinstall. and I was shocked when I had the same thing happen. so it is likely a new version of something isn't playing ball.
VARA_DEBUG=1 pat http
2024/11/20 21:11:18 my-rig ready. Dial frequency is 7.100.00 MHz.
2024/11/20 21:11:18 Starting HTTP service (http://127.0.0.1:8080)...
[VARA] 2024/11/20 21:12:31.642550 vara.go:192: Connecting command
[VARA] 2024/11/20 21:12:31.643000 vara.go:192: Connecting data
[VARA] 2024/11/20 21:12:31.644548 vara.go:110: writing cmd: PUBLIC ON
[VARA] 2024/11/20 21:12:31.644670 vara.go:115: writing cmd: CWID ON
[VARA] 2024/11/20 21:12:31.644704 vara.go:120: writing cmd: COMPRESSION TEXT
[VARA] 2024/11/20 21:12:31.644722 vara.go:124: writing cmd: MYCALL KM4PVB
[VARA] 2024/11/20 21:12:31.644736 vara.go:128: writing cmd: LISTEN OFF
[VARA] 2024/11/20 21:12:31.644778 vara.go:350: writing cmd: VERSION
[VARA] 2024/11/20 21:12:31.674091 vara.go:259: got cmd: BUSY ON
[VARA] 2024/11/20 21:12:31.805785 vara.go:259: got cmd: BUSY OFF
[VARA] 2024/11/20 21:12:31.805854 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:31.805873 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:31.805878 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:31.805883 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:31.805886 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:31.805891 vara.go:259: got cmd: VERSION VARA HF v4.8.9
2024/11/20 21:12:31 VARA modem (VARA HF v4.8.9) initialized
[VARA] 2024/11/20 21:12:31.805965 transport.go:132: writing cmd: BW2300
2024/11/20 21:12:31 QSY varahf: 7100
[VARA] 2024/11/20 21:12:31.904291 vara.go:259: got cmd: OK
2024/11/20 21:12:35 Connecting to KN4CCQ (varahf)...
[VARA] 2024/11/20 21:12:35.044685 transport.go:132: writing cmd: BW2750
[VARA] 2024/11/20 21:12:35.044745 transport.go:51: writing cmd: WINLINK SESSION
[VARA] 2024/11/20 21:12:35.044772 transport.go:61: writing cmd: CONNECT KM4PVB KN4CCQ
[VARA] 2024/11/20 21:12:35.155423 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:35.155651 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:35.155700 vara.go:259: got cmd: WRONG
[VARA] 2024/11/20 21:13:00.041332 vara.go:259: got cmd: BUSY ON
[VARA] 2024/11/20 21:13:01.001281 vara.go:259: got cmd: IAMALIVE
[VARA] 2024/11/20 21:13:01.456418 vara.go:259: got cmd: BUSY OFF
2024/11/20 21:11:18 my-rig ready. Dial frequency is 7.100.00 MHz.
2024/11/20 21:11:18 Starting HTTP service (http://127.0.0.1:8080)...
[VARA] 2024/11/20 21:12:31.642550 vara.go:192: Connecting command
[VARA] 2024/11/20 21:12:31.643000 vara.go:192: Connecting data
[VARA] 2024/11/20 21:12:31.644548 vara.go:110: writing cmd: PUBLIC ON
[VARA] 2024/11/20 21:12:31.644670 vara.go:115: writing cmd: CWID ON
[VARA] 2024/11/20 21:12:31.644704 vara.go:120: writing cmd: COMPRESSION TEXT
[VARA] 2024/11/20 21:12:31.644722 vara.go:124: writing cmd: MYCALL KM4PVB
[VARA] 2024/11/20 21:12:31.644736 vara.go:128: writing cmd: LISTEN OFF
[VARA] 2024/11/20 21:12:31.644778 vara.go:350: writing cmd: VERSION
[VARA] 2024/11/20 21:12:31.674091 vara.go:259: got cmd: BUSY ON
[VARA] 2024/11/20 21:12:31.805785 vara.go:259: got cmd: BUSY OFF
[VARA] 2024/11/20 21:12:31.805854 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:31.805873 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:31.805878 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:31.805883 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:31.805886 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:31.805891 vara.go:259: got cmd: VERSION VARA HF v4.8.9
2024/11/20 21:12:31 VARA modem (VARA HF v4.8.9) initialized
[VARA] 2024/11/20 21:12:31.805965 transport.go:132: writing cmd: BW2300
2024/11/20 21:12:31 QSY varahf: 7100
[VARA] 2024/11/20 21:12:31.904291 vara.go:259: got cmd: OK
2024/11/20 21:12:35 Connecting to KN4CCQ (varahf)...
[VARA] 2024/11/20 21:12:35.044685 transport.go:132: writing cmd: BW2750
[VARA] 2024/11/20 21:12:35.044745 transport.go:51: writing cmd: WINLINK SESSION
[VARA] 2024/11/20 21:12:35.044772 transport.go:61: writing cmd: CONNECT KM4PVB KN4CCQ
[VARA] 2024/11/20 21:12:35.155423 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:35.155651 vara.go:259: got cmd: OK
[VARA] 2024/11/20 21:12:35.155700 vara.go:259: got cmd: WRONG
[VARA] 2024/11/20 21:13:00.041332 vara.go:259: got cmd: BUSY ON
[VARA] 2024/11/20 21:13:01.001281 vara.go:259: got cmd: IAMALIVE
[VARA] 2024/11/20 21:13:01.456418 vara.go:259: got cmd: BUSY OFF
in Vara the log looks like this: (as expected)
2024-11-21 03:12:35 Wrong command: CONNECT KM4PVB KN4CCQ
Martin Hebnes Pedersen
Nov 21, 2024, 1:43:26 PM11/21/24
to Craig Landschoot, pat-users
Hi again Craig,
I certainly seems like a bug in VARA HF. I assume your are running the latest version?
Can anyone else running the same version share their experience, please?
--
73 de LA5NTA / Martin
To view this discussion, visit https://groups.google.com/d/msgid/pat-users/f07fb593-0bb8-47da-bb35-7069d66f61fdn%40googlegroups.com.
Martin Hebnes Pedersen
Nov 21, 2024, 1:54:19 PM11/21/24
to Craig Landschoot, pat-users
One thought...
I see "writing cmd: BW2750" in the log. Looks like that is a special mode called "VARA HF Tactical".. maybe it requires a special license?
Anyway, can you please try using standard 2300 Hz bandwidth?
--
Martin
Craig Landschoot
Nov 21, 2024, 2:11:36 PM11/21/24
to pat-users
I did purchase a vara license, and to my knowledge I have the license code correctly in the box (It gets masked with ***'s). I think that unlocks the higher bandwidth. I will try the 2750 this evening and report back.
Joel Black
Nov 21, 2024, 3:47:58 PM11/21/24
to pat-users
Craig,
I *think* buying the VARA license opens up the bit rate (I may be wrong) but I know if I forget to put my registration in on a new install, it doesn't go above 3 or 4.
Martin,
I'm running Pat v0.16.0 and I do *not* see what Craig sees. Anytime I've failed to connect, it's been a cockpit error:
2024/11/21 14:38:38 Starting HTTP service (http://localhost:8080)...
[VARA] 2024/11/21 14:40:44.545185 vara.go:192: Connecting command
[VARA] 2024/11/21 14:40:44.546792 vara.go:192: Connecting data
[VARA] 2024/11/21 14:40:44.547283 vara.go:110: writing cmd: PUBLIC ON
[VARA] 2024/11/21 14:40:44.547335 vara.go:115: writing cmd: CWID ON
[VARA] 2024/11/21 14:40:44.547354 vara.go:120: writing cmd: COMPRESSION TEXT
[VARA] 2024/11/21 14:40:44.547411 vara.go:124: writing cmd: MYCALL W4JBB
[VARA] 2024/11/21 14:40:44.547427 vara.go:128: writing cmd: LISTEN OFF
[VARA] 2024/11/21 14:40:44.547682 vara.go:350: writing cmd: VERSION
[VARA] 2024/11/21 14:40:44.578269 vara.go:259: got cmd: BUSY ON
[VARA] 2024/11/21 14:40:44.578576 vara.go:259: got cmd: BUSY OFF
[VARA] 2024/11/21 14:40:44.578798 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:44.578989 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:44.579031 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:44.579046 vara.go:259: got cmd: ENCRYPTION DISABLED
[VARA] 2024/11/21 14:40:44.579241 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:44.579262 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:44.579283 vara.go:259: got cmd: VERSION VARA HF v4.8.9
2024/11/21 14:40:44 VARA modem (VARA HF v4.8.9) initialized
[VARA] 2024/11/21 14:40:44.579642 transport.go:132: writing cmd: BW2750
2024/11/21 14:40:44 QSY varahf: 7101.7
[VARA] 2024/11/21 14:40:44.591469 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:45.770379 vara.go:259: got cmd: BUSY ON
2024/11/21 14:40:47 Connecting to K4HVF (varahf)...
[VARA] 2024/11/21 14:40:47.646410 transport.go:132: writing cmd: BW2750
[VARA] 2024/11/21 14:40:47.646497 transport.go:51: writing cmd: WINLINK SESSION
[VARA] 2024/11/21 14:40:47.646711 transport.go:61: writing cmd: CONNECT W4JBB K4HVF
[VARA] 2024/11/21 14:40:47.681975 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:47.682035 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:47.682061 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:47.682075 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:40:49.467663 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:40:49.612860 vara.go:259: got cmd: REGISTERED W4JBB
2024/11/21 14:40:49 VARA full speed available, registered to W4JBB
[VARA] 2024/11/21 14:40:50.721857 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:40:52.126617 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:40:53.391514 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:40:54.801359 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:40:56.053819 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:40:57.458927 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:40:58.732803 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:00.133026 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:01.368818 vara.go:259: got cmd: UNENCRYPTED LINK
[VARA] 2024/11/21 14:41:01.368907 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:01.370120 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:01.370165 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:05.753785 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:06.459041 vara.go:259: got cmd: CONNECTED W4JBB K4HVF 2750
[VARA] 2024/11/21 14:41:06.459218 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:06.459464 transport.go:76: dial completed - context cancellation no longer possible
2024/11/21 14:41:06 Connected to K4HVF (vara)
[VARA] 2024/11/21 14:41:07.192361 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:07.246137 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:07.246244 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:07.246316 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:07.246374 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:07.875829 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:09.268796 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:09.325331 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:09.325430 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:13.634254 vara.go:259: got cmd: SN 23.2
[VARA] 2024/11/21 14:41:13.634345 vara.go:306: got a vara command I wasn't expecting: "SN 23.2"
[VARA] 2024/11/21 14:41:13.634384 vara.go:259: got cmd: PTT ON
RMS Trimode 1.3.57.0 Welcome to my station
W4JBB has 1440 daily minutes remaining with K4HVF (EM63IS)
{SFI = 163 On 2024-11-21 17:00 UTC}
[WL2K-5.0-B2FWIHJM$]
;PQ: 84944163
CMS via K4HVF >
[VARA] 2024/11/21 14:41:13.829381 conn.go:245: write: sending 72 bytes
>FC EM LX774OJYYD3J 520 241 0
[VARA] 2024/11/21 14:41:13.836628 conn.go:245: write: sending 29 bytes
Sending checksum 88
[VARA] 2024/11/21 14:41:13.837418 conn.go:205: write: buffer full (101 >= 42)
[VARA] 2024/11/21 14:41:14.123235 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:14.846104 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:14.846189 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:14.846227 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:18.967085 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:19.694427 vara.go:259: got cmd: BUFFER 0
[VARA] 2024/11/21 14:41:19.694785 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:19.695185 conn.go:245: write: sending 6 bytes
[VARA] 2024/11/21 14:41:20.184266 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:20.238830 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:20.238903 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:20.238932 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:20.238949 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:20.869130 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:21.372070 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:22.079328 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:22.079377 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:22.079396 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:26.211728 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:26.818867 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:26.818916 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:26.818931 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:31.208006 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:31.916012 vara.go:259: got cmd: BUFFER 0
[VARA] 2024/11/21 14:41:31.916134 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:32.690458 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:32.746333 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:32.746425 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:32.746447 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:32.746463 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:35.600216 vara.go:259: got cmd: IAMALIVE
[VARA] 2024/11/21 14:41:37.024024 vara.go:259: got cmd: SN 20.6
[VARA] 2024/11/21 14:41:37.024105 vara.go:306: got a vara command I wasn't expecting: "SN 20.6"
[VARA] 2024/11/21 14:41:37.024138 vara.go:259: got cmd: PTT ON
FS Y
Remote accepted LX774OJYYD3J
Transmitting [Test] [offset 0]
[VARA] 2024/11/21 14:41:37.204589 conn.go:245: write: sending 9 bytes
[VARA] 2024/11/21 14:41:37.204746 conn.go:245: write: sending 127 bytes
[VARA] 2024/11/21 14:41:37.204820 conn.go:245: write: sending 118 bytes
[VARA] 2024/11/21 14:41:37.204864 conn.go:205: write: buffer full (254 >= 14)
Test: 0%[VARA] 2024/11/21 14:41:37.513908 vara.go:259: got cmd: PTT OFF
Test: 0%[VARA] 2024/11/21 14:41:38.229839 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:38.229899 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:38.229939 vara.go:259: got cmd: PTT ON
Test: 0%[VARA] 2024/11/21 14:41:42.624670 vara.go:259: got cmd: PTT OFF
Test: 0%[VARA] 2024/11/21 14:41:43.219218 vara.go:259: got cmd: BUFFER 165
[VARA] 2024/11/21 14:41:43.219319 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:43.219344 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:43.219402 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:43.219414 conn.go:205: write: buffer full (165 >= 14)
Test: 32%[VARA] 2024/11/21 14:41:47.615765 vara.go:259: got cmd: PTT OFF
Test: 32%[VARA] 2024/11/21 14:41:48.201289 vara.go:259: got cmd: BUFFER 76
[VARA] 2024/11/21 14:41:48.201378 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:48.201401 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:48.201455 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:48.201480 conn.go:205: write: buffer full (76 >= 14)
Test: 68%[VARA] 2024/11/21 14:41:52.599451 vara.go:259: got cmd: PTT OFF
Test: 68%[VARA] 2024/11/21 14:41:53.297550 vara.go:259: got cmd: BUFFER 0
[VARA] 2024/11/21 14:41:53.297748 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:53.297815 conn.go:245: write: sending 2 bytes
[VARA] 2024/11/21 14:41:53.298010 conn.go:32: Flushing...
Test: 99%[VARA] 2024/11/21 14:41:54.061154 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:54.119922 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:54.120013 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:54.120044 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:54.120061 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
Test: 99%[VARA] 2024/11/21 14:41:54.760049 vara.go:259: got cmd: PTT ON
Test: 99%[VARA] 2024/11/21 14:41:55.521205 vara.go:259: got cmd: PTT OFF
Test: 99%[VARA] 2024/11/21 14:41:56.213898 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:56.213957 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:56.213973 vara.go:259: got cmd: PTT ON
Test: 99%[VARA] 2024/11/21 14:42:00.605475 vara.go:259: got cmd: PTT OFF
Test: 99%[VARA] 2024/11/21 14:42:01.305133 vara.go:259: got cmd: BUFFER 0
[VARA] 2024/11/21 14:42:01.305216 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:42:01.305626 conn.go:63: Flushed
Test: 100%
[VARA] 2024/11/21 14:42:02.058514 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:42:02.111796 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:42:02.111848 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:42:02.111864 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:42:02.111873 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:42:06.408080 vara.go:259: got cmd: SN 27.0
[VARA] 2024/11/21 14:42:06.408130 vara.go:306: got a vara command I wasn't expecting: "SN 27.0"
[VARA] 2024/11/21 14:42:06.408148 vara.go:259: got cmd: PTT ON
FF
>FQ
[VARA] 2024/11/21 14:42:06.600282 conn.go:245: write: sending 3 bytes
[VARA] 2024/11/21 14:42:06.600544 conn.go:87: Closing connection...
[VARA] 2024/11/21 14:42:06.892464 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:42:07.626170 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:42:07.626217 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:42:07.626236 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:42:08.601727 conn.go:114: writing cmd: DISCONNECT
[VARA] 2024/11/21 14:42:08.605143 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:42:11.743736 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:42:12.482714 vara.go:259: got cmd: BUFFER 0
[VARA] 2024/11/21 14:42:12.482802 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:42:16.800028 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:42:16.854797 vara.go:259: got cmd: DISCONNECTED
[VARA] 2024/11/21 14:42:16.855156 transport.go:132: writing cmd: BW2750
[VARA] 2024/11/21 14:42:16.855208 vara.go:259: got cmd: ENCRYPTION DISABLED
[VARA] 2024/11/21 14:42:16.855260 vara.go:259: got cmd: ENCRYPTION DISABLED
[VARA] 2024/11/21 14:42:16.856037 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:42:17.856749 conn.go:96: close: discarded 0 bytes of remaining data
2024/11/21 14:42:17 Disconnected.
2024/11/21 14:42:18 QSX varahf: 7101.700
[VARA] 2024/11/21 14:42:20.753625 vara.go:259: got cmd: BUSY OFF
[VARA] 2024/11/21 14:40:44.545185 vara.go:192: Connecting command
[VARA] 2024/11/21 14:40:44.546792 vara.go:192: Connecting data
[VARA] 2024/11/21 14:40:44.547283 vara.go:110: writing cmd: PUBLIC ON
[VARA] 2024/11/21 14:40:44.547335 vara.go:115: writing cmd: CWID ON
[VARA] 2024/11/21 14:40:44.547354 vara.go:120: writing cmd: COMPRESSION TEXT
[VARA] 2024/11/21 14:40:44.547411 vara.go:124: writing cmd: MYCALL W4JBB
[VARA] 2024/11/21 14:40:44.547427 vara.go:128: writing cmd: LISTEN OFF
[VARA] 2024/11/21 14:40:44.547682 vara.go:350: writing cmd: VERSION
[VARA] 2024/11/21 14:40:44.578269 vara.go:259: got cmd: BUSY ON
[VARA] 2024/11/21 14:40:44.578576 vara.go:259: got cmd: BUSY OFF
[VARA] 2024/11/21 14:40:44.578798 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:44.578989 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:44.579031 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:44.579046 vara.go:259: got cmd: ENCRYPTION DISABLED
[VARA] 2024/11/21 14:40:44.579241 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:44.579262 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:44.579283 vara.go:259: got cmd: VERSION VARA HF v4.8.9
2024/11/21 14:40:44 VARA modem (VARA HF v4.8.9) initialized
[VARA] 2024/11/21 14:40:44.579642 transport.go:132: writing cmd: BW2750
2024/11/21 14:40:44 QSY varahf: 7101.7
[VARA] 2024/11/21 14:40:44.591469 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:45.770379 vara.go:259: got cmd: BUSY ON
2024/11/21 14:40:47 Connecting to K4HVF (varahf)...
[VARA] 2024/11/21 14:40:47.646410 transport.go:132: writing cmd: BW2750
[VARA] 2024/11/21 14:40:47.646497 transport.go:51: writing cmd: WINLINK SESSION
[VARA] 2024/11/21 14:40:47.646711 transport.go:61: writing cmd: CONNECT W4JBB K4HVF
[VARA] 2024/11/21 14:40:47.681975 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:47.682035 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:47.682061 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:40:47.682075 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:40:49.467663 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:40:49.612860 vara.go:259: got cmd: REGISTERED W4JBB
2024/11/21 14:40:49 VARA full speed available, registered to W4JBB
[VARA] 2024/11/21 14:40:50.721857 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:40:52.126617 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:40:53.391514 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:40:54.801359 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:40:56.053819 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:40:57.458927 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:40:58.732803 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:00.133026 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:01.368818 vara.go:259: got cmd: UNENCRYPTED LINK
[VARA] 2024/11/21 14:41:01.368907 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:01.370120 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:01.370165 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:05.753785 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:06.459041 vara.go:259: got cmd: CONNECTED W4JBB K4HVF 2750
[VARA] 2024/11/21 14:41:06.459218 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:06.459464 transport.go:76: dial completed - context cancellation no longer possible
2024/11/21 14:41:06 Connected to K4HVF (vara)
[VARA] 2024/11/21 14:41:07.192361 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:07.246137 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:07.246244 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:07.246316 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:07.246374 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:07.875829 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:09.268796 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:09.325331 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:09.325430 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:13.634254 vara.go:259: got cmd: SN 23.2
[VARA] 2024/11/21 14:41:13.634345 vara.go:306: got a vara command I wasn't expecting: "SN 23.2"
[VARA] 2024/11/21 14:41:13.634384 vara.go:259: got cmd: PTT ON
RMS Trimode 1.3.57.0 Welcome to my station
W4JBB has 1440 daily minutes remaining with K4HVF (EM63IS)
{SFI = 163 On 2024-11-21 17:00 UTC}
[WL2K-5.0-B2FWIHJM$]
;PQ: 84944163
CMS via K4HVF >
[VARA] 2024/11/21 14:41:13.829381 conn.go:245: write: sending 72 bytes
>FC EM LX774OJYYD3J 520 241 0
[VARA] 2024/11/21 14:41:13.836628 conn.go:245: write: sending 29 bytes
Sending checksum 88
[VARA] 2024/11/21 14:41:13.837418 conn.go:205: write: buffer full (101 >= 42)
[VARA] 2024/11/21 14:41:14.123235 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:14.846104 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:14.846189 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:14.846227 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:18.967085 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:19.694427 vara.go:259: got cmd: BUFFER 0
[VARA] 2024/11/21 14:41:19.694785 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:19.695185 conn.go:245: write: sending 6 bytes
[VARA] 2024/11/21 14:41:20.184266 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:20.238830 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:20.238903 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:20.238932 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:20.238949 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:20.869130 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:21.372070 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:22.079328 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:22.079377 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:22.079396 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:26.211728 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:26.818867 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:26.818916 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:26.818931 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:31.208006 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:31.916012 vara.go:259: got cmd: BUFFER 0
[VARA] 2024/11/21 14:41:31.916134 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:32.690458 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:32.746333 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:32.746425 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:32.746447 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:32.746463 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:41:35.600216 vara.go:259: got cmd: IAMALIVE
[VARA] 2024/11/21 14:41:37.024024 vara.go:259: got cmd: SN 20.6
[VARA] 2024/11/21 14:41:37.024105 vara.go:306: got a vara command I wasn't expecting: "SN 20.6"
[VARA] 2024/11/21 14:41:37.024138 vara.go:259: got cmd: PTT ON
FS Y
Remote accepted LX774OJYYD3J
Transmitting [Test] [offset 0]
[VARA] 2024/11/21 14:41:37.204589 conn.go:245: write: sending 9 bytes
[VARA] 2024/11/21 14:41:37.204746 conn.go:245: write: sending 127 bytes
[VARA] 2024/11/21 14:41:37.204820 conn.go:245: write: sending 118 bytes
[VARA] 2024/11/21 14:41:37.204864 conn.go:205: write: buffer full (254 >= 14)
Test: 0%[VARA] 2024/11/21 14:41:37.513908 vara.go:259: got cmd: PTT OFF
Test: 0%[VARA] 2024/11/21 14:41:38.229839 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:38.229899 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:38.229939 vara.go:259: got cmd: PTT ON
Test: 0%[VARA] 2024/11/21 14:41:42.624670 vara.go:259: got cmd: PTT OFF
Test: 0%[VARA] 2024/11/21 14:41:43.219218 vara.go:259: got cmd: BUFFER 165
[VARA] 2024/11/21 14:41:43.219319 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:43.219344 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:43.219402 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:43.219414 conn.go:205: write: buffer full (165 >= 14)
Test: 32%[VARA] 2024/11/21 14:41:47.615765 vara.go:259: got cmd: PTT OFF
Test: 32%[VARA] 2024/11/21 14:41:48.201289 vara.go:259: got cmd: BUFFER 76
[VARA] 2024/11/21 14:41:48.201378 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:48.201401 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:48.201455 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:48.201480 conn.go:205: write: buffer full (76 >= 14)
Test: 68%[VARA] 2024/11/21 14:41:52.599451 vara.go:259: got cmd: PTT OFF
Test: 68%[VARA] 2024/11/21 14:41:53.297550 vara.go:259: got cmd: BUFFER 0
[VARA] 2024/11/21 14:41:53.297748 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:41:53.297815 conn.go:245: write: sending 2 bytes
[VARA] 2024/11/21 14:41:53.298010 conn.go:32: Flushing...
Test: 99%[VARA] 2024/11/21 14:41:54.061154 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:41:54.119922 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:54.120013 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:54.120044 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:41:54.120061 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
Test: 99%[VARA] 2024/11/21 14:41:54.760049 vara.go:259: got cmd: PTT ON
Test: 99%[VARA] 2024/11/21 14:41:55.521205 vara.go:259: got cmd: PTT OFF
Test: 99%[VARA] 2024/11/21 14:41:56.213898 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:41:56.213957 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:41:56.213973 vara.go:259: got cmd: PTT ON
Test: 99%[VARA] 2024/11/21 14:42:00.605475 vara.go:259: got cmd: PTT OFF
Test: 99%[VARA] 2024/11/21 14:42:01.305133 vara.go:259: got cmd: BUFFER 0
[VARA] 2024/11/21 14:42:01.305216 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:42:01.305626 conn.go:63: Flushed
Test: 100%
[VARA] 2024/11/21 14:42:02.058514 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:42:02.111796 vara.go:259: got cmd: BITRATE (4) 175 bps
[VARA] 2024/11/21 14:42:02.111848 vara.go:306: got a vara command I wasn't expecting: "BITRATE (4) 175 bps"
[VARA] 2024/11/21 14:42:02.111864 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:42:02.111873 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:42:06.408080 vara.go:259: got cmd: SN 27.0
[VARA] 2024/11/21 14:42:06.408130 vara.go:306: got a vara command I wasn't expecting: "SN 27.0"
[VARA] 2024/11/21 14:42:06.408148 vara.go:259: got cmd: PTT ON
FF
>FQ
[VARA] 2024/11/21 14:42:06.600282 conn.go:245: write: sending 3 bytes
[VARA] 2024/11/21 14:42:06.600544 conn.go:87: Closing connection...
[VARA] 2024/11/21 14:42:06.892464 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:42:07.626170 vara.go:259: got cmd: BITRATE (5) 270 bps
[VARA] 2024/11/21 14:42:07.626217 vara.go:306: got a vara command I wasn't expecting: "BITRATE (5) 270 bps"
[VARA] 2024/11/21 14:42:07.626236 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:42:08.601727 conn.go:114: writing cmd: DISCONNECT
[VARA] 2024/11/21 14:42:08.605143 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:42:11.743736 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:42:12.482714 vara.go:259: got cmd: BUFFER 0
[VARA] 2024/11/21 14:42:12.482802 vara.go:259: got cmd: PTT ON
[VARA] 2024/11/21 14:42:16.800028 vara.go:259: got cmd: PTT OFF
[VARA] 2024/11/21 14:42:16.854797 vara.go:259: got cmd: DISCONNECTED
[VARA] 2024/11/21 14:42:16.855156 transport.go:132: writing cmd: BW2750
[VARA] 2024/11/21 14:42:16.855208 vara.go:259: got cmd: ENCRYPTION DISABLED
[VARA] 2024/11/21 14:42:16.855260 vara.go:259: got cmd: ENCRYPTION DISABLED
[VARA] 2024/11/21 14:42:16.856037 vara.go:259: got cmd: OK
[VARA] 2024/11/21 14:42:17.856749 conn.go:96: close: discarded 0 bytes of remaining data
2024/11/21 14:42:17 Disconnected.
2024/11/21 14:42:18 QSX varahf: 7101.700
[VARA] 2024/11/21 14:42:20.753625 vara.go:259: got cmd: BUSY OFF
Joel Black
Nov 21, 2024, 4:06:37 PM11/21/24
to pat-users
It helps if I read everything.
I think the VARA registration allows a higher bit rate (but don't hold me to that). I do know if I forget to register on a new install, I cannot get higher than level 3 or 4 (whatever bit rates those are).
The "tactical" 2750 doesn't require a special service code or license I'm aware of - I use it with both my amateur and SHARES calls.
I did notice some differences between mine and Craig's debug log.
Regards,
Joel, W4JBB
Craig Landschoot
Nov 23, 2024, 1:03:10 PM11/23/24
to pat-users
ok. next steps. sorry about the delay in response, I've been burning the candle at both ends.
I removed my registration info from vara, and reduced the speed to 2300 on the connection. same result.
I went into the vara setup, and checked the box for CW ID, that adds "disabled encryption" to the log. but other than that, I'm still getting the bad command problem.
here is the log:
2024/11/23 12:02:00 my-rig ready. Dial frequency is 7.100.00 MHz.
2024/11/23 12:02:00 Starting HTTP service (http://127.0.0.1:8080)...
[VARA] 2024/11/23 12:02:18.592729 vara.go:192: Connecting command
[VARA] 2024/11/23 12:02:18.594450 vara.go:192: Connecting data
[VARA] 2024/11/23 12:02:18.595095 vara.go:110: writing cmd: PUBLIC ON
[VARA] 2024/11/23 12:02:18.595179 vara.go:115: writing cmd: CWID ON
[VARA] 2024/11/23 12:02:18.595511 vara.go:120: writing cmd: COMPRESSION TEXT
[VARA] 2024/11/23 12:02:18.595728 vara.go:124: writing cmd: MYCALL KM4PVB
[VARA] 2024/11/23 12:02:18.595776 vara.go:128: writing cmd: LISTEN OFF
[VARA] 2024/11/23 12:02:18.595839 vara.go:350: writing cmd: VERSION
[VARA] 2024/11/23 12:02:18.703084 vara.go:259: got cmd: BUSY ON
[VARA] 2024/11/23 12:02:18.703159 vara.go:259: got cmd: BUSY OFF
[VARA] 2024/11/23 12:02:18.703182 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:18.703186 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:18.703191 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:18.703194 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:18.703198 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:18.703201 vara.go:259: got cmd: VERSION VARA HF v4.8.9
2024/11/23 12:02:18 VARA modem (VARA HF v4.8.9) initialized
[VARA] 2024/11/23 12:02:18.703269 transport.go:132: writing cmd: BW2300
2024/11/23 12:02:18 QSY varahf: 7100
[VARA] 2024/11/23 12:02:18.704212 vara.go:259: got cmd: OK
2024/11/23 12:02:21 Connecting to KN4CCQ (varahf)...
[VARA] 2024/11/23 12:02:21.865657 transport.go:132: writing cmd: BW2300
[VARA] 2024/11/23 12:02:21.865699 transport.go:51: writing cmd: WINLINK SESSION
[VARA] 2024/11/23 12:02:21.865737 transport.go:61: writing cmd: CONNECT KM4PVB KN4CCQ
[VARA] 2024/11/23 12:02:21.890420 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:21.890463 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:21.890478 vara.go:259: got cmd: WRONG
2024/11/23 12:02:00 Starting HTTP service (http://127.0.0.1:8080)...
[VARA] 2024/11/23 12:02:18.592729 vara.go:192: Connecting command
[VARA] 2024/11/23 12:02:18.594450 vara.go:192: Connecting data
[VARA] 2024/11/23 12:02:18.595095 vara.go:110: writing cmd: PUBLIC ON
[VARA] 2024/11/23 12:02:18.595179 vara.go:115: writing cmd: CWID ON
[VARA] 2024/11/23 12:02:18.595511 vara.go:120: writing cmd: COMPRESSION TEXT
[VARA] 2024/11/23 12:02:18.595728 vara.go:124: writing cmd: MYCALL KM4PVB
[VARA] 2024/11/23 12:02:18.595776 vara.go:128: writing cmd: LISTEN OFF
[VARA] 2024/11/23 12:02:18.595839 vara.go:350: writing cmd: VERSION
[VARA] 2024/11/23 12:02:18.703084 vara.go:259: got cmd: BUSY ON
[VARA] 2024/11/23 12:02:18.703159 vara.go:259: got cmd: BUSY OFF
[VARA] 2024/11/23 12:02:18.703182 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:18.703186 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:18.703191 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:18.703194 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:18.703198 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:18.703201 vara.go:259: got cmd: VERSION VARA HF v4.8.9
2024/11/23 12:02:18 VARA modem (VARA HF v4.8.9) initialized
[VARA] 2024/11/23 12:02:18.703269 transport.go:132: writing cmd: BW2300
2024/11/23 12:02:18 QSY varahf: 7100
[VARA] 2024/11/23 12:02:18.704212 vara.go:259: got cmd: OK
2024/11/23 12:02:21 Connecting to KN4CCQ (varahf)...
[VARA] 2024/11/23 12:02:21.865657 transport.go:132: writing cmd: BW2300
[VARA] 2024/11/23 12:02:21.865699 transport.go:51: writing cmd: WINLINK SESSION
[VARA] 2024/11/23 12:02:21.865737 transport.go:61: writing cmd: CONNECT KM4PVB KN4CCQ
[VARA] 2024/11/23 12:02:21.890420 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:21.890463 vara.go:259: got cmd: OK
[VARA] 2024/11/23 12:02:21.890478 vara.go:259: got cmd: WRONG
Craig Landschoot
Nov 23, 2024, 1:33:16 PM11/23/24
to pat-users
I removed my vara registration for testing purposes.... didn't change the result
I put the credentials back in, and it is still not reporting to pat that "vara is registered, and running in high speed mode". although that does not seem like a problem, that is information that is normally echoed in the log if vara is registered. My evolve laptop running mint DOES echo to pat that "vara registered, running in high speed" promptly after starting the connection, and the connection is successful on that machine.
To expand on this, I have also tested varaFM on the pi5, and yield the same "Bad command: Connect....." result. so I suspect a problem within wine, a dll.. or pat, and not an issue with VaraHF itself.
Martin Hebnes Pedersen
Nov 23, 2024, 4:58:41 PM11/23/24
to Craig Landschoot, pat-users
Hmm… this is a shot in the dark, but can you somehow confirm that the VARA modem is able to output sound? Is there a test-tone / tune etc you could try?
—
73 de LA5NTA / Martin
To view this discussion, visit https://groups.google.com/d/msgid/pat-users/a4d40a37-7530-46f5-8afc-c93571991e3dn%40googlegroups.com.
Craig Landschoot
Nov 23, 2024, 5:00:07 PM11/23/24
to Martin Hebnes Pedersen, pat-users
Yes. It will output sound to the radio and key the radio when using the tune function.
Martin Hebnes Pedersen
Nov 26, 2024, 1:37:22 AM11/26/24
to Craig Landschoot, pat-users
Craig,
Looking at the debug log output from Pat, I believe we are doing everything correct as per the VARA interface documentation.
The CONNECT command sent is correct, but for some reason VARA is unable to accept it.
I think we need assistance from the author of VARA in order to identify the cause of the issue. The lack of details in the error from VARA makes it very hard to debug.
Can you please try reaching out to the developer and share our findings so far?
Thanks!
--
73 de LA5NTA / Martin
Craig Landschoot
Nov 26, 2024, 8:29:47 AM11/26/24
to Martin Hebnes Pedersen, pat-users
Will do.
Reply all
Reply to author
Forward
0 new messages