Unable to connect after first time

1

Running wfview server on a Pi 4 and a wfview client on MacOS 12.1 works after initial start (audio is an issue, but that’s for later). When stopping the client and starting it again, it refuses to connect to the server. Only after restarting wfview server, I can connect again from the client (once).
The logfile of the server:

2022-01-11 17:10:25.075 INF default: Setting rig state
2022-01-11 17:10:25.078 INF rig: Using incomingCIVAddr: (int):  148  hex:  94
2022-01-11 17:10:25.078 INF serial: Received rigCapabilities for "IC-7300"
2022-01-11 17:10:25.078 INF rig: Have rig ID: decimal:  148
2022-01-11 17:10:25.134 INF rigctld: Got rigcaps for: "IC-7300"
2022-01-11 17:10:25.139 INF system: Delay command interval timing:  25 ms
2022-01-11 17:10:27.492 INF rig: Received 0x15 center span data: for frequency  10000
2022-01-11 17:10:59.411 INF udp.server:  My IP Address:  "0.0.0.0"  My MAC Address:  "E4:5F:01:1D:A2:39"
2022-01-11 17:10:59.412 INF udp.server: Server Binding Control to:  50001
2022-01-11 17:10:59.412 INF udp.server: Server Binding CIV to:  50002
2022-01-11 17:10:59.412 INF udp.server: Server Binding Audio to:  50003
2022-01-11 17:11:21.011 INF udp.server: "::ffff:192.168.2.100" : New Control connection created
2022-01-11 17:11:21.012 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Received 'are you there'
2022-01-11 17:11:21.017 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Received 'Are you ready'
2022-01-11 17:11:21.023 INF udp.server: "::ffff:192.168.2.100" : Received 'login'
2022-01-11 17:11:21.024 INF udp.server: "::ffff:192.168.2.100" : User  "pi"  login OK
2022-01-11 17:11:21.024 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Login response:  1
2022-01-11 17:11:21.030 INF udp.server: "::ffff:192.168.2.100" : Received create token request
2022-01-11 17:11:21.030 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Capabilities : 2
2022-01-11 17:11:21.031 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Client will have TX audio
2022-01-11 17:11:21.031 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending ConnectionInfo : 3
2022-01-11 17:11:21.035 INF udp.server: "::ffff:192.168.2.100" : Received request for radio connection
2022-01-11 17:11:21.035 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Status
2022-01-11 17:11:21.036 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending ConnectionInfo : 5
2022-01-11 17:11:21.036 INF udp.server: "::ffff:192.168.2.100" : rxCodec: 1  txCodec: 1  rxSampleRate 16000  txSampleRate 16000  txBufferLen 101
2022-01-11 17:11:21.038 INF audio: Output setVolume:  39 ( 0.0469 )
2022-01-11 17:11:21.038 INF audio: Output Internal: sample rate 48000 channel count 2
2022-01-11 17:11:21.038 INF audio: Input Internal: sample rate 48000 channel count 2
2022-01-11 17:11:21.039 INF audio: Output wf_resampler_init() returned:  0  resampleRatio:  3
2022-01-11 17:11:21.039 INF audio: Input wf_resampler_init() returned:  0  resampleRatio:  0.333333
2022-01-11 17:11:21.039 INF audio: Input thread id 0x987ff380
2022-01-11 17:11:21.040 INF audio: Input start() running
2022-01-11 17:11:21.040 INF audio: Output thread id 0x9913e380
2022-01-11 17:11:21.040 INF audio: Output start() running
2022-01-11 17:11:21.041 WRN default: "Stream error: No such entity"
2022-01-11 17:11:21.042 INF udp.server: "::ffff:192.168.2.100" ( "CIV" ): New connection created
2022-01-11 17:11:21.042 WRN default: "Stream error: No such entity"
2022-01-11 17:11:21.043 INF udp.server: "::ffff:192.168.2.100" ( "CIV" ): Received 'are you there'
2022-01-11 17:11:21.044 INF udp.server: "::ffff:192.168.2.100" ( "Audio" ): New connection created
2022-01-11 17:11:21.044 INF udp.server: "::ffff:192.168.2.100" ( "Audio" ): Received 'are you there'
2022-01-11 17:11:21.048 INF udp.server: "::ffff:192.168.2.100" ( "CIV" ): Received 'Are you ready'
2022-01-11 17:11:21.049 INF udp.server: "::ffff:192.168.2.100" ( "Audio" ): Received 'Are you ready'
2022-01-11 17:11:21.112 INF rig: Have rig ID: decimal:  148
2022-01-11 17:11:22.767 INF rig: Received 0x15 center span data: for frequency  10000
2022-01-11 17:12:03.952 INF udp.server: "::ffff:192.168.2.100" : Received token disconnect request
2022-01-11 17:12:03.953 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  1
2022-01-11 17:12:03.954 INF udp.server: "::ffff:192.168.2.100" : Received 'disconnect' request
2022-01-11 17:12:03.954 INF udp.server: Deleting "Audio" connection to:  "::ffff:192.168.2.100" : "64221"
2022-01-11 17:12:03.955 INF udp.server: Found "Audio" connection to:  "::ffff:192.168.2.100" : "64221"
2022-01-11 17:12:03.957 INF udp.server: Current Number of clients connected:  0

The last line is from the first disconnect, after that nothing is logged on the server anymore.
The log on the client is:

