Sat-IP client returns error due to string argument that cannot be parsed as float

Question

Sat-IP client returns error due to string argument that cannot be parsed as float

katokishin opened this issue 3 years ago · 12 comments

When leaving blocksat-cli sat-ip running, the following error seems to occur occasionally (several days usually).

2021-07-20 05:28:11 WARNING  Failed to fetch the frontend status.ty = 86.7%;
2021-07-20 10:07:03 WARNING  Failed to fetch the frontend status.ty = 86.7%;
2021-07-20 17:30:02 WARNING  Failed to fetch the frontend status.ty = 100.0%;
2021-07-20 19:42:44 WARNING  Failed to fetch the frontend status.ty = 100.0%;
2021-07-22 01:05:56 WARNING  Failed to fetch the frontend status.ty = 73.3%;
2021-07-22 10:36:25 WARNING  Failed to fetch the frontend status.ty = 86.7%;
2021-07-22 12:12:56 WARNING  Failed to fetch the frontend status.ty = 86.7%;
2021-07-22 14:00:15 WARNING  Failed to fetch the frontend status.ty = 86.7%;
2021-07-22 18:55:42 WARNING  Failed to fetch the frontend status.ty = 80.0%;
2021-07-23 03:44:30 WARNING  Failed to fetch the frontend status.ty = 73.3%;
2021-07-23 06:53:48 WARNING  Failed to fetch the frontend status.ty = 86.7%;
2021-07-23 15:12:07 WARNING  Failed to fetch the frontend status.ty = 100.0%;
2021-07-23 23:41:58 WARNING  Failed to fetch the frontend status.ty = 46.7%;
2021-07-24 01:25:43 WARNING  Failed to fetch the frontend status.ty = 100.0%;
Exception in thread Thread-2:rue; Level = -42.92dBm; Signal Quality = 80.0%;
Traceback (most recent call last):
  File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.8/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/usr/local/lib/python3.8/dist-packages/blocksatcli/satip.py", line 186, in _monitoring_thread
    status = sat_ip.fe_stats()
  File "/usr/local/lib/python3.8/dist-packages/blocksatcli/satip.py", line 146, in fe_stats
    return self._parse_fe_info(fe['frontend'])
  File "/usr/local/lib/python3.8/dist-packages/blocksatcli/satip.py", line 47, in _parse_fe_info
    signal_level = ((10 * float(fe_info['sq'])) - 3440) / 48
ValueError: could not convert string to float: 'NA'

The repetitive lines at the top seem to indicate times when the client had the same or similar issue with interpreting data on the sat-ip receiver. However, except for the last time, the client managed to return to normal and keep listening.

Perhaps a sanity check should be added in satip.py _parse_fe_info() to prevent the receiver reporting signal quality as 'NA' from crashing the client

Answer 1 · 2021-07-27T16:52:04.000Z

Hi @katokishin ,

Thanks for reporting the error. We have pushed a fix in 39b3066. This commit is on branch sat_ip_fw, which will be merged within the next CLI release.

If you want to try this version, you can clone the repository from Github and enter the cloned directory:

git clone https://github.com/Blockstream/satellite.git
cd satellite/

Then, switch into branch sat_ip_fw:

git checkout sat_ip_fw

If you've done this before, make sure to work on the latest state of the sat_ip_fw branch. As a quick verification, check if the command git rev-parse --short HEAD returns 39b3066. If not, you can reset the branch to its latest state by executing command git reset --hard origin/sat_ip_fw.

Lastly, run the blocksat-cli.py script directly from the top-level project directory instead of the blocksat-cli application installed globally on your system. For example, run the following command:

./blocksat-cli.py sat-ip

Alternatively, build and install this branch version globally on your system with:

make
sudo make install

Let us know if the patch fixes your problem and feel free to send any further questions.

Thanks again

Answer 2 · 2021-07-31T15:34:44.000Z

Thank you for the update! I've been running the sat_ip_fw branch for 4 days now, and the error originally raised in this issue has yet to reappear. Great job 🎉

