Photoframe authorization not found

[dgaz9]

Every two weeks or so the photoframe looses it's authorization json. When I look into the logs it just says not found. What causes this and anyway to resolve this?

[mrworf]

It shouldn't disappear like that for no reason. One thing that "might" be causing it is poor power supply that over time has started to corrupt your SD card. Other reasons would be revoking the OAuth from google's side but that is usually a manual process.

Feel free to attach a log to this ticket next time it happens using the "Log Report" feature and I'll have a look and see if I see something odd.

[mrworf]

I might have found an issue. Might be related to the loss of network

[dgaz9]

I started the photoframe again and waiting for it to lose the auth for the logs. Which logs should I review?

[mrworf]

Click this button from the web interface:

it will give you all the logs you could possibly need :) THen share here and I'll take a look 😄

[dgaz9]

Running version

commit af9881a
Author: Tom Anschutz
Date: Sun Jun 27 09:00:50 2021 -0400

Update base.py for issue #182, #186 (#183)

* Update base.py

Changed the way `sum` was computed in `getImagesTotal()` to avoid black screen with "no (new) images could be found" in the warning log.

* Update display.py

Fix Fill and Do Nothing image handling.

* Update base.py

Addresses #186

On branch master
Your branch is up to date with 'origin/master'.

nothing to commit, working tree clean
Last 100 lines from the photoframe log

Aug 28 06:00:54 photoframe photoframe[345]: 2021-08-28 06:00:54,913 - INFO - Starting presentation
Aug 28 14:55:27 photoframe photoframe[345]: 2021-08-28 14:55:26,993 - INFO - Internal display detected
(size of logfile 22807 bytes, created Sat Aug 28 14:55:57 2021)
Last 100 lines from the system log (/var/log/syslog)