2022-01-11 17:12:16.540 INF system: "wfview version: 1.2d (Git:b1ef680 on Dec  4 2021 at 16:26:19 by phil@Phils-MacBook-Pro-3.local)\nOperating System: macOS 12.1 (arm64)\nBuild Qt Version 5.15.2. Current Qt Version: 5.15.2\n"
2022-01-11 17:12:16.795 WRN qt.qpa.fonts: Populating font family aliases took 134 ms. Replace uses of missing font family "DejaVu Sans" with one that exists to avoid this cost. 
2022-01-11 17:12:16.835 INF default: setState 1
2022-01-11 17:12:16.836 INF default: setState 0
2022-01-11 17:12:16.836 INF default: setState 1
2022-01-11 17:12:16.869 INF system: Loading settings from  "/Users/ron/Library/Containers/org.wfview.wfview/Data/Library/Preferences/org.wfview.wfview.plist"
2022-01-11 17:12:16.870 INF gui: Got Audio Output:  "BlackHole 2ch"
2022-01-11 17:12:16.870 INF gui: Got Audio Input:  "BlackHole 2ch"
2022-01-11 17:12:16.871 INF default: Getting server config
2022-01-11 17:12:16.979 INF system: Cannot prepare WF view without rigCaps. Waiting on this.
2022-01-11 17:12:16.980 INF udp: Starting udpHandler user: "pi"  rx latency: 100  tx latency: 101  rx sample rate:  16000  rx codec:  1  tx sample rate:  16000  tx codec:  1
2022-01-11 17:12:16.983 INF udp: UDP Stream bound to local port: 55552  remote port: 50001
2022-01-11 17:12:17.012 INF system: Received CommReady!! 
2022-01-11 17:12:26.115 INF udp: Closing UDP stream : "192.168.2.220" : 50001
2022-01-11 17:12:26.116 INF udp: Starting udpHandler user: "pi"  rx latency: 100  tx latency: 101  rx sample rate:  16000  rx codec:  1  tx sample rate:  16000  tx codec:  1
2022-01-11 17:12:26.118 INF system: Received CommReady!! 
2022-01-11 17:12:26.119 INF udp: UDP Stream bound to local port: 49854  remote port: 50001
2022-01-11 17:12:28.816 INF udp: Closing UDP stream : "192.168.2.220" : 50001
2022-01-11 17:12:28.816 INF udp: Starting udpHandler user: "pi"  rx latency: 100  tx latency: 101  rx sample rate:  16000  rx codec:  1  tx sample rate:  16000  tx codec:  1
2022-01-11 17:12:28.818 INF system: Received CommReady!! 
2022-01-11 17:12:28.819 INF udp: UDP Stream bound to local port: 53936  remote port: 50001

What could be the issue?

1 Like
2

Hi Ron.

It is possible that you are experiencing a ‘deadlock’ condition on the server. When you restart it, does it exit cleanly or do you need to ‘force’ it to close?

There is currently an issue with audio on the server if you are using a recent download of wfview from gitlab. We are working on this but the workaround is to use Portaudio and the settings branch.

If you edit the script file that you use to build wfview, just edit the git line to select the branch called settings (there are examples in the script)

The you need to install the Portaudio library:

sudo apt-get install portaudio19-dev

Then edit the wfview.pro file located in the wfview source directory and remove the # before the line:

# DEFINES += PORTAUDIO

Then change to the build directory and run qmake/make:

cd ../build
qmake ../wfview/wfview.pro
make -j2
sudo make install
3

Hi Phil,

Thanks for the tips. I did use a recent source version, indeed.
I’ll rebuilld with the other branch and test again.

4

Hi Ron

We have actually just reverted a number of (not quite finished) changes to the master branch so it should work if you now pull the master branch (no need to use portaudio)

73 PHIL M0VSE

5

Yes, I just got notified about that.

6

Make sure to do an entirely fresh pull in a new directory. We’ve reverted the master branch, so the regular build script should do fine.

–E
de W6EL

1 Like
7

Going back to the master branch with a fresh raspbian buster image made it magically work for me, somehow :sunglasses:. I can also stop and start the client without having to restart the server.
On my Mac I now receives audio as well. Next step is to start integrating with the likes of RumLogNG and WSJT-x…

//Ron - 73 de PA7CT

BTW, did I already mention I really appreciate the developers’ work on making wfview a great tool for the Ham? :+1:

8

I have wfview (Client-Server), WSJT-X, RUMLogNG and JT-Bridge running and was able to work several QSO’s with FT8.
However, the connection doesn’t seem to be stable over a longer period. Initially it worked fine for about an hour and a half and then the server stopped responding. I noticed the wfview server could not exit cleanly and had to be killed to restart.
This evening, I did a few more tests and sometimes (mainly after the laptop has been in sleep mode) the client stops working (no audio and no rig control). Restarting the client usually helps but in one occasion I had to restart the wfview server to get the connection up.

I will do some more testing and log file checking and report back.

UPDATE 1:
To clarify the environment: wfview server on Pi4 with Raspbian Buster. Client on MacOS 12.1 (arm64).
Wfview client lost the connection with the wfview server after a while and even restarting the client didn’t fix it. The window of Wfview in server mode was still responding but the program could not be terminated with Exit program. I also noticed that any other window I opened on the desktop of the Pi 4 couldn’t get focus again after it was initially launched, after killing the wfview process, all windows could get focus again.
Restarting wfview in server mode fixed the connection issue (without restarting the client). I realised too late that the wfview.log file would be overridden upon restart, so I cannot share the log from when it sort of hanged.
Another thing I will try is to force the wfview server to use IPv4 instead of IPv6 and see if that makes any difference.

