search

bitsy-ai / printnanny-os

Image repository, change logs, and issue tracking for PrintNanny OS
GNU Affero General Public License v3.0
23 stars 2 forks source link

Video recording sometimes uploads 0 bytes, then exits #287

Closed leigh-johnson closed 1 year ago

leigh-johnson commented 1 year ago

Describe the bug

I managed to reproduce this one, although I haven't figured out the cause yet.

Logs:

Feb 27 17:39:24 travelpi systemd[1]: Starting Sync Video Recording with id=5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5...
Feb 27 17:39:24 travelpi printnanny[1700]: [2023-02-27T18:39:24Z INFO  printnanny_services::video_recording_sync] Starting cloud sync for VideoRecording: VideoRecording { id: "5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5", deleted: false, recording_status: "done", recording_start: Some(2023-02-27T18:36:01.227444220Z), recording_end: Some(2023-02-27T18:39:24.723063970Z), mp4_file_name: "/home/printnanny/.local/share/printnanny/video/5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5.mp4", mp4_upload_url: None, mp4_download_url: None, gcode_file_name: None, cloud_sync_status: "pending", cloud_sync_percent: None, cloud_sync_start: None, cloud_sync_end: None }
Feb 27 17:39:26 travelpi printnanny[1700]: [2023-02-27T18:39:26Z INFO  printnanny_edge_db::video_recording] Updated VideoRecording with id 5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5
Feb 27 17:39:26 travelpi printnanny[1700]: [2023-02-27T18:39:26Z INFO  printnanny_edge_db::video_recording] Updated VideoRecording with id 5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5
Feb 27 17:39:27 travelpi printnanny[1700]: [2023-02-27T18:39:27Z INFO  printnanny_edge_db::video_recording] Updated VideoRecording with id 5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5
Feb 27 17:39:27 travelpi printnanny[1700]: [2023-02-27T18:39:27Z INFO  printnanny_edge_db::video_recording] Updated VideoRecording with id 5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5
Feb 27 17:39:28 travelpi printnanny[1700]: [2023-02-27T18:39:28Z INFO  printnanny_edge_db::video_recording] Updated VideoRecording with id 5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5
Feb 27 17:39:28 travelpi printnanny[1700]: [2023-02-27T18:39:28Z INFO  printnanny_services::video_recording_sync] upload_video_recording response: Response {
Feb 27 17:39:28 travelpi printnanny[1700]:         url: Url {
Feb 27 17:39:28 travelpi printnanny[1700]:             scheme: "https",
Feb 27 17:39:28 travelpi printnanny[1700]:             cannot_be_a_base: false,
Feb 27 17:39:28 travelpi printnanny[1700]:             username: "",
Feb 27 17:39:28 travelpi printnanny[1700]:             password: None,
Feb 27 17:39:28 travelpi printnanny[1700]:             host: Some(
Feb 27 17:39:28 travelpi printnanny[1700]:                 Domain(
Feb 27 17:39:28 travelpi printnanny[1700]:                     "storage.googleapis.com",
Feb 27 17:39:28 travelpi printnanny[1700]:                 ),
Feb 27 17:39:28 travelpi printnanny[1700]:             ),
Feb 27 17:39:28 travelpi printnanny[1700]:             port: None,
Feb 27 17:39:28 travelpi printnanny[1700]:             path: "/print-nanny-prod/media/uploads/video_recordings/mp4/2023/02/27/5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5.mp4",
Feb 27 17:39:28 travelpi printnanny[1700]:             query: Some(
Feb 27 17:39:28 travelpi printnanny[1700]:                 "X-Goog-Algorithm=GOOG4-RSA-SHA256&X-Goog-Credential=webapp--live%40print-nanny.iam.gserviceaccount.com%2F20230227%2Fauto%2Fstorage%2Fgoog4_request&X-Goog-Date=20230227T183925Z&X-Goog-Expires=172800&X-Goog-SignedHeaders=host&X-Goog-Signature=5b1c0a6a2a062d804eee11b4d9f3d1691c5a756c918d6c32a9fca2a4b162dd41e3ec7eba3736448d4a6802cee796ef32e05ce2c6547393bb6c35c26de79284ab0fded98531837994a1c4fd709af802af57b2e4eaef5cfef24cdac8c2594b63fa1b33afe8b7c8569e7f0cdf61ae89736e0de7abe828f3de0f033b7590b0a5ebe76c0238ccac1a017efe0f480089ba2ee6584ad4bf88fa0d5642e7d1baf45611039553962045df0293cd427583725db5b51fecac1bd9fad0fa9e83ff6b910d5ec0b27631785538cf8dfc6b4a1ca4b241f639da5a093b10a9697d181c3537f0f6402429ab4f63f5b5b823f8b3c3fcaaf36699aba40c785f95e5b9fc5da2a037d8a0",
Feb 27 17:39:28 travelpi printnanny[1700]:             ),
Feb 27 17:39:28 travelpi printnanny[1700]:             fragment: None,
Feb 27 17:39:28 travelpi printnanny[1700]:         },
Feb 27 17:39:28 travelpi printnanny[1700]:         status: 200,
Feb 27 17:39:28 travelpi printnanny[1700]:         headers: {
Feb 27 17:39:28 travelpi printnanny[1700]:             "x-guploader-uploadid": "ADPycdsfsBZXqwuNH32GYVfTMQ7jiU3Z-oAT-1S9a7xN4O6SkeBFrBcLJo2updl93OnOLuQgsAQ4geY3UsolEMFB9bs-efVUMRVo",
Feb 27 17:39:28 travelpi printnanny[1700]:             "etag": "\"d41d8cd98f00b204e9800998ecf8427e\"",
Feb 27 17:39:28 travelpi printnanny[1700]:             "x-goog-generation": "1677523168451147",
Feb 27 17:39:28 travelpi printnanny[1700]:             "x-goog-metageneration": "1",
Feb 27 17:39:28 travelpi printnanny[1700]:             "x-goog-hash": "crc32c=AAAAAA==",
Feb 27 17:39:28 travelpi printnanny[1700]:             "x-goog-hash": "md5=1B2M2Y8AsgTpgAmY7PhCfg==",
Feb 27 17:39:28 travelpi printnanny[1700]:             "x-goog-stored-content-length": "0",
Feb 27 17:39:28 travelpi printnanny[1700]:             "x-goog-stored-content-encoding": "identity",
Feb 27 17:39:28 travelpi printnanny[1700]:             "vary": "Origin",
Feb 27 17:39:28 travelpi printnanny[1700]:             "content-length": "0",
Feb 27 17:39:28 travelpi printnanny[1700]:             "date": "Mon, 27 Feb 2023 18:39:28 GMT",
Feb 27 17:39:28 travelpi printnanny[1700]:             "server": "UploadServer",
Feb 27 17:39:28 travelpi printnanny[1700]:             "content-type": "text/html; charset=UTF-8",
Feb 27 17:39:28 travelpi printnanny[1700]:             "alt-svc": "h3=\":443\"; ma=2592000,h3-29=\":443\"; ma=2592000,h3-Q050=\":443\"; ma=2592000,h3-Q046=\":443\"; ma=2592000,h3-Q043=\":443\"; ma=2592000,quic=\":443\"; ma=2592000; v=\"46,43\"",
Feb 27 17:39:28 travelpi printnanny[1700]:         },
Feb 27 17:39:28 travelpi printnanny[1700]:     }
Feb 27 17:39:28 travelpi printnanny[1700]: [2023-02-27T18:39:28Z INFO  printnanny_services::video_recording_sync] Removing local file: /home/printnanny/.local/share/printnanny/video/5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5.mp4
Feb 27 17:39:28 travelpi printnanny[1700]: [2023-02-27T18:39:28Z INFO  printnanny_edge_db::video_recording] Updated VideoRecording with id 5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5
Feb 27 17:39:28 travelpi systemd[1]: printnanny-recording-sync@5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5.service: Deactivated successfully.
Feb 27 17:39:28 travelpi systemd[1]: Finished Sync Video Recording with id=5c5e8561-ea1b-48d0-9f0f-8c8fb54382a5.

