search

la5nta / pat

A cross-platform Winlink client written in Go
https://getpat.io
MIT License
497 stars 86 forks source link

Weird issue when transmitting larger files using VARA FM. #418

Open oe3gwu opened 1 year ago

oe3gwu commented 1 year ago

I am Sysop of OE3XNR-11 and -10. We use Packet and VARA FM. So I am kind of familiar with those technologies.

Using VARA FM in a VM with Winlink Express, everything works perfect, I connect and send data all along, Packet after packet. I see the progress in the Vara FM Modem.

image This is a reference picture for how it should look like - not my connection.

Using Pat, I send a Data Packet, then the modem resets, all bars disappear, it seems he negotiates again, then send one packet again, and so on. It is VERY slow but stable. What is the issue here? I use the latest version.

image image image

martinhpedersen commented 1 year ago

Thanks for reporting this issue 😊

I'm having trouble reproducing this locally, so it would be very helpful to get some debug logs from your end. Can you please provide full log output while running with the environment variable VARA_DEBUG=1? E.g. VARA_DEBUG=1 pat connect varafm:///....

Thanks!

martinhpedersen commented 1 year ago

Also, what's the output from pat version?

oe3gwu commented 1 year ago

Pat Version 0.15

Yeah, I can retry with Debug logs, but it will take until tuesday, because I am not at home.

oe3gwu commented 1 year ago

Sorry for the delay, were some busy days.

Here is the debug log. There are too many PTT OFF / ON in the transfer comared to a Windows System. And I guess that is also the reason I dont get above speed level 3. With Windows I am on 7-8.