9

Hi Ron,

Glad you’re enjoying the program! Phil is working on the server code as we speak, so stay tuned and keep the reports coming.

–E
de W6EL

1 Like
10

EDIT: Just noted the updated settings branch and will test that.

UPDATE 2:
Audio continues to stream but no CI-V. Stopped the client. Logfile on client:

2022-01-14 07:25:35.668 INF system: "wfview version: 1.2d (Git:b1ef680 on Dec  4 2021 at 16:26:19 by phil@Phils-MacBook-Pro-3.local)\nOperating System: macOS 12.1 (arm64)\nBuild Qt Version 5.15.2. Current Qt Version: 5.15.2\n"
2022-01-14 07:25:35.794 WRN qt.qpa.fonts: Populating font family aliases took 83 ms. Replace uses of missing font family "DejaVu Sans" with one that exists to avoid this cost. 
2022-01-14 07:25:35.822 INF default: setState 1
2022-01-14 07:25:35.822 INF default: setState 0
2022-01-14 07:25:35.822 INF default: setState 1
2022-01-14 07:25:35.842 INF system: Loading settings from  "/Users/ron/Library/Containers/org.wfview.wfview/Data/Library/Preferences/org.wfview.wfview.plist"
2022-01-14 07:25:35.843 INF rigctld: started on port  4533
2022-01-14 07:25:35.844 INF gui: Got Audio Output:  "Multi-Output Device"
2022-01-14 07:25:35.844 INF gui: Got Audio Input:  "MacBook Pro Microphone"
2022-01-14 07:25:35.844 INF default: Getting server config
2022-01-14 07:25:35.873 INF system: Cannot prepare WF view without rigCaps. Waiting on this.
2022-01-14 07:25:35.873 INF udp: Starting udpHandler user: "hampi"  rx latency: 100  tx latency: 101  rx sample rate:  16000  rx codec:  1  tx sample rate:  16000  tx codec:  1
2022-01-14 07:25:35.875 INF serial: Opened pt device:  31 , attempting to grant pt status
2022-01-14 07:25:35.875 INF serial: Opened pseudoterminal, slave name : /dev/ttys000
2022-01-14 07:25:35.875 INF udp: UDP Stream bound to local port: 64861  remote port: 50001
2022-01-14 07:25:35.875 INF serial: Created link to "/dev/ttys000" from "/Users/ron/Library/Containers/org.wfview.wfview/Data/Downloads/rig-pty1"
2022-01-14 07:25:35.899 INF system: Received CommReady!! 
2022-01-14 07:25:35.899 INF default: Setting rig state
2022-01-14 07:25:36.413 INF udp: udpHandler : Received I am here from:  QHostAddress("::ffff:192.168.2.220")
2022-01-14 07:25:36.413 INF udp: udpHandler : Received I am here 
2022-01-14 07:25:36.416 INF udp: udpHandler : Received I am ready
2022-01-14 07:25:36.416 INF udp: udpHandler : Sending login packet
2022-01-14 07:25:36.420 INF udp: Got connection type: "WFVIEW"
2022-01-14 07:25:36.420 INF udp: udpHandler : Received matching token response to our request
2022-01-14 07:25:36.420 INF udp: udpHandler : Detected connection speed  WFVIEW
2022-01-14 07:25:36.424 INF udp: udpHandler Received radio capabilities, Name: "IC-7300"  Audio: "ICOM_VAUDIO" CIV: 94
2022-01-14 07:25:36.425 INF default: Received serial port baud rate from remote server: 115200
2022-01-14 07:25:36.425 INF system: Delay command interval timing:  75 ms
2022-01-14 07:25:36.428 INF udp: Starting udpCivData
2022-01-14 07:25:36.429 INF udp: UDP Stream bound to local port: 50862  remote port: 50002
2022-01-14 07:25:36.429 INF udp: Starting udpAudio
2022-01-14 07:25:36.429 INF udp: UDP Stream bound to local port: 62035  remote port: 50003
2022-01-14 07:25:36.429 INF udp: udpHandler Got serial and audio request success, device name:  "IC-7300"
2022-01-14 07:25:36.429 INF audio: Input Internal: sample rate 48000 channel count 2
2022-01-14 07:25:36.430 INF audio: Output setVolume:  255 ( 1 )
2022-01-14 07:25:36.430 INF audio: Input wf_resampler_init() returned:  0  resampleRatio:  0.333333
2022-01-14 07:25:36.430 INF audio: Output Internal: sample rate 48000 channel count 2
2022-01-14 07:25:36.430 INF audio: Input thread id 0x16de1b000
2022-01-14 07:25:36.430 INF audio: Output wf_resampler_init() returned:  0  resampleRatio:  3
2022-01-14 07:25:36.430 INF audio: Input start() running
2022-01-14 07:25:36.430 INF audio: Output thread id 0x16dd8f000
2022-01-14 07:25:36.430 INF audio: Output start() running
2022-01-14 07:25:36.480 INF audio: Input Audio now in idle state:  0  packets in buffer
2022-01-14 07:25:36.498 INF udp: udpAudio : Received I am here 
2022-01-14 07:25:36.498 INF udp: udpCivData : Received I am here 
2022-01-14 07:25:36.507 INF audio: Output Audio now in active state:  0  packets in buffer
2022-01-14 07:25:36.552 INF audio: Input Audio now in active state:  0  packets in buffer
2022-01-14 07:25:38.444 INF udp:  CIV Watchdog: no CIV data received for 2s, requesting data start.
2022-01-14 07:25:40.699 INF audio: Output Audio now in stopped state:  0  packets in buffer
2022-01-14 07:25:40.760 INF udp: Closing UDP stream : "192.168.2.220" : 50003
2022-01-14 07:25:40.761 INF udp: Closing UDP stream : "192.168.2.220" : 50002
2022-01-14 07:25:40.761 INF udp: Sending token removal packet
2022-01-14 07:25:40.761 INF udp: Closing UDP stream : "192.168.2.220" : 50001
2022-01-14 07:25:40.762 INF udp: Starting udpHandler user: "hampi"  rx latency: 100  tx latency: 101  rx sample rate:  16000  rx codec:  1  tx sample rate:  16000  tx codec:  1
2022-01-14 07:25:40.767 INF serial: Opened pt device:  23 , attempting to grant pt status
2022-01-14 07:25:40.768 INF serial: Opened pseudoterminal, slave name : /dev/ttys001
2022-01-14 07:25:40.768 INF serial: Created link to "/dev/ttys001" from "/Users/ron/Library/Containers/org.wfview.wfview/Data/Downloads/rig-pty1"
2022-01-14 07:25:40.768 INF system: Received CommReady!! 
2022-01-14 07:25:40.769 INF udp: UDP Stream bound to local port: 54393  remote port: 50001
2022-01-14 07:25:40.769 INF default: Setting rig state
2022-01-14 07:25:41.307 INF udp: udpHandler : Received I am here from:  QHostAddress("::ffff:192.168.2.220")
2022-01-14 07:25:41.307 INF udp: udpHandler : Received I am here 
2022-01-14 07:25:41.310 INF udp: udpHandler : Received I am ready
2022-01-14 07:25:41.311 INF udp: udpHandler : Sending login packet
2022-01-14 07:25:41.314 INF udp: Got connection type: "WFVIEW"
2022-01-14 07:25:41.314 INF udp: udpHandler : Received matching token response to our request
2022-01-14 07:25:41.315 INF udp: udpHandler : Detected connection speed  WFVIEW
2022-01-14 07:25:41.318 INF udp: udpHandler Received radio capabilities, Name: "IC-7300"  Audio: "ICOM_VAUDIO" CIV: 94
2022-01-14 07:25:41.318 INF default: Received serial port baud rate from remote server: 115200
2022-01-14 07:25:41.318 INF system: Delay command interval timing:  75 ms
2022-01-14 07:25:41.323 INF udp: Starting udpCivData
2022-01-14 07:25:41.324 INF udp: UDP Stream bound to local port: 54394  remote port: 50002
2022-01-14 07:25:41.324 INF udp: Starting udpAudio
2022-01-14 07:25:41.326 INF udp: UDP Stream bound to local port: 52883  remote port: 50003
2022-01-14 07:25:41.326 INF audio: Output setVolume:  255 ( 1 )
2022-01-14 07:25:41.326 INF audio: Input Internal: sample rate 48000 channel count 2
2022-01-14 07:25:41.326 INF udp: udpHandler Got serial and audio request success, device name:  "IC-7300"
2022-01-14 07:25:41.327 INF audio: Output Internal: sample rate 48000 channel count 2
2022-01-14 07:25:41.327 INF audio: Input wf_resampler_init() returned:  0  resampleRatio:  0.333333
2022-01-14 07:25:41.327 INF audio: Output wf_resampler_init() returned:  0  resampleRatio:  3
2022-01-14 07:25:41.327 INF audio: Input thread id 0x16dc77000
2022-01-14 07:25:41.327 INF audio: Output thread id 0x16d55b000
2022-01-14 07:25:41.327 INF audio: Input start() running
2022-01-14 07:25:41.327 INF audio: Output start() running
2022-01-14 07:25:41.330 INF udp: udpCivData : Received I am here 
2022-01-14 07:25:41.332 INF audio: Input Audio now in idle state:  0  packets in buffer
2022-01-14 07:25:41.333 INF udp: udpAudio : Received I am here 
2022-01-14 07:25:41.360 INF audio: Output Audio now in active state:  0  packets in buffer
2022-01-14 07:25:41.419 INF audio: Input Audio now in active state:  0  packets in buffer
2022-01-14 07:25:43.424 INF udp:  CIV Watchdog: no CIV data received for 2s, requesting data start.
2022-01-14 07:25:54.364 INF audio: Output Audio now in stopped state:  0  packets in buffer
2022-01-14 07:25:54.438 INF udp: Closing UDP stream : "192.168.2.220" : 50003
2022-01-14 07:25:54.439 INF udp: Closing UDP stream : "192.168.2.220" : 50002
2022-01-14 07:25:54.439 INF udp: Sending token removal packet
2022-01-14 07:25:54.439 INF udp: Closing UDP stream : "192.168.2.220" : 50001
2022-01-14 07:25:54.440 INF udp: Starting udpHandler user: "hampi"  rx latency: 100  tx latency: 101  rx sample rate:  16000  rx codec:  1  tx sample rate:  16000  tx codec:  1
2022-01-14 07:25:54.447 INF serial: Opened pt device:  32 , attempting to grant pt status
2022-01-14 07:25:54.447 INF serial: Opened pseudoterminal, slave name : /dev/ttys004
2022-01-14 07:25:54.448 INF serial: Created link to "/dev/ttys004" from "/Users/ron/Library/Containers/org.wfview.wfview/Data/Downloads/rig-pty1"
2022-01-14 07:25:54.448 INF udp: UDP Stream bound to local port: 58592  remote port: 50001
2022-01-14 07:25:54.448 INF system: Received CommReady!! 
2022-01-14 07:25:54.448 INF default: Setting rig state
2022-01-14 07:25:54.955 INF udp: udpHandler : Received I am here from:  QHostAddress("::ffff:192.168.2.220")
2022-01-14 07:25:54.956 INF udp: udpHandler : Received I am here 
2022-01-14 07:25:54.959 INF udp: udpHandler : Received I am ready
2022-01-14 07:25:54.959 INF udp: udpHandler : Sending login packet
2022-01-14 07:25:54.962 INF udp: Got connection type: "WFVIEW"
2022-01-14 07:25:54.963 INF udp: udpHandler : Received matching token response to our request
2022-01-14 07:25:54.963 INF udp: udpHandler : Detected connection speed  WFVIEW
2022-01-14 07:25:54.967 INF udp: udpHandler Received radio capabilities, Name: "IC-7300"  Audio: "ICOM_VAUDIO" CIV: 94
2022-01-14 07:25:54.967 INF default: Received serial port baud rate from remote server: 115200
2022-01-14 07:25:54.967 INF system: Delay command interval timing:  75 ms
2022-01-14 07:25:54.970 INF udp: Starting udpCivData
2022-01-14 07:25:54.971 INF udp: UDP Stream bound to local port: 54559  remote port: 50002
2022-01-14 07:25:54.972 INF udp: Starting udpAudio
2022-01-14 07:25:54.972 INF udp: UDP Stream bound to local port: 59502  remote port: 50003
2022-01-14 07:25:54.972 INF audio: Input Internal: sample rate 48000 channel count 2
2022-01-14 07:25:54.973 INF udp: udpHandler Got serial and audio request success, device name:  "IC-7300"
2022-01-14 07:25:54.973 INF audio: Output setVolume:  255 ( 1 )
2022-01-14 07:25:54.973 INF audio: Input wf_resampler_init() returned:  0  resampleRatio:  0.333333
2022-01-14 07:25:54.973 INF audio: Output Internal: sample rate 48000 channel count 2
2022-01-14 07:25:54.973 INF audio: Input thread id 0x16dc77000
2022-01-14 07:25:54.973 INF audio: Output wf_resampler_init() returned:  0  resampleRatio:  3
2022-01-14 07:25:54.973 INF audio: Input start() running
2022-01-14 07:25:54.973 INF audio: Output thread id 0x16dbeb000
2022-01-14 07:25:54.973 INF audio: Output start() running
2022-01-14 07:25:54.980 INF udp: udpCivData : Received I am here 
2022-01-14 07:25:54.980 INF audio: Input Audio now in idle state:  0  packets in buffer
2022-01-14 07:25:54.981 INF udp: udpAudio : Received I am here 
2022-01-14 07:25:55.006 INF audio: Output Audio now in active state:  0  packets in buffer
2022-01-14 07:25:55.065 INF audio: Input Audio now in active state:  0  packets in buffer
2022-01-14 07:25:57.443 INF udp:  CIV Watchdog: no CIV data received for 2s, requesting data start.
2022-01-14 07:26:04.993 INF rigctld:  session connected:  46
2022-01-14 07:26:15.063 INF rigctld: 46 disconnected
2022-01-14 07:26:15.063 INF rigctld:  session connected:  7
2022-01-14 07:26:15.131 INF rigctld: 7 disconnected
2022-01-14 07:26:15.132 INF rigctld:  session connected:  7
2022-01-14 07:26:25.203 INF rigctld: 7 disconnected
2022-01-14 07:27:13.177 INF audio: Output Audio now in stopped state:  0  packets in buffer
2022-01-14 07:27:13.237 INF udp: Closing UDP stream : "192.168.2.220" : 50003
2022-01-14 07:27:13.238 INF udp: Closing UDP stream : "192.168.2.220" : 50002
2022-01-14 07:27:13.239 INF udp: Sending token removal packet
2022-01-14 07:27:13.239 INF udp: Closing UDP stream : "192.168.2.220" : 50001
2022-01-14 07:27:13.240 INF rigctld: closing rigctld

