[ERROR/ForkPoolWorker-1] podcast-download[php_...]: could not upload episode

[J0hn3ch]

Describe the bug

Hello everyone,
I tried to download an episode after add a new podcast from RSS Feeds. When I click on "Import" button after selecting the episode, the load circle animation appear but the episode is not downloaded.

I see in the logs and could be a problem in the worker node.

Could be a problem related to the fact I don't have performed the reverse proxy configuration as explained to the official guide?

To reproduce

1. Go to Podcast
2. Click on "Add" button in Dashboard - Podcasts
3. Copy URLs refer to a podcast RSS Feed
4. After an entry is created, click on "Edit" and go to the right Tab and click the checkbox of a podcast episode you want to Import
5. Click "Import" button, and could see the load circle.
6. Read the logs

Expected behavior

The podcast's episode will be added to the podcast to be able to schedule it in the calendar

Relevant log output or error messages

libretime_4-0-0-worker-1      | [2024-02-15 11:42:58,808: ERROR/ForkPoolWorker-1] podcast-download[php_65cdf8a8be45f7.99154140]: could not upload episode 411
libretime_4-0-0-worker-1      | Traceback (most recent call last):
libretime_4-0-0-worker-1      |   File "/src/libretime_worker/tasks.py", line 114, in podcast_download
libretime_4-0-0-worker-1      |     upload_resp.raise_for_status()
libretime_4-0-0-worker-1      |   File "/usr/local/lib/python3.10/site-packages/requests/models.py", line 1021, in raise_for_status
libretime_4-0-0-worker-1      |     raise HTTPError(http_error_msg, response=self)
libretime_4-0-0-worker-1      | requests.exceptions.HTTPError: 400 Client Error: Bad Request for url: http://nginx:8080/rest/media
libretime_4-0-0-worker-1      | [2024-02-15 11:43:00,273: INFO/ForkPoolWorker-1] Task podcast-download[php_65cdf8a8be45f7.99154140] succeeded in 27.039817648997996s: '{"episodeid": 411, "status": 0, "error": "400 Client Error: Bad Request for url: http://nginx:8080/rest/media"}'

LibreTime version

4.0.0

Installation method and OS / Environment

Operating system: Ubuntu 22.04
Method: Docker Compose

Installation details

No response

Client Environment

No response

Screenshots

No response

[paddatrapper]

Do you have the logs from the legacy container too?

[J0hn3ch]

Do you have the logs from the legacy container too?

libretime_4-0-0-legacy-1 | 172.19.0.11 - 15/Feb/2024:22:53:00 +0000 "GET /index.php" 200
libretime_4-0-0-nginx-1 | 172.19.0.1 - - [15/Feb/2024:22:53:00 +0000] "GET /Schedule/get-current-playlist/format/json?_=1708037580268 HTTP/1.1" 200 1860 "http://localhost:8080/showbuilder" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:122.0) Gecko/20100101 Firefox/122.0" "-"
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:00.465420+00:00 [info] <0.19062.2> closing AMQP connection <0.19062.2> (172.19.0.9:53388 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:00.466354+00:00 [info] <0.19068.2> closing AMQP connection <0.19068.2> (172.19.0.9:53394 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:00.669675+00:00 [info] <0.19074.2> closing AMQP connection <0.19074.2> (172.19.0.9:53408 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:00.669917+00:00 [info] <0.19091.2> closing AMQP connection <0.19091.2> (172.19.0.9:53420 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:00.670581+00:00 [info] <0.19097.2> closing AMQP connection <0.19097.2> (172.19.0.9:53426 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:01.143282+00:00 [info] <0.19103.2> closing AMQP connection <0.19103.2> (172.19.0.9:53434 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:01.143783+00:00 [info] <0.19120.2> closing AMQP connection <0.19120.2> (172.19.0.9:53446 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:01.143938+00:00 [info] <0.19126.2> closing AMQP connection <0.19126.2> (172.19.0.9:53454 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:02.249329+00:00 [info] <0.19132.2> closing AMQP connection <0.19132.2> (172.19.0.9:53466 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:02.249660+00:00 [info] <0.19149.2> closing AMQP connection <0.19149.2> (172.19.0.9:53480 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-rabbitmq-1 | 2024-02-15 22:53:02.250348+00:00 [info] <0.19155.2> closing AMQP connection <0.19155.2> (172.19.0.9:53482 -> 172.19.0.4:5672, vhost: '/libretime', user: 'libretime')
libretime_4-0-0-legacy-1 | 2024-02-15T22:53:02+00:00 ERR (3): [MediaController.php:154 - postAction()] - Bad file extension.
libretime_4-0-0-legacy-1 | #0 /var/www/html/application/models/airtime/CcFiles.php(88): CcFiles::createAndImport()
libretime_4-0-0-legacy-1 | #1 /var/www/html/application/modules/rest/controllers/MediaController.php(141): CcFiles::createFromUpload()
libretime_4-0-0-legacy-1 | #2 /var/www/html/vendor/zf1s/zend-controller/library/Zend/Controller/Action.php(516): Rest_MediaController->postAction()
libretime_4-0-0-legacy-1 | #3 /var/www/html/vendor/zf1s/zend-controller/library/Zend/Controller/Dispatcher/Standard.php(308): Zend_Controller_Action->dispatch()
libretime_4-0-0-legacy-1 | #4 /var/www/html/vendor/zf1s/zend-controller/library/Zend/Controller/Front.php(954): Zend_Controller_Dispatcher_Standard->dispatch()
libretime_4-0-0-legacy-1 | #5 /var/www/html/vendor/zf1s/zend-application/library/Zend/Application/Bootstrap/Bootstrap.php(105): Zend_Controller_Front->dispatch()
libretime_4-0-0-legacy-1 | #6 /var/www/html/vendor/zf1s/zend-application/library/Zend/Application.php(391): Zend_Application_Bootstrap_Bootstrap->run()
libretime_4-0-0-legacy-1 | #7 /var/www/html/application/airtime-boot.php(77): Zend_Application->run()
libretime_4-0-0-legacy-1 | #8 /var/www/html/public/index.php(56): require_once('/var/www/html/a...')
libretime_4-0-0-legacy-1 | #9 {main}
libretime_4-0-0-legacy-1 | 172.19.0.11 - bcvrkseL3tFPlHaVXvHM86VXtd4HyQo 15/Feb/2024:22:53:00 +0000 "POST /index.php" 400
libretime_4-0-0-nginx-1 | 172.19.0.6 - bcvrkseL3tFPlHaVXvHM86VXtd4HyQoo [15/Feb/2024:22:53:02 +0000] "POST /rest/media HTTP/1.1" 400 93 "-" "python-requests/2.31.0" "-"
libretime_4-0-0-worker-1 | [2024-02-15 22:53:02,569: ERROR/ForkPoolWorker-1] podcast-download[php_65ce95cae5ea23.07298835]: could not upload episode 546
libretime_4-0-0-worker-1 | Traceback (most recent call last):
libretime_4-0-0-worker-1 | File "/src/libretime_worker/tasks.py", line 114, in podcast_download
libretime_4-0-0-worker-1 | upload_resp.raise_for_status()
libretime_4-0-0-worker-1 | File "/usr/local/lib/python3.10/site-packages/requests/models.py", line 1021, in raise_for_status
libretime_4-0-0-worker-1 | raise HTTPError(http_error_msg, response=self)
libretime_4-0-0-worker-1 | requests.exceptions.HTTPError: 400 Client Error: Bad Request for url: http://nginx:8080/rest/media
`
@paddatrapper Here the logs with the legacy container

[paddatrapper]

libretime_4-0-0-legacy-1 | 2024-02-15T22:53:02+00:00 ERR (3): [MediaController.php:154 - postAction()] - Bad file extension.

This I think is the root cause. What is the file's name/extension and is it actually that file type?

[J0hn3ch]

libretime_4-0-0-legacy-1 | 2024-02-15T22:53:02+00:00 ERR (3): [MediaController.php:154 - postAction()] - Bad file extension.

This I think is the root cause. What is the file's name/extension and is it actually that file type?

I found this page on the Documentation of LibreTime:
https://libretime.org/docs/user-manual/podcasts/

Inside the "Info Box", there is this explanation for this kind of problem:
RSS feeds that don't end in .xml may be accepted by LibreTime yet fail to download episodes

My Podcast URL is like:
https://www.spreaker.com/show/*******/episodes/feed, so it doesn't end with ".xml". Could be this the problem?

Also, the link showed in the column "Link" of the Podcast Tab is like
https://api.spreaker.com/download/episode/********/podcast1.mp3,
so it ends with ".mp3". But when I copy and paste the link on browser URL, it redirect to a link like
https://d1bxy2pveef3fq.cloudfront.net/episodes/original/38301647?...

What do you think about that? @paddatrapper

[paddatrapper]

It could very well be the issue