Observation 7095583: Thybolt-1 (54363)

Regarding Observation 7095583
After an upgrade of everything (OS,satnogs client) on my RPi client all observations show black/failed. Where should I start looking. Lots of complaints from journalctl about unsupported sample rate which I set to 2.4e6 with rtlsdr.
tony kd1ik

Please share your config and log information, now it is a needle in a haystack.

  • sudo satnogs-setup -> Advanced -> Support
  • sudo journalctl -f -u satnogs-client -n 512

And set your rtlsdr sample rate to 2.048e6 as a start, if you are using a rtlsdr.

1 Like

These should be checked…

samp-rate-rx: "2.4e6",
bw: "10000",
doppler-correction-per-sec: "0",

I corrected the sample rate.

Here’s the postmortem:

=======================
tony@satnogs190:~ $ sudo systemctl status satnogs-client
sudo: unable to resolve host satnogs190: Name or service not known
● satnogs-client.service - SatNOGS client
Loaded: loaded (/etc/systemd/system/satnogs-client.service; enabled; vendor preset: enabled)
Active: active (running) since Sun 2023-01-29 18:55:53 GMT; 1min 11s ago
Main PID: 324 (satnogs-client)
Tasks: 3 (limit: 1596)
CPU: 7.588s
CGroup: /system.slice/satnogs-client.service
└─324 /var/lib/satnogs/bin/python /var/lib/satnogs/bin/satnogs-client

Jan 29 18:55:53 satnogs190 systemd[1]: Started SatNOGS client.

Jan 29 17:50:28 satnogs190 systemd[1]: Started SatNOGS client.
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: rot_init called
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: initrots4_dummy: _init called
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: rot_register (1)
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: rot_register (2)
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: dummy_rot_init called
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: rot_open called
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: dummy_rot_open called
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: rot_get_position called
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: dummy_rot_get_position called
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: rot_get_position: got az=0.00, el=0.00
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: rot_set_position called az=147.68 el=29.78
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: rot_set_position: south_zero=0
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: dummy_rot_set_position called: 147.68 29.78
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: rig_init: rig does not have rx_range!!
Jan 29 17:54:21 satnogs190 satnogs-client[1087]: network_open: hoststr=127.0.0.1, portstr=4532
Jan 29 17:54:23 satnogs190 satnogs-client[1113]: [INFO] [UHD] linux; GNU C++ version 10.2.1 20210110; Boost_107400; UHD_3.15.0.0-4+b1satnogs1
Jan 29 17:54:24 satnogs190 satnogs-client[1113]: Found Rafael Micro R820T tuner
Jan 29 17:54:24 satnogs190 satnogs-client[1113]: [INFO] Using format CF32.
Jan 29 17:54:35 satnogs190 satnogs-client[1113]: gr::log :WARN: soapy::source0 - Gain out of range: 0 <= gain <= 0
Jan 29 17:54:35 satnogs190 satnogs-client[1113]: Traceback (most recent call last):
Jan 29 17:54:35 satnogs190 satnogs-client[1113]: File “/usr/bin/satnogs_fm.py”, line 466, in
Jan 29 17:54:35 satnogs190 satnogs-client[1113]: main()
Jan 29 17:54:35 satnogs190 satnogs-client[1113]: File “/usr/bin/satnogs_fm.py”, line 449, in main
Jan 29 17:54:35 satnogs190 satnogs-client[1113]: tb = top_block_cls(antenna=options.antenna, bb_freq=options.bb_freq, bw=options.bw, dc_removal=options.dc_removal, decoded_data_file_path=options.decoded_data_file_path, dev_args=options.dev_args, deviation=options.deviation, doppler_correction_per_sec=options.doppler_correction_per_sec, enable_iq_dump=options.enable_iq_dump, file_path=options.file_path, gain=options.gain, gain_mode=options.gain_mode, iq_file_path=options.iq_file_path, lo_offset=options.lo_offset, max_modulation_freq=options.max_modulation_freq, other_settings=options.other_settings, ppm=options.ppm, rigctl_port=options.rigctl_port, rx_freq=options.rx_freq, samp_rate_rx=options.samp_rate_rx, soapy_rx_device=options.soapy_rx_device, stream_args=options.stream_args, tune_args=options.tune_args, udp_IP=options.udp_IP, udp_dump_host=options.udp_dump_host, udp_dump_port=options.udp_dump_port, udp_port=options.udp_port, waterfall_file_path=options.waterfall_file_path)
Jan 29 17:54:35 satnogs190 satnogs-client[1113]: File “/usr/bin/satnogs_fm.py”, line 126, in init
Jan 29 17:54:35 satnogs190 satnogs-client[1113]: self.satnogs_tcp_rigctl_msg_source_0 = satnogs.tcp_rigctl_msg_source(“127.0.0.1”, rigctl_port, False, int(1000.0/doppler_correction_per_sec) + 1, 1500)
Jan 29 17:54:35 satnogs190 satnogs-client[1113]: ZeroDivisionError: float division by zero
Jan 29 17:54:36 satnogs190 satnogs-client[1087]: netrigctl_close: done status=Command completed successfully
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: apscheduler.executors.default - ERROR - Job “spawn_observer (trigger: date[2023-01-29 17:54:21 UTC], next run at: 2023-01-29 17:54:21 UTC)” raised an exception
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: Traceback (most recent call last):
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: File “/var/lib/satnogs/lib/python3.9/site-packages/apscheduler/executors/base.py”, line 125, in run_job
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: retval = job.func(*job.args, **job.kwargs)
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: File “/var/lib/satnogs/lib/python3.9/site-packages/satnogsclient/scheduler/tasks.py”, line 64, in spawn_observer
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: observer.observe()
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: File “/var/lib/satnogs/lib/python3.9/site-packages/satnogsclient/observer/observer.py”, line 266, in observe
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: waterfall = Waterfall(self.observation_waterfall_file)
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: File “/var/lib/satnogs/lib/python3.9/site-packages/satnogsclient/waterfall.py”, line 99, in init
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: self.data = _get_waterfall(datafile_path)
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: File “/var/lib/satnogs/lib/python3.9/site-packages/satnogsclient/waterfall.py”, line 76, in _get_waterfall
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: waterfall = _read_waterfall(datafile_path)
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: File “/var/lib/satnogs/lib/python3.9/site-packages/satnogsclient/waterfall.py”, line 34, in _read_waterfall
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: ‘timestamp’: np.fromfile(datafile, dtype=‘|S32’, count=1)[0],
Jan 29 17:54:39 satnogs190 satnogs-client[1087]: IndexError: index 0 is out of bounds for axis 0 with size 0
Jan 29 18:01:55 satnogs190 satnogs-client[1087]: satnogsclient.scheduler.tasks - ERROR - Observer job lock acquiring timed out.
Jan 29 18:54:17 satnogs190 systemd[1]: Stopping SatNOGS client…
Jan 29 18:54:17 satnogs190 systemd[1]: satnogs-client.service: Succeeded.
Jan 29 18:54:17 satnogs190 systemd[1]: Stopped SatNOGS client.
Jan 29 18:54:17 satnogs190 systemd[1]: satnogs-client.service: Consumed 30.054s CPU time.
Jan 29 18:54:17 satnogs190 systemd[1]: Started SatNOGS client.
Jan 29 18:55:48 satnogs190 systemd[1]: Stopping SatNOGS client…
Jan 29 18:55:48 satnogs190 systemd[1]: satnogs-client.service: Succeeded.