Worked again for a while after restart of the client. After about 25 minutes the audio and rig control stopped working. This time restart of the client didn’t fix it. Log file of client before restart:

2022-01-14 07:31:36.968 INF system: "wfview version: 1.2d (Git:b1ef680 on Dec  4 2021 at 16:26:19 by phil@Phils-MacBook-Pro-3.local)\nOperating System: macOS 12.1 (arm64)\nBuild Qt Version 5.15.2. Current Qt Version: 5.15.2\n"
2022-01-14 07:31:37.111 WRN qt.qpa.fonts: Populating font family aliases took 85 ms. Replace uses of missing font family "DejaVu Sans" with one that exists to avoid this cost. 
2022-01-14 07:31:37.140 INF default: setState 1
2022-01-14 07:31:37.140 INF default: setState 0
2022-01-14 07:31:37.140 INF default: setState 1
2022-01-14 07:31:37.159 INF system: Loading settings from  "/Users/ron/Library/Containers/org.wfview.wfview/Data/Library/Preferences/org.wfview.wfview.plist"
2022-01-14 07:31:37.162 INF rigctld: started on port  4533
2022-01-14 07:31:37.162 INF gui: Got Audio Output:  "Multi-Output Device"
2022-01-14 07:31:37.162 INF gui: Got Audio Input:  "MacBook Pro Microphone"
2022-01-14 07:31:37.163 INF default: Getting server config
2022-01-14 07:31:37.197 INF system: Cannot prepare WF view without rigCaps. Waiting on this.
2022-01-14 07:31:37.197 INF udp: Starting udpHandler user: "hampi"  rx latency: 100  tx latency: 101  rx sample rate:  16000  rx codec:  1  tx sample rate:  16000  tx codec:  1
2022-01-14 07:31:37.369 INF serial: Opened pt device:  29 , attempting to grant pt status
2022-01-14 07:31:37.369 INF serial: Opened pseudoterminal, slave name : /dev/ttys000
2022-01-14 07:31:37.369 INF serial: Created link to "/dev/ttys000" from "/Users/ron/Library/Containers/org.wfview.wfview/Data/Downloads/rig-pty1"
2022-01-14 07:31:37.369 INF system: Received CommReady!! 
2022-01-14 07:31:37.370 INF default: Setting rig state
2022-01-14 07:31:37.370 INF udp: UDP Stream bound to local port: 63962  remote port: 50001
2022-01-14 07:31:37.899 INF udp: udpHandler : Received I am here from:  QHostAddress("::ffff:192.168.2.220")
2022-01-14 07:31:37.900 INF udp: udpHandler : Received I am here 
2022-01-14 07:31:37.902 INF udp: udpHandler : Received I am ready
2022-01-14 07:31:37.902 INF udp: udpHandler : Sending login packet
2022-01-14 07:31:37.906 INF udp: Got connection type: "WFVIEW"
2022-01-14 07:31:37.906 INF udp: udpHandler : Received matching token response to our request
2022-01-14 07:31:37.906 INF udp: udpHandler : Detected connection speed  WFVIEW
2022-01-14 07:31:37.910 INF udp: udpHandler Received radio capabilities, Name: "IC-7300"  Audio: "ICOM_VAUDIO" CIV: 94
2022-01-14 07:31:37.910 INF default: Received serial port baud rate from remote server: 115200
2022-01-14 07:31:37.910 INF system: Delay command interval timing:  75 ms
2022-01-14 07:31:37.915 INF udp: Starting udpCivData
2022-01-14 07:31:37.915 INF udp: UDP Stream bound to local port: 58576  remote port: 50002
2022-01-14 07:31:37.915 INF udp: Starting udpAudio
2022-01-14 07:31:37.916 INF udp: UDP Stream bound to local port: 52947  remote port: 50003
2022-01-14 07:31:37.916 INF audio: Input Internal: sample rate 48000 channel count 2
2022-01-14 07:31:37.916 INF audio: Output setVolume:  255 ( 1 )
2022-01-14 07:31:37.916 INF udp: udpHandler Got serial and audio request success, device name:  "IC-7300"
2022-01-14 07:31:37.916 INF audio: Output Internal: sample rate 48000 channel count 2
2022-01-14 07:31:37.916 INF audio: Input wf_resampler_init() returned:  0  resampleRatio:  0.333333
2022-01-14 07:31:37.916 INF audio: Output wf_resampler_init() returned:  0  resampleRatio:  3
2022-01-14 07:31:37.916 INF audio: Input thread id 0x16b9e7000
2022-01-14 07:31:37.917 INF audio: Output thread id 0x16b95b000
2022-01-14 07:31:37.917 INF audio: Input start() running
2022-01-14 07:31:37.917 INF audio: Output start() running
2022-01-14 07:31:37.921 INF udp: udpCivData : Received I am here 
2022-01-14 07:31:37.921 INF udp: udpAudio : Received I am here 
2022-01-14 07:31:37.939 INF rig: Warning: Spectrum sequence max was zero, yet spectrum was received.
2022-01-14 07:31:37.960 INF rig: Warning: Spectrum sequence max was zero, yet spectrum was received.
2022-01-14 07:31:37.968 INF audio: Input Audio now in idle state:  0  packets in buffer
2022-01-14 07:31:37.982 INF rig: Warning: Spectrum sequence max was zero, yet spectrum was received.
2022-01-14 07:31:37.994 INF rig: Using incomingCIVAddr: (int):  148  hex:  94
2022-01-14 07:31:37.994 INF serial: Received rigCapabilities for "IC-7300"
2022-01-14 07:31:37.994 INF rig: Have rig ID: decimal:  148
2022-01-14 07:31:37.994 INF rigctld: Got rigcaps for: "IC-7300"
2022-01-14 07:31:37.995 INF audio: Output Audio now in active state:  0  packets in buffer
2022-01-14 07:31:37.995 INF system: Delay command interval timing:  25 ms
2022-01-14 07:31:38.039 INF audio: Input Audio now in active state:  0  packets in buffer
2022-01-14 07:31:39.776 INF rig: Received 0x15 center span data: for frequency  10000
2022-01-14 07:31:44.238 INF rigctld:  session connected:  44
2022-01-14 07:31:50.267 INF audio: Output Audio now in active state:  0  packets in buffer
2022-01-14 07:31:50.267 INF audio: Output Audio now in active state:  0  packets in buffer
2022-01-14 07:44:42.911 INF udp: udpCivData : ******* seq number has rolled over ****** previous highest:  ffff  current:  1
2022-01-14 07:47:00.590 INF default: setState 3
2022-01-14 07:47:14.111 INF default: setState 0
2022-01-14 07:47:30.112 INF default: setState 3
2022-01-14 07:47:44.711 INF default: setState 0
2022-01-14 07:48:02.433 INF udp:  CIV Watchdog: no CIV data received for 2s, requesting data start.
2022-01-14 07:48:02.433 INF udp:  Audio Watchdog: no audio data received for 2s, restart required?
2022-01-14 07:57:52.029 INF audio: Output Audio now in stopped state:  0  packets in buffer
2022-01-14 07:57:52.097 INF udp: Closing UDP stream : "192.168.2.220" : 50003
2022-01-14 07:57:52.099 INF udp: Closing UDP stream : "192.168.2.220" : 50002
2022-01-14 07:57:52.099 INF udp: Sending token removal packet
2022-01-14 07:57:52.099 INF udp: Closing UDP stream : "192.168.2.220" : 50001
2022-01-14 07:57:52.101 INF rigctld: closing rigctld