Aug 28 09:24:45 photoframe rngd[257]: stats: FIPS 140-2 failures: 0
Aug 28 09:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Aug 28 09:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Poker: 0
Aug 28 09:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Runs: 0
Aug 28 09:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Long run: 0
Aug 28 09:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Aug 28 09:24:45 photoframe rngd[257]: stats: HRNG source speed: (min=119.268; avg=818.230; max=1083.384)Kibits/s
Aug 28 09:24:45 photoframe rngd[257]: stats: FIPS tests speed: (min=1.286; avg=6.066; max=8.900)Mibits/s
Aug 28 09:24:45 photoframe rngd[257]: stats: Lowest ready-buffers level: 2
Aug 28 09:24:45 photoframe rngd[257]: stats: Entropy starvations: 0
Aug 28 09:24:45 photoframe rngd[257]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Aug 28 10:17:01 photoframe CRON[5115]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Aug 28 10:24:45 photoframe rngd[257]: stats: bits received from HRNG source: 3920064
Aug 28 10:24:45 photoframe rngd[257]: stats: bits sent to kernel pool: 3870752
Aug 28 10:24:45 photoframe rngd[257]: stats: entropy added to kernel pool: 3870752
Aug 28 10:24:45 photoframe rngd[257]: stats: FIPS 140-2 successes: 196
Aug 28 10:24:45 photoframe rngd[257]: stats: FIPS 140-2 failures: 0
Aug 28 10:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Aug 28 10:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Poker: 0
Aug 28 10:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Runs: 0
Aug 28 10:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Long run: 0
Aug 28 10:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Aug 28 10:24:45 photoframe rngd[257]: stats: HRNG source speed: (min=119.268; avg=818.562; max=1083.384)Kibits/s
Aug 28 10:24:45 photoframe rngd[257]: stats: FIPS tests speed: (min=1.286; avg=6.067; max=8.900)Mibits/s
Aug 28 10:24:45 photoframe rngd[257]: stats: Lowest ready-buffers level: 2
Aug 28 10:24:45 photoframe rngd[257]: stats: Entropy starvations: 0
Aug 28 10:24:45 photoframe rngd[257]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Aug 28 11:17:01 photoframe CRON[5135]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Aug 28 11:24:45 photoframe rngd[257]: stats: bits received from HRNG source: 3960064
Aug 28 11:24:45 photoframe rngd[257]: stats: bits sent to kernel pool: 3900512
Aug 28 11:24:45 photoframe rngd[257]: stats: entropy added to kernel pool: 3900512
Aug 28 11:24:45 photoframe rngd[257]: stats: FIPS 140-2 successes: 198
Aug 28 11:24:45 photoframe rngd[257]: stats: FIPS 140-2 failures: 0
Aug 28 11:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Aug 28 11:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Poker: 0
Aug 28 11:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Runs: 0
Aug 28 11:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Long run: 0
Aug 28 11:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Aug 28 11:24:45 photoframe rngd[257]: stats: HRNG source speed: (min=119.268; avg=819.208; max=1083.384)Kibits/s
Aug 28 11:24:45 photoframe rngd[257]: stats: FIPS tests speed: (min=1.286; avg=6.069; max=8.900)Mibits/s
Aug 28 11:24:45 photoframe rngd[257]: stats: Lowest ready-buffers level: 2
Aug 28 11:24:45 photoframe rngd[257]: stats: Entropy starvations: 0
Aug 28 11:24:45 photoframe rngd[257]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Aug 28 12:17:01 photoframe CRON[5155]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Aug 28 12:24:45 photoframe rngd[257]: stats: bits received from HRNG source: 3980064
Aug 28 12:24:45 photoframe rngd[257]: stats: bits sent to kernel pool: 3930752
Aug 28 12:24:45 photoframe rngd[257]: stats: entropy added to kernel pool: 3930752
Aug 28 12:24:45 photoframe rngd[257]: stats: FIPS 140-2 successes: 199
Aug 28 12:24:45 photoframe rngd[257]: stats: FIPS 140-2 failures: 0
Aug 28 12:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Aug 28 12:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Poker: 0
Aug 28 12:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Runs: 0
Aug 28 12:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Long run: 0
Aug 28 12:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Aug 28 12:24:45 photoframe rngd[257]: stats: HRNG source speed: (min=119.268; avg=819.543; max=1083.384)Kibits/s
Aug 28 12:24:45 photoframe rngd[257]: stats: FIPS tests speed: (min=1.286; avg=6.067; max=8.900)Mibits/s
Aug 28 12:24:45 photoframe rngd[257]: stats: Lowest ready-buffers level: 2
Aug 28 12:24:45 photoframe rngd[257]: stats: Entropy starvations: 0
Aug 28 12:24:45 photoframe rngd[257]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Aug 28 13:17:01 photoframe CRON[5174]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Aug 28 13:24:45 photoframe rngd[257]: stats: bits received from HRNG source: 4020064
Aug 28 13:24:45 photoframe rngd[257]: stats: bits sent to kernel pool: 3960512
Aug 28 13:24:45 photoframe rngd[257]: stats: entropy added to kernel pool: 3960512
Aug 28 13:24:45 photoframe rngd[257]: stats: FIPS 140-2 successes: 201
Aug 28 13:24:45 photoframe rngd[257]: stats: FIPS 140-2 failures: 0
Aug 28 13:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Aug 28 13:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Poker: 0
Aug 28 13:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Runs: 0
Aug 28 13:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Long run: 0
Aug 28 13:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Aug 28 13:24:45 photoframe rngd[257]: stats: HRNG source speed: (min=119.268; avg=820.169; max=1083.384)Kibits/s
Aug 28 13:24:45 photoframe rngd[257]: stats: FIPS tests speed: (min=1.286; avg=6.069; max=8.900)Mibits/s
Aug 28 13:24:45 photoframe rngd[257]: stats: Lowest ready-buffers level: 2
Aug 28 13:24:45 photoframe rngd[257]: stats: Entropy starvations: 0
Aug 28 13:24:45 photoframe rngd[257]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Aug 28 13:56:06 photoframe systemd[1]: Starting Daily apt download activities...
Aug 28 13:56:11 photoframe systemd[1]: apt-daily.service: Succeeded.
Aug 28 13:56:11 photoframe systemd[1]: Started Daily apt download activities.
Aug 28 14:17:01 photoframe CRON[5244]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Aug 28 14:24:45 photoframe rngd[257]: stats: bits received from HRNG source: 4040064
Aug 28 14:24:45 photoframe rngd[257]: stats: bits sent to kernel pool: 3990752
Aug 28 14:24:45 photoframe rngd[257]: stats: entropy added to kernel pool: 3990752
Aug 28 14:24:45 photoframe rngd[257]: stats: FIPS 140-2 successes: 202
Aug 28 14:24:45 photoframe rngd[257]: stats: FIPS 140-2 failures: 0
Aug 28 14:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Aug 28 14:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Poker: 0
Aug 28 14:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Runs: 0
Aug 28 14:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Long run: 0
Aug 28 14:24:45 photoframe rngd[257]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Aug 28 14:24:45 photoframe rngd[257]: stats: HRNG source speed: (min=119.268; avg=820.481; max=1083.384)Kibits/s
Aug 28 14:24:45 photoframe rngd[257]: stats: FIPS tests speed: (min=1.286; avg=6.069; max=8.900)Mibits/s
Aug 28 14:24:45 photoframe rngd[257]: stats: Lowest ready-buffers level: 2
Aug 28 14:24:45 photoframe rngd[257]: stats: Entropy starvations: 0
Aug 28 14:24:45 photoframe rngd[257]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Aug 28 14:55:26 photoframe dbus-daemon[289]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.20' (uid=0 pid=5276 comm="/usr/bin/timedatectl list-timezones ")
Aug 28 14:55:26 photoframe systemd[1]: Starting Time & Date Service...
Aug 28 14:55:27 photoframe photoframe[345]: 2021-08-28 14:55:26,993 - INFO - Internal display detected
Aug 28 14:55:27 photoframe dbus-daemon[289]: [system] Successfully activated service 'org.freedesktop.timedate1'
Aug 28 14:55:27 photoframe systemd[1]: Started Time & Date Service.
Aug 28 14:55:57 photoframe systemd[1]: systemd-timedated.service: Succeeded.
(size of logfile 22807 bytes, created Sat Aug 28 14:55:57 2021)
Stacktrace of all running threads