===============================
Generating support report. Please wait…
------------[ copy here ]------------
{
“versions”: {
“satnogs-client”: “1.8.1”,
“satnogs-client-ansible”: “202209101521”,
“satnogs-flowgraphs”: “1.4-1”,
“gr-satnogs”: “2.3.3.0-1”,
“gr-soapy”: “2.1.3.1-1”,
“gnuradio”: “3.8.2.0-14”,
“satnogs-config”: “0.13.2”
},
“state”: {
“is-applied”: true,
“pending-tags”: null
},
“system”: {
“date”: “2023-01-29T19:03:49.187793+00:00”,
“distribution”: {
“DESCRIPTION”: “Raspbian GNU/Linux 11 (bullseye)”,
“RELEASE”: “11”,
“CODENAME”: “bullseye”,
“ID”: “Raspbian”
},
“pending-updates”: false,
“platform”: {
“system”: “Linux”,
“node”: “satnogs190”,
“release”: “5.15.84-v7+”,
“version”: “#1613 SMP Thu Jan 5 11:59:48 GMT 2023”,
“machine”: “armv7l”
},
“memory”: {
“total”: 966930432,
“available”: 791932928,
“percent”: 18.1,
“used”: 120836096,
“free”: 615452672,
“active”: 118648832,
“inactive”: 168665088,
“buffers”: 19419136,
“cached”: 211222528,
“shared”: 745472,
“slab”: 29937664
},
“disk”: {
“total”: 7478652928,
“used”: 4519792640,
“free”: 2600169472,
“percent”: 63.5
}
},
“configuration”: {
“satnogs_antenna”: “RX”,
“satnogs_api_token”: “[redacted]”,
“satnogs_artifacts_api_token”: “[redacted]”,
“satnogs_artifacts_enabled”: true,
“satnogs_doppler_corr_per_sec”: “0”,
“satnogs_rf_gain”: “38.5”,
“satnogs_rx_bandwidth”: “10000”,
“satnogs_rx_samp_rate”: “2.048e6”,
“satnogs_soapy_rx_device”: “device=rtlsdr”,
“satnogs_station_elev”: “70”,
“satnogs_station_id”: “385”,
“satnogs_station_lat”: “42.45”,
“satnogs_station_lon”: “-71.23”
}
}
------------[ copy end ]-------------

I don’t think it likes rate=2.048e6

Jan 29 19:23:48 satnogs190 satnogs-client[1088]: File “/usr/lib/python3/dist-packages/soapy/soapy_swig.py”, line 131, in make
Jan 29 19:23:48 satnogs190 satnogs-client[1088]: return _soapy_swig.source_make(nchan, device, dev_args, stream_args, tune_args, other_settings, sampling_rate, type)
Jan 29 19:23:48 satnogs190 satnogs-client[1088]: RuntimeError: soapy::source: Unsupported sample rate (2048000.000000). Rate must be in the range [8000.000000, 8000.000000] [16000.000000, 16000.000000] [22050.000000, 22050.000000] [32000.000000, 32000.000000] [44100.000000, 44100.000000] [48000.000000, 48000.000000] [96000.000000, 96000.000000]
Jan 29 19:23:49 satnogs190 satnogs-client[324]: netrigctl_close: done status=Command completed successfully
Jan 29 19:23:50 satnogs190 satnogs-client[324]: satnogsclient.observer.observer - ERROR - No waterfall data file found
Jan 29 19:23:52 satnogs190 satnogs-client[324]: apscheduler.executors.default - ERROR - Job “spawn_observer (trigger: date[2023-01-29 19:23:41 UTC], next run at: 2023-01-29 19:23:41 UTC)” raised an exception
Jan 2

this, as I hinted about earlier, is one roadblock. remove the setting for doppler-correction-per-sec.

did what you said. Making progress
no longer down in flames…now I get receptions but still status Unknown (orange) and still complaints:
tony@satnogs190:~ $ sudo journalctl -f -u satnogs-client.service
sudo: unable to resolve host satnogs190: Name or service not known
– Journal begins at Sat 2022-09-10 18:10:32 BST. –
Jan 29 22:25:06 satnogs190 satnogs-client[331]: Traceback (most recent call last):
Jan 29 22:25:06 satnogs190 satnogs-client[331]: File “/var/lib/satnogs/lib/python3.9/site-packages/apscheduler/executors/base.py”, line 125, in run_job
Jan 29 22:25:06 satnogs190 satnogs-client[331]: retval = job.func(*job.args, **job.kwargs)
Jan 29 22:25:06 satnogs190 satnogs-client[331]: File “/var/lib/satnogs/lib/python3.9/site-packages/satnogsclient/scheduler/tasks.py”, line 64, in spawn_observer
Jan 29 22:25:06 satnogs190 satnogs-client[331]: observer.observe()
Jan 29 22:25:06 satnogs190 satnogs-client[331]: File “/var/lib/satnogs/lib/python3.9/site-packages/satnogsclient/observer/observer.py”, line 320, in observe
Jan 29 22:25:06 satnogs190 satnogs-client[331]: artifact = Artifacts(waterfall, metadata)
Jan 29 22:25:06 satnogs190 satnogs-client[331]: File “/var/lib/satnogs/lib/python3.9/site-packages/satnogsclient/artifacts.py”, line 30, in init
Jan 29 22:25:06 satnogs190 satnogs-client[331]: self._waterfall_data = waterfall.data
Jan 29 22:25:06 satnogs190 satnogs-client[331]: AttributeError: ‘NoneType’ object has no attribute ‘data’
Jan 29 22:33:39 satnogs190 satnogs-client[331]: satnogsclient.scheduler.tasks - ERROR - Observer job lock acquiring timed out.

So, what is the “Observer job lock”? …and who sets it?
Tony

The error is further up, job lock means that the observer task is already (still) running and cannot be started again. This usually has a few reasons, some problem with the sdr or flowgraph not exiting.
You can check the running processes for this, I usually run ps ax|grep satnogs_ and that will show for example satnogs_fm.py running. Either restart the client or kill that process, then the next obs should be able to try (and perhaps show the reason for failing).
You should monitor the log with journalctl continuously when starting the client and when the obs starts, this is when you can catch the errors.