This time, the wfview server was still showing a waterfall but the desktop became partly unresponsive. Wfview could not exit clean and was using 100% cpu (1 core). Log file of wfview server:

2022-01-14 07:31:02.348 INF system: "wfview version: 1.2d (Git:f8351ad on Jan 13 2022 at 14:19:02 by pi@hampi)\nOperating System: Raspbian GNU/Linux 10 (buster) (arm)\nBuild Qt Version 5.11.3. Current Qt Version: 5.11.3\n"
2022-01-14 07:31:02.667 INF default: setState 1
2022-01-14 07:31:02.669 INF default: setState 0
2022-01-14 07:31:02.670 INF default: setState 1
2022-01-14 07:31:05.739 INF system: Loading settings from  "/home/pi/.config/wfview/wfview.conf"
2022-01-14 07:31:05.761 INF gui: Got Audio Output:  ""
2022-01-14 07:31:05.761 INF gui: Got Audio Input:  ""
2022-01-14 07:31:05.764 INF default: Getting server config
2022-01-14 07:31:06.097 INF system: Cannot prepare WF view without rigCaps. Waiting on this.
2022-01-14 07:31:06.097 INF udp.server: Starting udp server
2022-01-14 07:31:06.100 INF system: Could not find Icom serial port. Falling back to OS default. Use --port to specify, or modify preferences.
2022-01-14 07:31:06.108 INF udp.server:  My IP Address:  "0.0.0.0"  My MAC Address:  "E4:5F:01:1D:A2:39"
2022-01-14 07:31:06.108 INF udp.server: Server Binding Control to:  50001
2022-01-14 07:31:06.111 INF udp.server: Server Binding CIV to:  50002
2022-01-14 07:31:06.111 INF udp.server: Server Binding Audio to:  50003
2022-01-14 07:31:06.111 INF serial: Opened port:  "/dev/ttyUSB0"
2022-01-14 07:31:06.429 INF system: Received CommReady!! 
2022-01-14 07:31:06.430 INF system: Delay command interval timing:  75 ms
2022-01-14 07:31:06.431 INF default: Setting rig state for wfmain
2022-01-14 07:31:06.433 INF rig: Using incomingCIVAddr: (int):  148  hex:  94
2022-01-14 07:31:06.433 INF serial: Received rigCapabilities for "IC-7300"
2022-01-14 07:31:06.433 INF rig: Have rig ID: decimal:  148
2022-01-14 07:31:06.456 INF system: Delay command interval timing:  25 ms
2022-01-14 07:31:08.088 INF rig: Received 0x15 center span data: for frequency  10000
2022-01-14 07:31:37.901 INF udp.server: "::ffff:192.168.2.100" : New Control connection created
2022-01-14 07:31:37.901 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Received 'are you there'
2022-01-14 07:31:37.904 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Received 'Are you ready'
2022-01-14 07:31:37.907 INF udp.server: "::ffff:192.168.2.100" : Received 'login'
2022-01-14 07:31:37.908 INF udp.server: "::ffff:192.168.2.100" : User  "hampi"  login OK
2022-01-14 07:31:37.908 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Login response:  1
2022-01-14 07:31:37.911 INF udp.server: "::ffff:192.168.2.100" : Received create token request
2022-01-14 07:31:37.911 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Capabilities : 2
2022-01-14 07:31:37.912 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Client will have TX audio
2022-01-14 07:31:37.912 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending ConnectionInfo : 3
2022-01-14 07:31:37.916 INF udp.server: "::ffff:192.168.2.100" : Received request for radio connection
2022-01-14 07:31:37.916 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Status
2022-01-14 07:31:37.916 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending ConnectionInfo : 5
2022-01-14 07:31:37.916 INF udp.server: "::ffff:192.168.2.100" : rxCodec: 1  txCodec: 1  rxSampleRate 16000  txSampleRate 16000  txBufferLen 101
2022-01-14 07:31:37.917 INF audio: Output setVolume:  255 ( 1 )
2022-01-14 07:31:37.917 INF audio: Output Internal: sample rate 48000 channel count 2
2022-01-14 07:31:37.917 INF audio: Input Internal: sample rate 48000 channel count 2
2022-01-14 07:31:37.917 INF audio: Output wf_resampler_init() returned:  0  resampleRatio:  3
2022-01-14 07:31:37.917 INF audio: Input wf_resampler_init() returned:  0  resampleRatio:  0.333333
2022-01-14 07:31:37.917 INF audio: Input thread id 0x94589380
2022-01-14 07:31:37.917 INF audio: Input start() running
2022-01-14 07:31:37.917 INF audio: Output thread id 0x94d8a380
2022-01-14 07:31:37.917 INF audio: Output start() running
2022-01-14 07:31:37.923 INF udp.server: "::ffff:192.168.2.100" ( "CIV" ): New connection created
2022-01-14 07:31:37.923 INF udp.server: "::ffff:192.168.2.100" ( "CIV" ): Received 'are you there'
2022-01-14 07:31:37.923 INF udp.server: "::ffff:192.168.2.100" ( "Audio" ): New connection created
2022-01-14 07:31:37.923 INF udp.server: "::ffff:192.168.2.100" ( "Audio" ): Received 'are you there'
2022-01-14 07:31:37.926 INF udp.server: "::ffff:192.168.2.100" ( "CIV" ): Received 'Are you ready'
2022-01-14 07:31:37.927 INF udp.server: "::ffff:192.168.2.100" ( "Audio" ): Received 'Are you ready'
2022-01-14 07:31:37.929 INF audio: Output Audio now in active state:  0  packets in buffer
2022-01-14 07:31:37.929 INF audio: Input Audio now in active state:  0  packets in buffer
2022-01-14 07:31:37.996 INF rig: Have rig ID: decimal:  148
2022-01-14 07:31:39.779 INF rig: Received 0x15 center span data: for frequency  10000
2022-01-14 07:32:37.447 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:32:37.447 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:33:37.447 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:33:37.447 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:34:37.448 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:34:37.449 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:35:37.447 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:35:37.447 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:36:37.448 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:36:37.448 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:37:37.447 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:37:37.447 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:38:37.445 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:38:37.446 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:39:37.443 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:39:37.444 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:40:24.756 INF udp.server: "::ffff:192.168.2.100" ( "CIV" ): Received 'retransmit' request for  43939
2022-01-14 07:40:24.756 INF udp.server: "::ffff:192.168.2.100" ( "CIV" ): Sending retransmit of  aba3
2022-01-14 07:40:37.443 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:40:37.443 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:41:37.442 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:41:37.442 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:42:37.443 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:42:37.443 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:43:37.441 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:43:37.441 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:44:37.442 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:44:37.442 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:45:37.441 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:45:37.441 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:46:37.441 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:46:37.442 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:47:00.593 INF default: setState 3
2022-01-14 07:47:14.114 INF default: setState 0
2022-01-14 07:47:30.114 INF default: setState 3
2022-01-14 07:47:37.439 INF udp.server: "::ffff:192.168.2.100" : Received token request
2022-01-14 07:47:37.439 INF udp.server: "::ffff:192.168.2.100" ( "Control" ): Sending Token response for type:  5
2022-01-14 07:47:44.713 INF default: setState 0
2022-01-14 07:48:00.988 INF default: setState 3
2022-01-14 07:51:00.288 INF default: setState 0
2022-01-14 08:05:18.347 INF udp.server: Closing udpServer
2022-01-14 08:05:18.347 INF udp.server: Deleting "Control" connection to:  "::ffff:192.168.2.100" : "63962"
2022-01-14 08:05:18.351 INF udp.server: Found "Control" connection to:  "::ffff:192.168.2.100" : "63962"
2022-01-14 08:05:18.351 INF udp.server: Current Number of clients connected:  0
2022-01-14 08:05:18.352 INF audio: Input Audio now in stopped state:  0  packets in buffer
2022-01-14 08:05:18.352 INF audio: Output Audio now in stopped state:  0  packets in buffer
2022-01-14 08:05:18.353 INF udp.server: Deleting "CIV" connection to:  "::ffff:192.168.2.100" : "58576"
2022-01-14 08:05:18.392 INF udp.server: Found "CIV" connection to:  "::ffff:192.168.2.100" : "58576"
2022-01-14 08:05:18.395 INF udp.server: Current Number of clients connected:  0
2022-01-14 08:05:18.399 INF udp.server: Deleting "Audio" connection to:  "::ffff:192.168.2.100" : "52947"
2022-01-14 08:05:18.448 INF udp.server: Found "Audio" connection to:  "::ffff:192.168.2.100" : "52947"
2022-01-14 08:05:18.453 INF udp.server: Current Number of clients connected:  0