In GCS, I'm seeing:

Type
application/octet-stream
Size
0 B
Created
Feb 27, 2023, 7:39:28 PM
Last modified
Feb 27, 2023, 7:39:28 PM
leigh-johnson commented 1 year ago

Looking into this further, it looks like the problem is recordings under a certain length aren't getting flushed to disk.

With cloud backups disabled (so local recordings are kept), I started / stopped a quick 10 second recording but see 0 bytes written:

travelpi:~$ ls -ahl  ~/.local/share/printnanny/video/c27c35f3-71be-4109-bf44-a0dbd7657e84.mp4
-rw-r--r-- 1 printnanny printnanny 0 Feb 28 10:42 /home/printnanny/.local/share/printnanny/video/c27c35f3-71be-4109-bf44-a0dbd7657e84.mp4
leigh-johnson commented 1 year ago

:raised_hands: Fixed in the latest nightly!

I'm going to tweak the chunk size to ~5MB, and we'll sync each part in a parallel process as the chunks are written out. 

dev-rpi4:~$ ls -ahl /home/printnanny/.local/share/printnanny/video/810ea2c4-e0d0-4b15-a9bc-68e8c0cb0b18/
total 1.5M
drwxr-xr-x  2 printnanny printnanny 1.0K Nov  8 06:05 .
drwxrwxr-x 17 printnanny printnanny 1.0K Nov  8 06:04 ..
-rw-r--r--  1 printnanny printnanny 113K Nov  8 06:04 00000.mp4
-rw-r--r--  1 printnanny printnanny 109K Nov  8 06:04 00001.mp4
-rw-r--r--  1 printnanny printnanny 113K Nov  8 06:04 00002.mp4
-rw-r--r--  1 printnanny printnanny 115K Nov  8 06:04 00003.mp4
-rw-r--r--  1 printnanny printnanny 116K Nov  8 06:04 00004.mp4
-rw-r--r--  1 printnanny printnanny 117K Nov  8 06:04 00005.mp4
-rw-r--r--  1 printnanny printnanny 117K Nov  8 06:04 00006.mp4
-rw-r--r--  1 printnanny printnanny 116K Nov  8 06:04 00007.mp4
-rw-r--r--  1 printnanny printnanny 117K Nov  8 06:04 00008.mp4
-rw-r--r--  1 printnanny printnanny 119K Nov  8 06:05 00009.mp4
-rw-r--r--  1 printnanny printnanny 118K Nov  8 06:05 00010.mp4
-rw-r--r--  1 printnanny printnanny 125K Nov  8 06:05 00011.mp4
-rw-r--r--  1 printnanny printnanny  65K Nov  8 06:05 00012.mp4