Failed observations - cb transfer status: 1, canceling

mat · February 14, 2021, 8:49pm

After successfully upgrading to 1.4 and having working observations, my station has gone u/s a few days later. I’ve tried the obvious turn it off and back on again to no avail.

Seems I’m getting some connection failures but this is kinda normal and it usually works better next time it tries:

pi@pinog:~ $ journalctl -u satnogs-client.service
-- Logs begin at Sun 2021-02-14 14:17:01 UTC, end at Sun 2021-02-14 20:37:57 UTC. --
Feb 14 14:24:52 pinog systemd[1]: Started SatNOGS client.
Feb 14 14:24:57 pinog s-client[336]: satnogsclient - INFO - Starting status listener thread...
Feb 14 14:24:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Starting scheduler...
Feb 14 14:24:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Registering `get_jobs` periodic task (60 sec. interval)
Feb 14 14:24:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Registering `post_data` periodic task (180 sec. interval)
Feb 14 14:24:57 pinog satnogs-client[336]: satnogsclient - INFO - Press Ctrl+C to exit SatNOGS poller
Feb 14 14:25:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 14 14:26:00 pinog satnogs-client[336]: apscheduler.executors.default - ERROR - Job "get_jobs (trigger: interval[0:01:00], next run at: 2021-02-14 14:26:57 UTC)" raised an exception
Feb 14 14:26:00 pinog satnogs-client[336]: Traceback (most recent call last):
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connection.py", line 160, in _new_conn
Feb 14 14:26:00 pinog satnogs-client[336]:     (self._dns_host, self.port), self.timeout, **extra_kw
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/util/connection.py", line 84, in create_connection
Feb 14 14:26:00 pinog satnogs-client[336]:     raise err
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/util/connection.py", line 74, in create_connection
Feb 14 14:26:00 pinog satnogs-client[336]:     sock.connect(sa)
Feb 14 14:26:00 pinog satnogs-client[336]: OSError: [Errno 113] No route to host
Feb 14 14:26:00 pinog satnogs-client[336]: During handling of the above exception, another exception occurred:
Feb 14 14:26:00 pinog satnogs-client[336]: Traceback (most recent call last):
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connectionpool.py", line 677, in urlopen
Feb 14 14:26:00 pinog satnogs-client[336]:     chunked=chunked,
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connectionpool.py", line 381, in _make_request
Feb 14 14:26:00 pinog satnogs-client[336]:     self._validate_conn(conn)
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connectionpool.py", line 978, in _validate_conn
Feb 14 14:26:00 pinog satnogs-client[336]:     conn.connect()
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connection.py", line 309, in connect
Feb 14 14:26:00 pinog satnogs-client[336]:     conn = self._new_conn()
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connection.py", line 172, in _new_conn
Feb 14 14:26:00 pinog satnogs-client[336]:     self, "Failed to establish a new connection: %s" % e
Feb 14 14:26:00 pinog satnogs-client[336]: urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0xb22d13d0>: Failed to establish a new connection: [Errno 113] No route to host
Feb 14 14:26:00 pinog satnogs-client[336]: During handling of the above exception, another exception occurred:
Feb 14 14:26:00 pinog satnogs-client[336]: Traceback (most recent call last):
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
Feb 14 14:26:00 pinog satnogs-client[336]:     timeout=timeout
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connectionpool.py", line 727, in urlopen
Feb 14 14:26:00 pinog satnogs-client[336]:     method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/util/retry.py", line 446, in increment
Feb 14 14:26:00 pinog satnogs-client[336]:     raise MaxRetryError(_pool, url, error or ResponseError(cause))
Feb 14 14:26:00 pinog satnogs-client[336]: urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='network.satnogs.org', port=443): Max retries exceeded with url: /api/jobs/?ground_station=1450&lat=52.212&lon=-0.904&alt=112 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0xb22d13d0>: Failed to establish a new connection: [Errno 113] No route to host'))
Feb 14 14:26:00 pinog satnogs-client[336]: During handling of the above exception, another exception occurred:
Feb 14 14:26:00 pinog satnogs-client[336]: Traceback (most recent call last):
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/apscheduler/executors/base.py", line 125, in run_job
Feb 14 14:26:00 pinog satnogs-client[336]:     retval = job.func(*job.args, **job.kwargs)
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/satnogsclient/scheduler/tasks.py", line 171, in get_jobs
Feb 14 14:26:00 pinog satnogs-client[336]:     timeout=45)
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/api.py", line 76, in get
Feb 14 14:26:00 pinog satnogs-client[336]:     return request('get', url, params=params, **kwargs)
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/api.py", line 61, in request
Feb 14 14:26:00 pinog satnogs-client[336]:     return session.request(method=method, url=url, **kwargs)
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/sessions.py", line 530, in request
Feb 14 14:26:00 pinog satnogs-client[336]:     resp = self.send(prep, **send_kwargs)
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/sessions.py", line 643, in send
Feb 14 14:26:00 pinog satnogs-client[336]:     r = adapter.send(request, **kwargs)
Feb 14 14:26:00 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/adapters.py", line 516, in send
Feb 14 14:26:00 pinog satnogs-client[336]:     raise ConnectionError(e, request=request)
Feb 14 14:26:00 pinog satnogs-client[336]: requests.exceptions.ConnectionError: HTTPSConnectionPool(host='network.satnogs.org', port=443): Max retries exceeded with url: /api/jobs/?ground_station=1450&lat=52.212&lon=-0.904&alt=112 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0xb22d13d0>: Failed to establish a new connection: [Errno 113] No route to host'))
Feb 14 14:26:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 14 14:37:50 pinog satnogs-client[336]: apscheduler.executors.default - WARNING - Run time of job "get_jobs (trigger: interval[0:01:00], next run at: 2021-02-14 14:27:57 UTC)" was missed by 0:00:53.581664
Feb 14 14:37:50 pinog satnogs-client[336]: apscheduler.executors.default - WARNING - Run time of job "post_data (trigger: interval[0:03:00], next run at: 2021-02-14 14:27:57 UTC)" was missed by 0:00:53.583109
Feb 14 14:37:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 14 14:38:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 14 14:39:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 14 14:39:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started

But then when it actually does an Observation 3636767, it doesn’t seem to make it to the database:

Feb 14 15:42:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 14 15:42:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started
Feb 14 15:43:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 14 15:44:00 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Spawning observer worker.
Feb 14 15:44:00 pinog satnogs-client[336]: satnogsclient.observer.observer - INFO - Executing pre-observation script.
Feb 14 15:44:00 pinog satnogs-client[336]: Pre-observation script started
Feb 14 15:44:00 pinog satnogs-client[336]: Stopping auto_rx.service
Feb 14 15:44:00 pinog sudo[1354]:  satnogs : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/systemctl stop auto_rx.service
Feb 14 15:44:00 pinog sudo[1354]: pam_unix(sudo:session): session opened for user root by (uid=0)
Feb 14 15:44:00 pinog sudo[1354]: pam_unix(sudo:session): session closed for user root
Feb 14 15:44:00 pinog satnogs-client[336]: Found 1 device(s):
Feb 14 15:44:00 pinog satnogs-client[336]:   0:  Realtek, RTL2838UHIDIR, SN: 00000001
Feb 14 15:44:00 pinog satnogs-client[336]: Using device 0: Generic RTL2832U OEM
Feb 14 15:44:00 pinog satnogs-client[336]: Found Rafael Micro R820T tuner
Feb 14 15:44:01 pinog satnogs-client[336]: rtl_biast
Feb 14 15:44:01 pinog satnogs-client[336]: Pre-observation script complete
Feb 14 15:44:01 pinog satnogs-client[336]: satnogsclient.observer.observer - INFO - Start rotctrl thread.
Feb 14 15:44:01 pinog satnogs-client[336]: satnogsclient.observer.worker - INFO - Tracking initiated
Feb 14 15:44:01 pinog satnogs-client[336]: rot_init called
Feb 14 15:44:01 pinog satnogs-client[336]: dummy: _init called
Feb 14 15:44:01 pinog satnogs-client[336]: rot_register (1)
Feb 14 15:44:01 pinog satnogs-client[336]: rot_register (2)
Feb 14 15:44:01 pinog satnogs-client[336]: dummy_rot_init called
Feb 14 15:44:01 pinog satnogs-client[336]: rot_open called
Feb 14 15:44:01 pinog satnogs-client[336]: dummy_rot_open called
Feb 14 15:44:01 pinog satnogs-client[336]: rot_get_position called
Feb 14 15:44:01 pinog satnogs-client[336]: dummy_rot_get_position called
Feb 14 15:44:01 pinog satnogs-client[336]: rot_set_position called
Feb 14 15:44:01 pinog satnogs-client[336]: dummy_rot_set_position called: 104.96 0.06
Feb 14 15:44:01 pinog satnogs-client[336]: satnogsclient.observer.observer - INFO - Start rigctrl thread.
Feb 14 15:44:01 pinog satnogs-client[336]: satnogsclient.observer.worker - INFO - Tracking initiated
Feb 14 15:44:02 pinog satnogs-client[336]: satnogsclient.observer.observer - INFO - Start gnuradio thread.
Feb 14 15:44:05 pinog satnogs-client[336]: Found Rafael Micro R820T tuner
Feb 14 15:44:06 pinog satnogs-client[336]: [INFO] Opening Generic RTL2832U OEM :: 00000001...
Feb 14 15:44:06 pinog satnogs-client[336]: Found Rafael Micro R820T tuner
Feb 14 15:44:06 pinog satnogs-client[336]: [R82XX] PLL not locked!
Feb 14 15:44:06 pinog satnogs-client[336]: [INFO] Using format CF32.
Feb 14 15:44:08 pinog satnogs-client[336]: Allocating 15 zero-copy buffers
Feb 14 15:44:15 pinog satnogs-client[336]: cb transfer status: 1, canceling...
Feb 14 15:44:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 14 15:45:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 14 15:45:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started

I’ve not touched it for a while so can’t remember what the logfile shows on a good observation (and rebooting’s dropped the old ones) but I presume cb transfer status: 1, canceling... isn’t a positive log entry.

Has anyone seen this before? A search shows Setup problem RTLSDR referencing this message, but resolves it by a reinstall which is a bit of a blunt instrument.

satcolintel5 · February 15, 2021, 8:37pm

Seems like a the DNS lookup is timing out on your end. Check /etc/resolv.conf and see if they are pointing to reliable DNS servers

mat · February 16, 2021, 11:51am

Ah yeah, it makes sense that the earlier DNS lookup that’s occasionally failed for a long time might be happening again later during the observation. Looks like it was set to my router and it’s not the most reliable. I’d added static domain_name_servers=1.1.1.1 8.8.8.8 to the end of /etc/dhcpcd.conf as is Raspbian’s wont.

Disappointingly, that doesn’t seem to have made much difference:

Feb 16 11:06:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started
Feb 16 11:07:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:08:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:08:57 pinog satnogs-client[336]: apscheduler.executors.default - ERROR - Job "get_jobs (trigger: interval[0:01:00], next run at: 2021-02-16 11:09:57 UTC)" raised an exception
Feb 16 11:08:57 pinog satnogs-client[336]: Traceback (most recent call last):
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connection.py", line 160, in _new_conn
Feb 16 11:08:57 pinog satnogs-client[336]:     (self._dns_host, self.port), self.timeout, **extra_kw
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/util/connection.py", line 61, in create_connection
Feb 16 11:08:57 pinog satnogs-client[336]:     for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/usr/lib/python3.7/socket.py", line 748, in getaddrinfo
Feb 16 11:08:57 pinog satnogs-client[336]:     for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
Feb 16 11:08:57 pinog satnogs-client[336]: socket.gaierror: [Errno -3] Temporary failure in name resolution
Feb 16 11:08:57 pinog satnogs-client[336]: During handling of the above exception, another exception occurred:
Feb 16 11:08:57 pinog satnogs-client[336]: Traceback (most recent call last):
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connectionpool.py", line 677, in urlopen
Feb 16 11:08:57 pinog satnogs-client[336]:     chunked=chunked,
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connectionpool.py", line 381, in _make_request
Feb 16 11:08:57 pinog satnogs-client[336]:     self._validate_conn(conn)
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connectionpool.py", line 978, in _validate_conn
Feb 16 11:08:57 pinog satnogs-client[336]:     conn.connect()
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connection.py", line 309, in connect
Feb 16 11:08:57 pinog satnogs-client[336]:     conn = self._new_conn()
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connection.py", line 172, in _new_conn
Feb 16 11:08:57 pinog satnogs-client[336]:     self, "Failed to establish a new connection: %s" % e
Feb 16 11:08:57 pinog satnogs-client[336]: urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPSConnection object at 0xb1a5c110>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution
Feb 16 11:08:57 pinog satnogs-client[336]: During handling of the above exception, another exception occurred:
Feb 16 11:08:57 pinog satnogs-client[336]: Traceback (most recent call last):
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
Feb 16 11:08:57 pinog satnogs-client[336]:     timeout=timeout
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/connectionpool.py", line 727, in urlopen
Feb 16 11:08:57 pinog satnogs-client[336]:     method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/urllib3/util/retry.py", line 446, in increment
Feb 16 11:08:57 pinog satnogs-client[336]:     raise MaxRetryError(_pool, url, error or ResponseError(cause))
Feb 16 11:08:57 pinog satnogs-client[336]: urllib3.exceptions.MaxRetryError: HTTPSConnectionPool(host='network.satnogs.org', port=443): Max retries exceeded with url: /api/jobs/?ground_station=1450&lat=52.212&lon=-0.904&alt=112 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0xb1a5c110>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution'))
Feb 16 11:08:57 pinog satnogs-client[336]: During handling of the above exception, another exception occurred:
Feb 16 11:08:57 pinog satnogs-client[336]: Traceback (most recent call last):
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/apscheduler/executors/base.py", line 125, in run_job
Feb 16 11:08:57 pinog satnogs-client[336]:     retval = job.func(*job.args, **job.kwargs)
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/satnogsclient/scheduler/tasks.py", line 171, in get_jobs
Feb 16 11:08:57 pinog satnogs-client[336]:     timeout=45)
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/api.py", line 76, in get
Feb 16 11:08:57 pinog satnogs-client[336]:     return request('get', url, params=params, **kwargs)
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/api.py", line 61, in request
Feb 16 11:08:57 pinog satnogs-client[336]:     return session.request(method=method, url=url, **kwargs)
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/sessions.py", line 530, in request
Feb 16 11:08:57 pinog satnogs-client[336]:     resp = self.send(prep, **send_kwargs)
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/sessions.py", line 643, in send
Feb 16 11:08:57 pinog satnogs-client[336]:     r = adapter.send(request, **kwargs)
Feb 16 11:08:57 pinog satnogs-client[336]:   File "/var/lib/satnogs/lib/python3.7/site-packages/requests/adapters.py", line 516, in send
Feb 16 11:08:57 pinog satnogs-client[336]:     raise ConnectionError(e, request=request)
Feb 16 11:08:57 pinog satnogs-client[336]: requests.exceptions.ConnectionError: HTTPSConnectionPool(host='network.satnogs.org', port=443): Max retries exceeded with url: /api/jobs/?ground_station=1450&lat=52.212&lon=-0.904&alt=112 (Caused by NewConnectionError('<urllib3.connection.HTTPSConnection object at 0xb1a5c110>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution'))
Feb 16 11:09:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:09:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started
Feb 16 11:09:57 pinog satnogs-client[336]: apscheduler.executors.default - ERROR - Job "get_jobs (trigger: interval[0:01:00], next run at: 2021-02-16 11:10:57 UTC)" raised an exception

... repeats a minute later ...

Feb 16 11:10:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:11:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:12:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:12:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started

But as I say, I’ve had that before, it recovers.

I’m now getting different error messages. So that’s kinda handy. Seems my real problem is something to do with Observer job lock acquiring timed out.

Feb 16 11:24:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started
Feb 16 11:25:34 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Spawning observer worker.
Feb 16 11:25:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:26:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:27:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:27:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started
Feb 16 11:28:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:29:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:30:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:30:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started
Feb 16 11:31:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:32:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:33:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:33:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started
Feb 16 11:34:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:35:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:36:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:36:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Post data started
Feb 16 11:37:57 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - INFO - Trying to GET observation jobs from the network
Feb 16 11:38:01 pinog satnogs-client[336]: satnogsclient.scheduler.tasks - ERROR - Observer job lock acquiring timed out.

That gives me a better search term, and gives a few references to the problem on here, but moreso there’s a live GitLab issue #415 Client stops working with Observer job lock acquiring timed out.

.

mat · February 16, 2021, 3:39pm

For the benefit of anyone else having the same problem, I found I needed to do a hard power-off and re-power-up reset rather than just a sudo restart reboot.

All is now working again but questionable for how long.

Acinonyx · February 17, 2021, 2:35pm

Since I’ve recently looked into that part of librtlsdr code extensively, I would say that this messages shows up when there are consecutive USB transfer errors. It could be an indication that the device is completely lost (disconnected) but the userspace is not informed yet.

michal.drzal · August 7, 2021, 8:58pm

I have exact same issue and also tried adding other dns servers but still only cure seems to be rebooting RPI. Right now I do it every day, but still sometimes it hits at wrong time so I loose some observations - I’ll probably add curl checking google or something and rebootin as soon as I get couple of name resolution errors but this is definetely weird.

Have you found any solution for this or a good workaround?