Hope this helps Phil. :grinning:

/Ron - 73 de PA7CT

11

Hi Ron.

Let us know how you get on with the settings branch. So far we are pretty happy with it and things seem to work much better.

73 Phil M0VSE

12

Sorry for breaking in here but would really like to learn your settings for getting Rumlog working with review, I have had no success!

73 Alan

13

I am not using Rumlog currently. I will use it when I get everything running remote on my Mac ie Steppir, linear amp, Icom 7601, rotator - way to go yet

73 Peter ZL2LD

(Attachment PastedGraphic-1.tiff is missing)

14

No problem Peter…good luck with the setup. It’s a journey!

I’ve got some ideas on how to get Rumlog going so maybe will have a solution ready when you get to that point.

73 Alan VK2ATW

15

I am a bit late reporting this, but recently while downloading and building from the settings branch (with the ‘ignore single missing audio packet’ commit from Phil), I noticed that one of the prereq’s couldn’t be found on Raspbian (Debian Buster): “E: Unable to locate package libqcustomplot1.3”. Hadn’t noticed it before but that’s probably because I am now in “testing/debugging mode” and take a closer look at what is happening… :grin:
This version of the library seems to be only available in Stretch (old stable), while version 2.0 is in the Buster and later repo’s. Had to pin this to the specific repo to get it installed.
@phil I’ve created an issue on Gitlab.

16

Hi Ron.

This isn’t actually a bug and it is operating ‘as designed’. The fullbuild script looks for either qcustomplot 1.3 or 2.0 and tries to install them both. One will ALWAYS fail and is silently ignored.

73 Phil

17

Ah, I missed that part! :innocent: