[Bug]: Auto Delete Stopped Working After Upgrade to Version 0.4.4

[birdwing]

I've read the documentation

• I'm running the latest version of Tube Archivist and have read the release notes.
• I have read the how to open an issue guide, particularly the bug report section.

Operating System

Linux

Your Bug Report

Describe the bug

Videos are not being deleted automatically.

Steps To Reproduce

Go to Settings -> Application
Set Auto Delete Watched Videos to 1
Download a Video to Trigger Auto Delete
Old videos are not deleted

Expected behavior

A day after the videos are watched they should be deleted.

Relevant log output

{"log":"[2023-12-03 08:47:59,821: INFO/MainProcess] Task download_pending[156a59a2-1671-4a06-98c3-098cae2cc08a] received\n","stream":"stderr","time":"2023-12-03T13:47:59.821750745Z"}
{"log":"[2023-12-03 08:47:59,825: WARNING/ForkPoolWorker-4] download_pending create callback\n","stream":"stderr","time":"2023-12-03T13:47:59.826418618Z"}
{"log":"[2023-12-03 08:48:00,900: WARNING/ForkPoolWorker-4] auto delete older than 1 days\n","stream":"stderr","time":"2023-12-03T13:48:00.901252608Z"}
{"log":"[2023-12-03 08:48:00,937: WARNING/ForkPoolWorker-4] UC4O9HKe9Jt5yAhKuNv3LXpQ: delete older than 1d\n","stream":"stderr","time":"2023-12-03T13:48:00.937427682Z"}
{"log":"[2023-12-03 08:48:00,968: WARNING/ForkPoolWorker-4] UCWFKCr40YwOZQx8FHU_ZqqQ: delete older than 1d\n","stream":"stderr","time":"2023-12-03T13:48:00.968927068Z"}
{"log":"[2023-12-03 08:48:01,006: WARNING/ForkPoolWorker-4] 156a59a2-1671-4a06-98c3-098cae2cc08a success callback\n","stream":"stderr","time":"2023-12-03T13:48:01.006996146Z"}
{"log":"[2023-12-03 08:48:01,011: INFO/ForkPoolWorker-4] Task download_pending[156a59a2-1671-4a06-98c3-098cae2cc08a] succeeded in 1.1817593285813928s: None\n","stream":"stderr","time":"2023-12-03T13:48:01.011763178Z"}
{"log":"[2023-12-03 08:48:01,011: WARNING/ForkPoolWorker-4] 156a59a2-1671-4a06-98c3-098cae2cc08a return callback\n","stream":"stderr","time":"2023-12-03T13:48:01.011908956Z"}
{"log":"{\"_index\":\"ta_video\",\"_id\":\"YWp6qjevHH0\",\"found\":false}\n","stream":"stderr","time":"2023-12-03T13:49:37.525230258Z"}
{"log":"Not Found: /api/video/YWp6qjevHH0/\n","stream":"stderr","time":"2023-12-03T13:49:37.526428298Z"}
{"log":"[pid: 38|app: 0|req: 90/90] 10.0.0.41 () {58 vars in 1003 bytes} [Sun Dec  3 08:49:37 2023] GET /api/video/YWp6qjevHH0/ =\u003e generated 493 bytes in 20 msecs (HTTP/1.1 404) 9 headers in 353 bytes (1 switches on core 0)\n","stream":"stderr","time":"2023-12-03T13:49:37.527313105Z"}
{"log":"[2023-12-03 08:49:38,114: INFO/MainProcess] Task extract_download[874554fb-09b4-4ba8-81a7-e85431c54a27] received\n","stream":"stderr","time":"2023-12-03T13:49:38.11465222Z"}
{"log":"[2023-12-03 08:49:38,116: WARNING/ForkPoolWorker-4] extract_download create callback\n","stream":"stderr","time":"2023-12-03T13:49:38.116846028Z"}
{"log":"[2023-12-03 08:49:38,575: WARNING/ForkPoolWorker-4] YWp6qjevHH0: [1/1]: add to queue\n","stream":"stderr","time":"2023-12-03T13:49:38.5761514Z"}
{"log":"[2023-12-03 08:49:40,763: WARNING/ForkPoolWorker-4] 874554fb-09b4-4ba8-81a7-e85431c54a27 success callback\n","stream":"stderr","time":"2023-12-03T13:49:40.764372647Z"}
{"log":"[2023-12-03 08:49:40,771: INFO/ForkPoolWorker-4] Task extract_download[874554fb-09b4-4ba8-81a7-e85431c54a27] succeeded in 2.647122242487967s: None\n","stream":"stderr","time":"2023-12-03T13:49:40.771560117Z"}
{"log":"[2023-12-03 08:49:40,771: WARNING/ForkPoolWorker-4] 874554fb-09b4-4ba8-81a7-e85431c54a27 return callback\n","stream":"stderr","time":"2023-12-03T13:49:40.771738575Z"}
{"log":"[2023-12-03 08:49:51,536: INFO/MainProcess] Task download_pending[d674893c-a3cd-4027-89b4-82c642c299ba] received\n","stream":"stderr","time":"2023-12-03T13:49:51.536638631Z"}
{"log":"[2023-12-03 08:49:51,537: WARNING/ForkPoolWorker-4] download_pending create callback\n","stream":"stderr","time":"2023-12-03T13:49:51.538420901Z"}
{"log":"[2023-12-03 08:49:51,901: WARNING/ForkPoolWorker-4] YWp6qjevHH0: Downloading video\n","stream":"stderr","time":"2023-12-03T13:49:51.901434743Z"}
{"log":"[2023-12-03 08:50:01,572: WARNING/ForkPoolWorker-4] YWp6qjevHH0: get metadata from youtube\n","stream":"stderr","time":"2023-12-03T13:50:01.572988444Z"}
{"log":"[2023-12-03 08:50:03,355: WARNING/ForkPoolWorker-4] UCdBK94H6oZT2Q7l0-b0xmMg: get metadata from es\n","stream":"stderr","time":"2023-12-03T13:50:03.355392084Z"}
{"log":"[2023-12-03 08:50:03,363: WARNING/ForkPoolWorker-4] {\"_index\":\"ta_channel\",\"_id\":\"UCdBK94H6oZT2Q7l0-b0xmMg\",\"found\":false}\n","stream":"stderr","time":"2023-12-03T13:50:03.363715721Z"}
{"log":"[2023-12-03 08:50:03,363: WARNING/ForkPoolWorker-4] UCdBK94H6oZT2Q7l0-b0xmMg: get metadata from youtube\n","stream":"stderr","time":"2023-12-03T13:50:03.364151119Z"}
{"log":"[2023-12-03 08:50:04,174: WARNING/ForkPoolWorker-4] UCdBK94H6oZT2Q7l0-b0xmMg: download channel thumbnail\n","stream":"stderr","time":"2023-12-03T13:50:04.175345473Z"}
{"log":"[2023-12-03 08:50:05,273: WARNING/ForkPoolWorker-4] YWp6qjevHH0: get sponsorblock timestamps\n","stream":"stderr","time":"2023-12-03T13:50:05.273764259Z"}
{"log":"[2023-12-03 08:50:06,466: WARNING/ForkPoolWorker-4] auto delete older than 1 days\n","stream":"stderr","time":"2023-12-03T13:50:06.470616314Z"}
{"log":"[2023-12-03 08:50:06,505: WARNING/ForkPoolWorker-4] UC4O9HKe9Jt5yAhKuNv3LXpQ: delete older than 1d\n","stream":"stderr","time":"2023-12-03T13:50:06.505571602Z"}
{"log":"[2023-12-03 08:50:06,540: WARNING/ForkPoolWorker-4] UCWFKCr40YwOZQx8FHU_ZqqQ: delete older than 1d\n","stream":"stderr","time":"2023-12-03T13:50:06.541346029Z"}
{"log":"[2023-12-03 08:50:06,628: WARNING/ForkPoolWorker-4] d674893c-a3cd-4027-89b4-82c642c299ba success callback\n","stream":"stderr","time":"2023-12-03T13:50:06.628946087Z"}
{"log":"[2023-12-03 08:50:06,634: INFO/ForkPoolWorker-4] Task download_pending[d674893c-a3cd-4027-89b4-82c642c299ba] succeeded in 15.090998463332653s: 'downloaded 1 videos.'\n","stream":"stderr","time":"2023-12-03T13:50:06.635253769Z"}
{"log":"[2023-12-03 08:50:06,635: WARNING/ForkPoolWorker-4] d674893c-a3cd-4027-89b4-82c642c299ba return callback\n","stream":"stderr","time":"2023-12-03T13:50:06.635497112Z"}
{"log":"[2023-12-03 08:50:06,645: WARNING/ForkPoolWorker-4] A Connection error occurred sending JSON notification to 10.0.0.142.\n","stream":"stderr","time":"2023-12-03T13:50:06.645493193Z"}