ThreadID: -1291860896

File: "/usr/lib/python2.7/threading.py", line 774, in __bootstrap
self.__bootstrap_inner()
File: "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File: "/usr/lib/python2.7/threading.py", line 754, in run
self.__target(*self.__args, **self.__kwargs)
File: "/usr/lib/python2.7/SocketServer.py", line 599, in process_request_thread
self.finish_request(request, client_address)
File: "/usr/lib/python2.7/SocketServer.py", line 334, in finish_request
self.RequestHandlerClass(request, client_address, self)
File: "/usr/lib/python2.7/SocketServer.py", line 655, in init
self.handle()
File: "/usr/lib/python2.7/dist-packages/werkzeug/serving.py", line 293, in handle
rv = BaseHTTPRequestHandler.handle(self)
File: "/usr/lib/python2.7/BaseHTTPServer.py", line 340, in handle
self.handle_one_request()
File: "/usr/lib/python2.7/dist-packages/werkzeug/serving.py", line 328, in handle_one_request
return self.run_wsgi()
File: "/usr/lib/python2.7/dist-packages/werkzeug/serving.py", line 270, in run_wsgi
execute(self.server.app)
File: "/usr/lib/python2.7/dist-packages/werkzeug/serving.py", line 258, in execute
application_iter = app(environ, start_response)
File: "/usr/lib/python2.7/dist-packages/flask/app.py", line 2309, in call
return self.wsgi_app(environ, start_response)
File: "/usr/lib/python2.7/dist-packages/flask/app.py", line 2292, in wsgi_app
response = self.full_dispatch_request()
File: "/usr/lib/python2.7/dist-packages/flask/app.py", line 1813, in full_dispatch_request
rv = self.dispatch_request()
File: "/usr/lib/python2.7/dist-packages/flask/app.py", line 1799, in dispatch_request
return self.view_functionsrule.endpoint
File: "/root/photoframe/routes/baseroute.py", line 62, in call
return self.handle(self.app, **kwargs)
File: "/root/photoframe/routes/debug.py", line 34, in handle
report.append(debug.stacktrace())
File: "/root/photoframe/modules/debug.py", line 48, in stacktrace
for filename, lineno, name, line in traceback.extract_stack(stack):

ThreadID: -1246641056

File: "/usr/lib/python2.7/threading.py", line 774, in __bootstrap
self.__bootstrap_inner()
File: "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File: "/usr/lib/python2.7/threading.py", line 754, in run
self.__target(*self.__args, **self.__kwargs)
File: "/root/photoframe/modules/slideshow.py", line 315, in presentation
self.delayNextImage(time_process)
File: "/root/photoframe/modules/slideshow.py", line 252, in delayNextImage
self.delayer.wait(self.minimumWait) # Always wait ONE second to avoid busy waiting)
File: "/usr/lib/python2.7/threading.py", line 614, in wait
self.__cond.wait(timeout)
File: "/usr/lib/python2.7/threading.py", line 359, in wait
_sleep(delay)

ThreadID: -1266682784

File: "/usr/lib/python2.7/threading.py", line 774, in __bootstrap
self.__bootstrap_inner()
File: "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File: "/root/photoframe/modules/shutdown.py", line 59, in run
i = poller.poll(None)

ThreadID: -1225773040

File: "./frame.py", line 185, in
frame.start()
File: "./frame.py", line 182, in start
self.webServer.start()
File: "/root/photoframe/modules/server.py", line 84, in start
self.run()
File: "/root/photoframe/modules/server.py", line 101, in run
self.app.run(debug=False, port=self.port, host=self.listen )
File: "/usr/lib/python2.7/dist-packages/flask/app.py", line 943, in run
run_simple(host, port, self, **options)
File: "/usr/lib/python2.7/dist-packages/werkzeug/serving.py", line 814, in run_simple
inner()
File: "/usr/lib/python2.7/dist-packages/werkzeug/serving.py", line 777, in inner
srv.serve_forever()
File: "/usr/lib/python2.7/dist-packages/werkzeug/serving.py", line 612, in serve_forever
HTTPServer.serve_forever(self)
File: "/usr/lib/python2.7/SocketServer.py", line 231, in serve_forever
poll_interval)
File: "/usr/lib/python2.7/SocketServer.py", line 150, in _eintr_retry
return func(*args)

ThreadID: -1256197024

File: "/usr/lib/python2.7/threading.py", line 774, in __bootstrap
self.__bootstrap_inner()
File: "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File: "/root/photoframe/modules/timekeeper.py", line 118, in run