The only time in the last 4 days that the client was closed was due to a "connection reset by peer" error, reproduced below. I suppose this technically belongs in a different issue though, so I will close this one.

2021-07-29 20:38:07 WARNING  Failed to fetch the frontend status.ty = 46.7%;
* Error: http: download error, Failure when receiving data from the peer, Recv failure: Connection reset by peer

The control panel of the receiver shows an uptime of 62+ days (which should be true), so I doubt the whole unit is restarting, but possibly the http server may restart every now and then. I couldn't find detailed documentation on this, however.

Answer 3 · 2021-08-03T18:26:10.000Z

Hi @katokishin ,

Thanks for confirming the version on branch sat_ip_fw works. We have pushed a workaround for the new error you mentioned (http: download error). The new patch was pushed to the same Git branch, so just run git pull origin sat_ip_fw to pull it.

The changes include the option --ignore-http-errors, which should retry the connection if an HTTP error occurs. With that, you can run the Sat-IP client as follows:

./blocksat-cli.py sat-ip --ignore-http-errors

Let us know if that helps.

Thanks again!

Answer 4 · 2021-08-03T19:20:33.000Z

Thank you again!
It seems that commit bc182f2 introduced the following error:

2021-08-03 11:51:19 WARNING  Failed to fetch the frontend status.

Upon further investigation, it seems to be caused by self.local_addr returning 127.0.1.1 rather than my IP on the local network (environment: Ubuntu).

The version committed in fdd53f1 is working as reported previously.

As such, I have temporarily resorted to running the latest commit with a hard-coded self.local_addr using the ignore-http-errors flag, and it seems to be working fine.

Answer 5 · 2021-08-05T20:25:51.000Z

You are right. bc182f2 had a problem on self.local_addr where it could return 127.0.0.1 in some platforms. We have pushed another fix in c6933dc, now calling ip route to discover the local address that communicates with the Sat-IP server. If you can try this version, please let us know how it goes.

Thanks for testing this thoroughly.

Answer 6 · 2021-08-07T18:32:45.000Z

Thank you for the fix, the issue with self.local_addr appears to be completely gone!
However, I've noticed one major and one minor issue while running commit c6933dc.

The major issue is a reemergence of the following error (which was the initial reason for this thread):

Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.8/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/kishin/Desktop/satellite/blocksatcli/satip.py", line 516, in _monitoring_thread
    status = sat_ip.fe_stats()
  File "/home/kishin/Desktop/satellite/blocksatcli/satip.py", line 459, in fe_stats
    if float(fe['fq']) != self.params['freq'] or \
ValueError: could not convert string to float: 'NA'

The minor issue is that if the client happens to be run in a VM, the following message is printed before the client begins functioning. It does not appear if the software is run normally (not in a VM).
However the client itself seems to function normally (albeit with the above issue), despite the error message.

2021-08-07 09:22:44 WARNING  Failed to parse the local Sat-IP client address
2021-08-07 09:22:44 WARNING  'ens33' does not appear to be an IPv4 or IPv6 address

Answer 7 · 2021-08-09T15:10:58.000Z

Thanks again for your helpful feedback, @katokishin

The major issue you mentioned was slightly unexpected. It's an error when parsing the frequency to which the IP22 frontend is tuned. Since this is a fixed parameter, the returned value should not change to NA for an active frontend. So it would be interesting to see what exactly is returned by the IP22 when this happens, which can be seen by running in debug mode with option -d, like so:

./blocksat-cli.py -d sat-ip

In any case, we have pushed a fix that should cover this error. We also pushed another patch for the minor issue you reported, which is definitely something to be fixed. The latest version is now 9f308a2. Hopefully, it's starting to converge to a more stable version! :)

Again, your feedback is greatly appreciated.

Answer 8 · 2021-08-10T01:18:43.000Z

I've run c6933dc in debug mode to figure out what is being returned when fe['fq'] = "NA"

Typical log when everything is fine:

2021-08-09 14:32:20 DEBUG    urllib3.connectionpool http://192.168.11.16:8000 "GET /cgi-bin/index.cgi?cmd=frontend_info HTTP/1.1" 200 None
2021-08-09 14:32:20 DEBUG    blocksatcli.satip Active frontends: [{'name': 'frontend 1', 'tt': 'Satellite', 'tm': 'HTTP', 'ip': '192.168.11.5', 'playing': 'yes', 'ls': 'yes', 'ber': '14', 'sq': '139', 'fq': '11506.75', 'sr': '1000', 'pol': 'h', 'rs': 'dvbs2', 'mod': 'QPSK', 'pids': '32'}]
2021-08-09 14:32:20  Lock = True; Level = -42.71dBm; Signal Quality = 93.3%;
2021-08-09 14:32:21 DEBUG    urllib3.connectionpool Resetting dropped connection: 192.168.11.16

Log when fe['fq] = 'NA':

2021-08-09 14:32:24 DEBUG    urllib3.connectionpool http://192.168.11.16:8000 "GET /cgi-bin/index.cgi?cmd=frontend_info HTTP/1.1" 200 None
2021-08-09 14:32:24 DEBUG    blocksatcli.satip Active frontends: [{'name': 'frontend 1', 'tt': 'Satellite', 'tm': 'HTTP', 'ip': '192.168.11.5', 'playing': 'yes', 'ls': 'yes', 'ber': '14', 'sq': '140', 'fq': '11506.75', 'sr': '1000', 'pol': 'h', 'rs': 'dvbs2', 'mod': 'QPSK', 'pids': '32'}, {'name': 'frontend 8', 'tt': 'NA', 'tm': 'NA', 'ip': 'NA', 'playing': 'NA', 'ls': 'NA', 'ber': 'NA', 'sq': 'NA', 'fq': 'NA', 'sr': 'NA', 'pol': 'NA', 'rs': 'NA', 'mod': 'NA', 'pids': 'NA'}]
Exception in thread Thread-2:
Traceback (most recent call last):
  File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.8/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/kishin/Desktop/satellite/blocksatcli/satip.py", line 516, in _monitoring_thread
    status = sat_ip.fe_stats()
  File "/home/kishin/Desktop/satellite/blocksatcli/satip.py", line 459, in fe_stats
    if float(fe['fq']) != self.params['freq'] or \
ValueError: could not convert string to float: 'NA'

I hope the above information helps. For some reason, the client finds another active frontend.

Commit 9f308a2 works perfectly so far on a machine on my local network! However, when run from inside a VM, I encounter the following error caused by self.local_addr not matching fe['ip'].

Here is the log from running 9f308a2 inside a VM, which fails on start, where the local IP of the receiver is 192.168.11.16 and the client is 192.168.11.5:

2021-08-09 17:56:06 DEBUG    root [Debug Mode]
2021-08-09 17:56:06 DEBUG    blocksatcli.update Last update check was less than a day ago: 9:11:33.388319
2021-08-09 17:56:06 DEBUG    urllib3.connectionpool Starting new HTTP connection (1): 192.168.11.16:8000
2021-08-09 17:56:06 DEBUG    urllib3.connectionpool http://192.168.11.16:8000 "GET / HTTP/1.1" 200 481
2021-08-09 17:56:06 DEBUG    blocksatcli.satip Local Sat-IP client address: 192.168.247.130
2021-08-09 17:56:06 DEBUG    urllib3.connectionpool Starting new HTTP connection (1): 192.168.11.16:8000
2021-08-09 17:56:06 DEBUG    urllib3.connectionpool http://192.168.11.16:8000 "GET /gmi_sw_ver.txt HTTP/1.1" 200 7
2021-08-09 17:56:06 DEBUG    urllib3.connectionpool Starting new HTTP connection (1): 192.168.11.16:8000
2021-08-09 17:56:06 DEBUG    urllib3.connectionpool http://192.168.11.16:8000 "POST /cgi-bin/login.cgi HTTP/1.1" 200 None
2021-08-09 17:56:06 DEBUG    blocksatcli.satip Run:
2021-08-09 17:56:06 DEBUG    blocksatcli.satip tsp --realtime --buffer-size-mb 1.0 --max-flushed-packets 10 --max-input-packets 10 -I http http://192.168.11.16/?src=1&freq=11506.75&pol=h&ro=0.2&msys=dvbs2&mtype=qpsk&plts=on&sr=1000&fec=35&pids=32 --infinite --ignore-errors -P mpe --pid 32 --udp-forward --local-address 127.0.0.1 -O drop
2021-08-09 17:56:07 DEBUG    urllib3.connectionpool Resetting dropped connection: 192.168.11.16
2021-08-09 17:56:07 DEBUG    urllib3.connectionpool http://192.168.11.16:8000 "GET /cgi-bin/index.cgi?cmd=frontend_info HTTP/1.1" 200 None
2021-08-09 17:56:07 DEBUG    blocksatcli.satip Active frontends: [{'name': 'frontend 1', 'tt': 'Satellite', 'tm': 'HTTP', 'ip': '192.168.11.5', 'playing': 'no', 'ls': 'no', 'ber': '0', 'sq': '0', 'fq': '11506.75', 'sr': '1000', 'pol': 'h', 'rs': 'dvbs2', 'mod': 'QPSK', 'pids': '32'}]
Exception in thread Thread-1:
Traceback (most recent call last):
  File "/usr/lib/python3.8/threading.py", line 932, in _bootstrap_inner
    self.run()
  File "/usr/lib/python3.8/threading.py", line 870, in run
    self._target(*self._args, **self._kwargs)
  File "/home/kishin/Desktop/satellite/blocksatcli/satip.py", line 530, in _monitoring_thread
    status = sat_ip.fe_stats()
  File "/home/kishin/Desktop/satellite/blocksatcli/satip.py", line 487, in fe_stats
    return self._parse_fe_info(candidate_frontends[0])
IndexError: list index out of range

Sorry about my particular environment involving VMs being difficult to work around! I deeply appreciate the work you've put in so far to help me out.

Answer 9 · 2021-08-10T22:05:51.000Z

Thanks a lot, @katokishin . Your feedback makes total sense. The first issue (of fe['fq'] = 'NA') is that the code was expecting fe['fq'] to be always a float number or none. However, the Sat-IP server can apparently return NA for this and other fields, with the same meaning as none. That's hopefully fixed in c27e48b.

Regarding the VM issue, it seems that your VM is running behind a NAT, which is usual for VMs. The local IP address inside the VM is 192.168.247.130, but in reality, the IP22 server sees the host's address (192.168.11.5). In this scenario, the previous scheme to filter logs based on the client address wouldn't work. The local address (192.168.247.130) would never match the 'ip' field seen on the active frontend list (192.168.11.5).

We have refactored the client filtering in a924f03 to accommodate this typical scenario of a VM behind a NAT. We would appreciate it if you could try it out. Also, one experiment of interest is running two clients concurrently, one from the normal host and the other from the guest VM.

With the new version in a924f03, if you run a single Sat-IP client from the VM, it should work with no apparent difference (hopefully). However, if you launch a client from the host first and then launch a client from the VM, the VM client should print a warning like Could not find a frontend serving the local 192.168.247.130 address. Nevertheless, the program should still work after this warning.

Thanks

Answer 10 · 2021-08-16T06:45:08.000Z

Thank you so much. Running a924f03 & everything seems to be working fine as described, nice and stable.

By the way I am using this software to run blocksat-reader, a website that shows the latest files I've been able to download via Satellite. (It kind of functions as a rudimentary online forum as is.) Thanks for the cool product & I hope to come up with interesting new ways to use it!

Answer 11 · 2021-08-19T11:59:36.000Z

@katokishin Thanks for confirming a924f03 works. Excellent!

The blocksat-reader app is interesting! Thanks for sharing :)

Answer 12 · 2021-09-10T20:43:52.000Z

Hi @katokishin ,

FYI, the fixes for the Sat-IP client have been released today on version 0.4.0, so you don't need to use the temporary branch version anymore.

To upgrade, run:

sudo pip3 install blocksat-cli --upgrade

Or refer to the instructions.

Thanks again.