$ VARA_DEBUG=1 pat http
2023/07/22 21:20:37 Starting HTTP service (http://localhost:8080)...
2023/07/22 21:20:40 Auto converting 'hi-tech-industry-solutions-topbanner-min_5.jpg' [image/jpeg]...
2023/07/22 21:20:40 Done converting 'hi-tech-industry-solutions-topbanner-min_5.jpg'.
[VARA] 2023/07/22 21:20:55.232702 vara.go:192: Connecting command
[VARA] 2023/07/22 21:20:55.232853 vara.go:192: Connecting data
[VARA] 2023/07/22 21:20:55.232934 vara.go:110: writing cmd: PUBLIC ON
[VARA] 2023/07/22 21:20:55.232961 vara.go:120: writing cmd: COMPRESSION TEXT
[VARA] 2023/07/22 21:20:55.232978 vara.go:124: writing cmd: MYCALL OE3GWU
[VARA] 2023/07/22 21:20:55.232991 vara.go:128: writing cmd: LISTEN OFF
[VARA] 2023/07/22 21:20:55.233018 vara.go:346: writing cmd: VERSION
[VARA] 2023/07/22 21:20:55.237894 vara.go:259: got cmd: OK
[VARA] 2023/07/22 21:20:55.237903 vara.go:259: got cmd: OK
[VARA] 2023/07/22 21:20:55.237908 vara.go:259: got cmd: OK
[VARA] 2023/07/22 21:20:55.237911 vara.go:259: got cmd: OK
[VARA] 2023/07/22 21:20:55.237914 vara.go:259: got cmd: VERSION VARA FM v4.2.9
2023/07/22 21:20:55 VARA modem (VARA FM v4.2.9) initialized
2023/07/22 21:20:55 Connecting to OE3XNR-11 (varafm)...
[VARA] 2023/07/22 21:20:55.237956 transport.go:61: writing cmd: CONNECT OE3GWU OE3XNR-11
[VARA] 2023/07/22 21:20:55.384955 vara.go:259: got cmd: OK
[VARA] 2023/07/22 21:20:55.384972 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:20:55.384979 vara.go:259: got cmd: BUSY ON
[VARA] 2023/07/22 21:20:56.555155 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:20:57.697627 vara.go:259: got cmd: PENDING
[VARA] 2023/07/22 21:20:57.697643 vara.go:259: got cmd: CONNECTED OE3GWU OE3XNR-11 NARROW
[VARA] 2023/07/22 21:20:57.697662 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:20:57.697675 transport.go:76: dial completed - context cancellation no longer possible
2023/07/22 21:20:57 Connected to OE3XNR-11 (vara)
[VARA] 2023/07/22 21:20:58.535400 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:20:59.703867 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:00.067776 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:21:00.400518 vara.go:259: got cmd: REGISTERED OE3GWU
2023/07/22 21:21:00 VARA full speed available, registered to OE3GWU
[VARA] 2023/07/22 21:21:02.787553 vara.go:259: got cmd: PTT ON
WARC Nebelstein VHF/UHF/SHF Repeater Site - http://www.oe3xnr.eu
[WL2K-5.0-B2FWIHJM$]
;PQ: 29237743
CMS via OE3XNR >
[VARA] 2023/07/22 21:21:02.980027 conn.go:245: write: sending 104 bytes
>FC EM S6ZGZ6V4EJDR 6622 5940 0
[VARA] 2023/07/22 21:21:02.983204 conn.go:245: write: sending 31 bytes
Sending checksum FD
[VARA] 2023/07/22 21:21:02.983267 conn.go:205: write: buffer full (135 >= 42)
[VARA] 2023/07/22 21:21:03.126410 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:21:04.082208 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:04.656296 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:21:05.138801 vara.go:259: got cmd: BUFFER 118
[VARA] 2023/07/22 21:21:05.138822 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:05.138842 conn.go:205: write: buffer full (118 >= 42)
[VARA] 2023/07/22 21:21:07.256205 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:21:07.743078 vara.go:259: got cmd: BUFFER 0
[VARA] 2023/07/22 21:21:07.743093 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:07.743109 conn.go:245: write: sending 6 bytes
[VARA] 2023/07/22 21:21:08.086026 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:21:08.522239 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:08.875913 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:21:09.312130 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:09.876692 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:21:10.345034 vara.go:259: got cmd: BUFFER 0
[VARA] 2023/07/22 21:21:10.345055 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:10.685756 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:21:11.351089 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:11.695473 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:21:13.942054 vara.go:259: got cmd: PTT ON
;WARNING: Password could not be validated for OE3GWU@AMSAT.ORG
FS Y
Remote accepted S6ZGZ6V4EJDR
Transmitting [Vara Test] [offset 0]
[VARA] 2023/07/22 21:21:14.132362 conn.go:245: write: sending 14 bytes
[VARA] 2023/07/22 21:21:14.132397 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:14.132411 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:14.132421 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:14.132430 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:14.132444 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:14.132461 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:14.132470 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:14.132479 conn.go:205: write: buffer full (903 >= 889)
[VARA] 2023/07/22 21:21:14.277640 vara.go:259: got cmd: PTT OFF
Vara Test:   2%[VARA] 2023/07/22 21:21:14.733268 vara.go:259: got cmd: PTT ON
Vara Test:   2%[VARA] 2023/07/22 21:21:15.307307 vara.go:259: got cmd: PTT OFF
Vara Test:   2%[VARA] 2023/07/22 21:21:15.788643 vara.go:259: got cmd: BUFFER 892
[VARA] 2023/07/22 21:21:15.788660 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:15.788677 conn.go:205: write: buffer full (892 >= 889)
Vara Test:   2%[VARA] 2023/07/22 21:21:20.718099 vara.go:259: got cmd: PTT OFF
Vara Test:   2%[VARA] 2023/07/22 21:21:21.275447 vara.go:259: got cmd: BUFFER 0
[VARA] 2023/07/22 21:21:21.275464 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:21.275485 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:21.275514 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:21.275527 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:21.275536 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:21.275547 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:21.275555 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:21.275569 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:21.275579 conn.go:205: write: buffer full (889 >= 889)
Vara Test:  17%[VARA] 2023/07/22 21:21:21.617247 vara.go:259: got cmd: PTT OFF
Vara Test:  17%[VARA] 2023/07/22 21:21:22.051943 vara.go:259: got cmd: PTT ON
Vara Test:  17%[VARA] 2023/07/22 21:21:22.395717 vara.go:259: got cmd: PTT OFF
Vara Test:  17%[VARA] 2023/07/22 21:21:22.832822 vara.go:259: got cmd: PTT ON
Vara Test:  17%[VARA] 2023/07/22 21:21:23.397135 vara.go:259: got cmd: PTT OFF
Vara Test:  17%[VARA] 2023/07/22 21:21:23.875953 vara.go:259: got cmd: BUFFER 878
[VARA] 2023/07/22 21:21:23.875973 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:23.875997 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:23.876033 conn.go:205: write: buffer full (1005 >= 889)
Vara Test:  17%[VARA] 2023/07/22 21:21:28.805895 vara.go:259: got cmd: PTT OFF
Vara Test:  17%[VARA] 2023/07/22 21:21:29.334854 vara.go:259: got cmd: BUFFER 127
[VARA] 2023/07/22 21:21:29.334870 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:29.334885 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:29.334913 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:29.334927 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:29.334940 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:29.334965 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:29.334974 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:29.334982 conn.go:205: write: buffer full (889 >= 889)
Vara Test:  31%[VARA] 2023/07/22 21:21:29.688116 vara.go:259: got cmd: PTT OFF
Vara Test:  31%[VARA] 2023/07/22 21:21:30.121694 vara.go:259: got cmd: PTT ON
Vara Test:  31%[VARA] 2023/07/22 21:21:30.476704 vara.go:259: got cmd: PTT OFF
Vara Test:  31%[VARA] 2023/07/22 21:21:30.912825 vara.go:259: got cmd: PTT ON
Vara Test:  31%[VARA] 2023/07/22 21:21:31.477189 vara.go:259: got cmd: PTT OFF
Vara Test:  31%[VARA] 2023/07/22 21:21:31.955789 vara.go:259: got cmd: BUFFER 878
[VARA] 2023/07/22 21:21:31.955804 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:31.955818 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:31.955846 conn.go:205: write: buffer full (1005 >= 889)
Vara Test:  31%[VARA] 2023/07/22 21:21:36.887644 vara.go:259: got cmd: PTT OFF
Vara Test:  31%[VARA] 2023/07/22 21:21:37.413545 vara.go:259: got cmd: BUFFER 127
[VARA] 2023/07/22 21:21:37.413560 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:37.413573 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:37.413603 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:37.413616 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:37.413634 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:37.413649 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:37.413661 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:37.413674 conn.go:205: write: buffer full (889 >= 889)
Vara Test:  46%[VARA] 2023/07/22 21:21:37.767261 vara.go:259: got cmd: PTT OFF
Vara Test:  46%[VARA] 2023/07/22 21:21:38.199681 vara.go:259: got cmd: PTT ON
Vara Test:  46%[VARA] 2023/07/22 21:21:38.557022 vara.go:259: got cmd: PTT OFF
Vara Test:  46%[VARA] 2023/07/22 21:21:38.993473 vara.go:259: got cmd: PTT ON
Vara Test:  46%[VARA] 2023/07/22 21:21:39.567674 vara.go:259: got cmd: PTT OFF
Vara Test:  46%[VARA] 2023/07/22 21:21:40.041350 vara.go:259: got cmd: BUFFER 878
[VARA] 2023/07/22 21:21:40.041368 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:40.041388 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:40.041424 conn.go:205: write: buffer full (1005 >= 889)
Vara Test:  46%[VARA] 2023/07/22 21:21:44.965273 vara.go:259: got cmd: PTT OFF
Vara Test:  46%[VARA] 2023/07/22 21:21:45.497669 vara.go:259: got cmd: BUFFER 127
[VARA] 2023/07/22 21:21:45.497685 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:45.497701 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:45.497731 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:45.497752 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:45.497789 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:45.497809 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:45.497825 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:45.497842 conn.go:205: write: buffer full (889 >= 889)
Vara Test:  61%[VARA] 2023/07/22 21:21:45.845806 vara.go:259: got cmd: PTT OFF
Vara Test:  61%[VARA] 2023/07/22 21:21:46.279661 vara.go:259: got cmd: PTT ON
Vara Test:  61%[VARA] 2023/07/22 21:21:46.636081 vara.go:259: got cmd: PTT OFF
Vara Test:  61%[VARA] 2023/07/22 21:21:47.070104 vara.go:259: got cmd: PTT ON
Vara Test:  61%[VARA] 2023/07/22 21:21:47.645014 vara.go:259: got cmd: PTT OFF
Vara Test:  61%[VARA] 2023/07/22 21:21:48.119644 vara.go:259: got cmd: BUFFER 878
[VARA] 2023/07/22 21:21:48.119662 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:48.119680 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:48.119709 conn.go:205: write: buffer full (1005 >= 889)
Vara Test:  61%[VARA] 2023/07/22 21:21:49.782047 vara.go:259: got cmd: IAMALIVE
Vara Test:  61%[VARA] 2023/07/22 21:21:53.048982 vara.go:259: got cmd: PTT OFF
Vara Test:  61%[VARA] 2023/07/22 21:21:53.590642 vara.go:259: got cmd: BUFFER 127
[VARA] 2023/07/22 21:21:53.590663 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:53.590686 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:53.590741 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:53.590768 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:53.590794 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:53.590818 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:53.590844 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:53.590869 conn.go:205: write: buffer full (889 >= 889)
Vara Test:  76%[VARA] 2023/07/22 21:21:53.935633 vara.go:259: got cmd: PTT OFF
Vara Test:  76%[VARA] 2023/07/22 21:21:54.370354 vara.go:259: got cmd: PTT ON
Vara Test:  76%[VARA] 2023/07/22 21:21:54.716086 vara.go:259: got cmd: PTT OFF
Vara Test:  76%[VARA] 2023/07/22 21:21:55.153315 vara.go:259: got cmd: PTT ON
Vara Test:  76%[VARA] 2023/07/22 21:21:55.726424 vara.go:259: got cmd: PTT OFF
Vara Test:  76%[VARA] 2023/07/22 21:21:56.208356 vara.go:259: got cmd: BUFFER 878
[VARA] 2023/07/22 21:21:56.208373 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:21:56.208395 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:21:56.208434 conn.go:205: write: buffer full (1005 >= 889)
Vara Test:  76%[VARA] 2023/07/22 21:22:01.138017 vara.go:259: got cmd: PTT OFF
Vara Test:  76%[VARA] 2023/07/22 21:22:01.687345 vara.go:259: got cmd: BUFFER 127
[VARA] 2023/07/22 21:22:01.687362 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:01.687379 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:22:01.687411 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:22:01.687424 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:22:01.687432 conn.go:245: write: sending 127 bytes
[VARA] 2023/07/22 21:22:01.687446 conn.go:205: write: buffer full (635 >= 469)
Vara Test:  89%[VARA] 2023/07/22 21:22:02.026900 vara.go:259: got cmd: PTT OFF
Vara Test:  89%[VARA] 2023/07/22 21:22:02.472016 vara.go:259: got cmd: PTT ON
Vara Test:  89%[VARA] 2023/07/22 21:22:02.819728 vara.go:259: got cmd: PTT OFF
Vara Test:  89%[VARA] 2023/07/22 21:22:03.243055 vara.go:259: got cmd: PTT ON
Vara Test:  89%[VARA] 2023/07/22 21:22:03.817465 vara.go:259: got cmd: PTT OFF
Vara Test:  89%[VARA] 2023/07/22 21:22:04.287225 vara.go:259: got cmd: BUFFER 624
[VARA] 2023/07/22 21:22:04.287242 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:04.287260 conn.go:205: write: buffer full (624 >= 469)
Vara Test:  89%[VARA] 2023/07/22 21:22:09.217064 vara.go:259: got cmd: PTT OFF
Vara Test:  89%[VARA] 2023/07/22 21:22:09.755382 vara.go:259: got cmd: BUFFER 0
[VARA] 2023/07/22 21:22:09.755399 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:09.755421 conn.go:245: write: sending 67 bytes
[VARA] 2023/07/22 21:22:09.755466 conn.go:205: write: buffer full (67 >= 14)
Vara Test:  99%[VARA] 2023/07/22 21:22:10.095603 vara.go:259: got cmd: PTT OFF
Vara Test:  99%[VARA] 2023/07/22 21:22:10.522828 vara.go:259: got cmd: PTT ON
Vara Test:  99%[VARA] 2023/07/22 21:22:10.881208 vara.go:259: got cmd: PTT OFF
Vara Test:  99%[VARA] 2023/07/22 21:22:11.310707 vara.go:259: got cmd: PTT ON
Vara Test:  99%[VARA] 2023/07/22 21:22:11.877112 vara.go:259: got cmd: PTT OFF
Vara Test:  99%[VARA] 2023/07/22 21:22:12.339353 vara.go:259: got cmd: BUFFER 56
[VARA] 2023/07/22 21:22:12.339379 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:12.339400 conn.go:205: write: buffer full (56 >= 14)
Vara Test:  99%[VARA] 2023/07/22 21:22:14.458283 vara.go:259: got cmd: PTT OFF
Vara Test:  99%[VARA] 2023/07/22 21:22:14.952778 vara.go:259: got cmd: BUFFER 0
[VARA] 2023/07/22 21:22:14.952796 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:14.952812 conn.go:245: write: sending 2 bytes
[VARA] 2023/07/22 21:22:14.952846 conn.go:32: Flushing...
Vara Test: 100%[VARA] 2023/07/22 21:22:15.286719 vara.go:259: got cmd: PTT OFF
Vara Test: 100%[VARA] 2023/07/22 21:22:15.722054 vara.go:259: got cmd: PTT ON
Vara Test: 100%[VARA] 2023/07/22 21:22:16.077740 vara.go:259: got cmd: PTT OFF
Vara Test: 100%[VARA] 2023/07/22 21:22:16.512669 vara.go:259: got cmd: PTT ON
Vara Test: 100%[VARA] 2023/07/22 21:22:17.076656 vara.go:259: got cmd: PTT OFF
Vara Test: 100%[VARA] 2023/07/22 21:22:17.547259 vara.go:259: got cmd: BUFFER 0
[VARA] 2023/07/22 21:22:17.547277 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:17.547296 conn.go:63: Flushed
Vara Test: 100%
[VARA] 2023/07/22 21:22:17.885720 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:22:18.330419 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:18.687209 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:22:19.129919 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:19.485619 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:22:20.147131 vara.go:259: got cmd: PTT ON
FF
>FQ
[VARA] 2023/07/22 21:22:20.347485 conn.go:245: write: sending 3 bytes
[VARA] 2023/07/22 21:22:20.347517 conn.go:87: Closing connection...
[VARA] 2023/07/22 21:22:20.485873 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:22:20.929434 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:21.498143 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:22:21.947971 vara.go:259: got cmd: BUFFER 0
[VARA] 2023/07/22 21:22:21.947990 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:22.285243 vara.go:259: got cmd: PTT ON
[VARA] 2023/07/22 21:22:22.348393 conn.go:114: writing cmd: DISCONNECT
[VARA] 2023/07/22 21:22:22.350559 vara.go:259: got cmd: OK
[VARA] 2023/07/22 21:22:22.688188 vara.go:259: got cmd: DISCONNECTED
[VARA] 2023/07/22 21:22:22.688204 vara.go:259: got cmd: PTT OFF
[VARA] 2023/07/22 21:22:22.688220 vara.go:259: got cmd: BUSY OFF
[VARA] 2023/07/22 21:22:22.688225 vara.go:259: got cmd: CANCELPENDING
[VARA] 2023/07/22 21:22:23.443026 vara.go:259: got cmd: BUSY ON
[VARA] 2023/07/22 21:22:23.443052 vara.go:259: got cmd: BUSY OFF
[VARA] 2023/07/22 21:22:23.688849 conn.go:96: close: discarded 0 bytes of remaining data
2023/07/22 21:22:23 Disconnected.
martinhpedersen commented 1 year ago

Perfect. Thank you 😄

I'm not completely sure, but I think this relates to a bug in VARA. It sends very few BUFFER updates, and certainly not after each Write call as it should.

This is a known issue, but I though my workaround was sufficient... but maybe not.

I think we need to experiment with a higher "magic number" (see link above). Unfortunately, I did not make this configurable. We need to change some code and/or make it configurable in order to experiment with different values.

I am currently moving to a new QTH, so quite busy with RL at the moment. I'll get back to you as soon as I have some time to work on this 🙂

Thanks!

oe3gwu commented 1 year ago

What puzzles me is that in the GUI the bars disappear what already has been transferred. It looks like everytime he negotiates new. Also between every data transfer there are extra negotiations with speed level 1, and not only ACK's as usual. It is very weird.

Until solved, I use FX.25. Our Winlink Gateway works with both, and FX.25 is working really great, so no big deal currently.

Thanks for looking into it. If you wanna make tests, I am here to help.

73 Rainer (OE3GWU)