Anything else?

It doesn't even appear to attempt to delete the videos.
This is all I got in the logs after a fresh restart and setting DJANGO_DEBUG = true.
I attempted 2 downloads. Some of the videos not being deleted were watched 3 or 4 days ago.

Digging further into, I went to one of the Channel pages then to About.
I noticed that "Auto Delete" on each channel page has been set to "false"
I never did this. I have only ever set Auto Delete on the settings page.
It appears that somehow during the upgrade to this version, all the channel page setting overrides for Auto Delete got set to "false" (0)

[birdwing]

I just went through all the channels I am subscribbed to in Tubearchivist and set the Auto Delete on each channel too 1.
Downloaded videos again (one of my channels just happened to have uploaded a new video)

None of the old videos were deleted. It seems to be completely broken.
Here are the logs after that:

{"log":"[2023-12-03 09:05:10,440: INFO/ForkPoolWorker-2] Task update_subscribed[0ef62e7a-16f3-4e50-bffc-fa9d213df685] succeeded in 10.383961968123913s: None\n","stream":"stderr","time":"2023-12-03T14:05:10.443193602Z"}
{"log":"[2023-12-03 09:05:10,441: WARNING/ForkPoolWorker-2] 0ef62e7a-16f3-4e50-bffc-fa9d213df685 return callback\n","stream":"stderr","time":"2023-12-03T14:05:10.443249044Z"}
{"log":"[2023-12-03 09:06:57,910: WARNING/ForkPoolWorker-4] eWnsJB_sfMs: get metadata from youtube\n","stream":"stderr","time":"2023-12-03T14:06:57.911015174Z"}
{"log":"[2023-12-03 09:07:00,765: WARNING/ForkPoolWorker-4] UCuMJPFqazQI4SofSFEd-5zA: get metadata from es\n","stream":"stderr","time":"2023-12-03T14:07:00.766226131Z"}
{"log":"[2023-12-03 09:07:00,920: WARNING/ForkPoolWorker-4] eWnsJB_sfMs: get sponsorblock timestamps\n","stream":"stderr","time":"2023-12-03T14:07:00.920482646Z"}
{"log":"[2023-12-03 09:07:01,136: WARNING/ForkPoolWorker-4] eWnsJB_sfMs: sponsorblock failed: 404\n","stream":"stderr","time":"2023-12-03T14:07:01.136677331Z"}
{"log":"[2023-12-03 09:07:07,381: WARNING/ForkPoolWorker-4] auto delete older than 1 days\n","stream":"stderr","time":"2023-12-03T14:07:07.382028674Z"}
{"log":"[2023-12-03 09:07:07,404: WARNING/ForkPoolWorker-4] UC4O9HKe9Jt5yAhKuNv3LXpQ: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.405329922Z"}
{"log":"[2023-12-03 09:07:07,427: WARNING/ForkPoolWorker-4] UC6107grRI4m0o2-emgoDnAA: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.428212403Z"}
{"log":"[2023-12-03 09:07:07,449: WARNING/ForkPoolWorker-4] UCFKDEp9si4RmHFWJW1vYsMA: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.450179203Z"}
{"log":"[2023-12-03 09:07:07,480: WARNING/ForkPoolWorker-4] UCHYoe8kQ-7Gn9ASOlmI0k6Q: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.480692718Z"}
{"log":"[2023-12-03 09:07:07,505: WARNING/ForkPoolWorker-4] UCPK5G4jeoVEbUp5crKJl6CQ: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.506233683Z"}
{"log":"[2023-12-03 09:07:07,529: WARNING/ForkPoolWorker-4] UCR9Gcq0CMm6YgTzsDxAxjOQ: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.52952583Z"}
{"log":"[2023-12-03 09:07:07,551: WARNING/ForkPoolWorker-4] UCU9pX8hKcrx06XfOB-VQLdw: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.551982298Z"}
{"log":"[2023-12-03 09:07:07,575: WARNING/ForkPoolWorker-4] UCWFKCr40YwOZQx8FHU_ZqqQ: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.575781527Z"}
{"log":"[2023-12-03 09:07:07,599: WARNING/ForkPoolWorker-4] UCZ9x-z3iOnIbJxVpm1rsu2A: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.600458209Z"}
{"log":"[2023-12-03 09:07:07,625: WARNING/ForkPoolWorker-4] UChFur_NwVSbUozOcF_F2kMg: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.625636103Z"}
{"log":"[2023-12-03 09:07:07,647: WARNING/ForkPoolWorker-4] UCluqnG4yYHGsfRuV-_wjHNw: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.647703533Z"}
{"log":"[2023-12-03 09:07:07,670: WARNING/ForkPoolWorker-4] UCodkNmk9oWRTIYZdr_HuSlg: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.671194747Z"}
{"log":"[2023-12-03 09:07:07,693: WARNING/ForkPoolWorker-4] UCsM--5bs5DdDVpALDPXUiiw: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.694131332Z"}
{"log":"[2023-12-03 09:07:07,716: WARNING/ForkPoolWorker-4] UCu17Sme-KE87ca9OTzP0p7g: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.716811434Z"}
{"log":"[2023-12-03 09:07:07,741: WARNING/ForkPoolWorker-4] UCuMJPFqazQI4SofSFEd-5zA: delete older than 1d\n","stream":"stderr","time":"2023-12-03T14:07:07.741831971Z"}
{"log":"[2023-12-03 09:07:07,802: WARNING/ForkPoolWorker-4] 63f05b1b-e35a-49c1-95aa-3b3a15c4f3bc success callback\n","stream":"stderr","time":"2023-12-03T14:07:07.803106807Z"}
{"log":"[2023-12-03 09:07:07,808: INFO/ForkPoolWorker-4] Task download_pending[63f05b1b-e35a-49c1-95aa-3b3a15c4f3bc] succeeded in 135.25222819205374s: 'downloaded 1 videos.'\n","stream":"stderr","time":"2023-12-03T14:07:07.808501288Z"}
{"log":"[2023-12-03 09:07:07,808: WARNING/ForkPoolWorker-4] 63f05b1b-e35a-49c1-95aa-3b3a15c4f3bc return callback\n","stream":"stderr","time":"2023-12-03T14:07:07.808575334Z"}
{"log":"[2023-12-03 09:07:07,815: WARNING/ForkPoolWorker-4] A Connection error occurred sending JSON notification to 10.0.0.142.\n","stream":"stderr","time":"2023-12-03T14:07:07.816302271Z"}

There are alot more "delete after 1d" entries. But nothing actually gets deleted.

[bbilly1]

Can confirm, same problem with incompatible datatypes never returning anything from ES as fixed for the periodic reindex task in v0.4.4.

[Pete060490]

Same here, just pasting my logs in case that helps:

[2023-12-13 19:32:50,625: INFO/MainProcess] Task extract_download[926d7100-5ddf-4dae-8be3-59261943fed2] received
[2023-12-13 19:32:50,627: WARNING/ForkPoolWorker-8] extract_download create callback
[2023-12-13 19:32:50,816: WARNING/ForkPoolWorker-8] vM6WtOmy190: [1/1]: add to queue
[2023-12-13 19:32:53,373: INFO/MainProcess] Task download_pending[529ad129-17de-40be-bc8f-69ca227c66b9] received
[2023-12-13 19:32:53,374: WARNING/ForkPoolWorker-1] download_pending create callback
[2023-12-13 19:32:53,375: WARNING/ForkPoolWorker-8] 926d7100-5ddf-4dae-8be3-59261943fed2 success callback
[2023-12-13 19:32:53,379: INFO/ForkPoolWorker-8] Task extract_download[926d7100-5ddf-4dae-8be3-59261943fed2] succeeded in 2.748674105037935s: None
[2023-12-13 19:32:53,379: WARNING/ForkPoolWorker-8] 926d7100-5ddf-4dae-8be3-59261943fed2 return callback
[2023-12-13 19:32:53,511: WARNING/ForkPoolWorker-1] vM6WtOmy190: Downloading video
[2023-12-13 19:33:04,489: WARNING/ForkPoolWorker-1] vM6WtOmy190: get metadata from youtube
[2023-12-13 19:33:06,851: WARNING/ForkPoolWorker-1] UCiW7-IEQCTqS9l7223whHZA: get metadata from es
[2023-12-13 19:33:06,977: WARNING/ForkPoolWorker-1] vM6WtOmy190: get ryd stats
[2023-12-13 19:33:07,086: WARNING/ForkPoolWorker-1] vM6WtOmy190: get sponsorblock timestamps
[2023-12-13 19:33:07,285: WARNING/ForkPoolWorker-1] vM6WtOmy190: sponsorblock failed: 404
[2023-12-13 19:33:07,287: WARNING/ForkPoolWorker-1] vM6WtOmy190-en: get user uploaded subtitles
[2023-12-13 19:33:07,287: WARNING/ForkPoolWorker-1] vM6WtOmy190-en: get auto generated subtitles
[2023-12-13 19:33:07,287: WARNING/ForkPoolWorker-1] vM6WtOmy190-de: get user uploaded subtitles
[2023-12-13 19:33:07,287: WARNING/ForkPoolWorker-1] vM6WtOmy190-de: get auto generated subtitles
[2023-12-13 19:33:08,146: WARNING/ForkPoolWorker-1] auto delete older than 1 days
[2023-12-13 19:33:08,206: WARNING/ForkPoolWorker-1] vM6WtOmy190: get comments
[2023-12-13 19:33:12,252: WARNING/ForkPoolWorker-1] WARNING: [youtube] Incomplete data received. Retrying (1/3)...
[2023-12-13 19:33:12,339: WARNING/ForkPoolWorker-1] WARNING: [youtube] Incomplete data received. Retrying (2/3)...
[2023-12-13 19:33:12,470: WARNING/ForkPoolWorker-1] WARNING: [youtube] Incomplete data received. Retrying (3/3)...
[2023-12-13 19:33:12,557: WARNING/ForkPoolWorker-1] WARNING: [youtube] Incomplete data received. Giving up after 3 retries
[2023-12-13 19:33:13,142: WARNING/ForkPoolWorker-1] vM6WtOmy190: upload comments
[2023-12-13 19:33:13,256: WARNING/ForkPoolWorker-1] 529ad129-17de-40be-bc8f-69ca227c66b9 success callback
[2023-12-13 19:33:13,258: INFO/ForkPoolWorker-1] Task download_pending[529ad129-17de-40be-bc8f-69ca227c66b9] succeeded in 19.881462368997745s: 'downloaded 1 videos.'

[bbilly1]

should be fixed in v0.4.5