Podcast downloads hard time out after 300 seconds

[Robbt]

Due to the bandwidth constraints of one of our audio providers it appears that some podcast downloads are taking longer than 300 seconds to complete. Unfortunately LibreTime has a hard cut-off of 300 seconds currently employed.

Here is the error.
[2017-06-06 09:13:11,125: ERROR/MainProcess] Task handler raised error: TimeLimitExceeded(300.0,)
Traceback (most recent call last):
File "/usr/local/lib/python2.7/dist-packages/billiard-3.5.0.2-py2.7-linux-x86_64.egg/billiard/pool.py", line 661, in on_hard_timeout
raise TimeLimitExceeded(job._timeout)
TimeLimitExceeded: TimeLimitExceeded(300.0,)
[2017-06-06 09:13:11,127: ERROR/MainProcess] Hard time limit (300.0s) exceeded for podcast-download[php_5936a93aa2df19.97689474]
[2017-06-06 09:13:11,241: ERROR/MainProcess] Process 'PoolWorker-152' pid:12431 exited with 'signal 9 (SIGKILL)'
~

I will look into modification of this because this is needed for my station and I don't think we should expect all downloads to complete within 5 minutes especially for say bandwidth constrained internet connections that may occur around the globe.

[Robbt]

Ok, trying to fix this has descended into Python egg hell.
First the fix should be easy enough.
https://stackoverflow.com/questions/28713922/celery-hard-time-limit-defaults-to-300-no-matter-what
Add time_limit=333333, soft_time_limit=333333 to the @task for podcast downloads in tasks.py for airtime-celery

Unfortunately after trying to reinstall celery I ran into numerous odd issues that have me scratching my head.
First an error with ImportError: cannot import name 'get_fdmax' relating to billiard
then I try uninstall kombu and billiard and ran into an
ImportError: cannot import name LRUCache here - File "/usr/local/lib/python2.7/dist-packages/celery/utils/functional.py", line 11, in
from kombu.utils.functional import (
The only google hit I get is here celery/celery#3200
Which suggests installing the development version of kombu and billiard which highlights perhaps we need to lock the billiard version as we have in #161

Will continue to troubleshoot.

[Robbt]

Ok so I resolved the issue but running pip install pip --upgrade and then proceeding to run
sudo pip uninstall celery - repeatedly until it didn't find any version
sudo pip uninstall kombu - repeatedly until it didn't find any version
sudo pip uninstall billiard - repeatedly until it didn't find any version

pip had failed to find the versions before the upgrade but afterwards it was able to install airtime-celery just fine by running python setup.py install and it installed the appropriate versions and appears to be working.

Now we will see if that modification to the time_limit works. I made the limit 60 minutes or 6000 seconds as I figured that would be more than adequate for everything except the slowest of Internet connections.

Actually I was mistaken airtime-celery is now appearing to start based upon service airtime-celery start but it is failing to actually run and produce any loggable errors as indicated by its absence from the process list.

[Robbt]

So while trying to run it via the CLI - /usr/local//bin/celery worker -A airtime-celery.tasks:celery --time-limit=300 --concurrency=1 --config=celeryconfig -l INFO
First I had to sudo su and then su celery and
export RMQ_CONFIG_FILE=/etc/airtime/airtime.conf
then I got the following error that shows an issue with billiard
"

Traceback (most recent call last):
File "/usr/local//bin/celery", line 11, in
load_entry_point('celery==3.1.25', 'console_scripts', 'celery')()
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/main.py", line 30, in main
main()
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/bin/celery.py", line 81, in main
cmd.execute_from_commandline(argv)
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/bin/celery.py", line 793, in execute_from_commandline
super(CeleryCommand, self).execute_from_commandline(argv)))
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/bin/base.py", line 311, in execute_from_commandline
return self.handle_argv(self.prog_name, argv[1:])
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/bin/celery.py", line 785, in handle_argv
return self.execute(command, argv)
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/bin/celery.py", line 717, in execute
).run_from_argv(self.prog_name, argv[1:], command=argv[0])
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/bin/worker.py", line 179, in run_from_argv
return self(*args, **options)
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/bin/base.py", line 274, in call
ret = self.run(*args, **kwargs)
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/bin/worker.py", line 194, in run
pool_cls = (concurrency.get_implementation(pool_cls) or
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/concurrency/init.py", line 29, in get_implementation
return symbol_by_name(cls, ALIASES)
File "/usr/local/lib/python2.7/dist-packages/kombu-3.0.37-py2.7.egg/kombu/utils/init.py", line 96, in symbol_by_name
module = imp(module_name, package=package, **kwargs)
File "/usr/lib/python2.7/importlib/init.py", line 37, in import_module
import(name)
File "/usr/local/lib/python2.7/dist-packages/celery-3.1.25-py2.7.egg/celery/concurrency/prefork.py", line 14, in
from billiard.pool import RUN, CLOSE, Pool as BlockingPool
File "/usr/local/lib/python2.7/dist-packages/billiard-3.3.0.23-py2.7-linux-x86_64.egg/billiard/pool.py", line 34, in
from .dummy import DummyProcess
File "/usr/local/lib/python2.7/dist-packages/billiard-3.3.0.23-py2.7-linux-x86_64.egg/billiard/dummy/init.py", line 50, in
from billiard.connection import Pipe
File "/usr/local/lib/python2.7/dist-packages/billiard-3.3.0.23-py2.7-linux-x86_64.egg/billiard/connection.py", line 10, in
from .py2 import connection # noqa
File "/usr/local/lib/python2.7/dist-packages/billiard-3.3.0.23-py2.7-linux-x86_64.egg/billiard/py2/connection.py", line 23, in
from .. import reduction
File "/usr/local/lib/python2.7/dist-packages/billiard-3.3.0.23-py2.7-linux-x86_64.egg/billiard/reduction.py", line 8, in
from .py2 import reduction # noqa
File "/usr/local/lib/python2.7/dist-packages/billiard-3.3.0.23-py2.7-linux-x86_64.egg/billiard/py2/reduction.py", line 21, in
from .._ext import _billiard, win32
File "/usr/local/lib/python2.7/dist-packages/billiard-3.3.0.23-py2.7-linux-x86_64.egg/billiard/_ext.py", line 20, in
from billiard.connection import Connection # noqa
ImportError: cannot import name Connection

[Robbt]

Ok before anyone wastes their brainpower trying to decipher what has happened I managed to find a workaround.
sudo pip uninstall billiard
sudo pip install billiard
This worked because it installed the latest 3.5 version of billiard but for some reason either kombu < 3.1 or celery <4 was installing the 3.3 version of billiard which did not work. So there may still be a bug here that needs to be resolved in terms of tangled requirements. But I was able to get my celery worker started again.

I also realized that /etc/default/airtime-celery where sudo service airtime-celery gets its config file from and the systemd install file have the hard limit of 300 seconds encoded in
CELERYD_OPTS="--time-limit=300 --concurrency=1 --config=celeryconfig"

I'm trying to just modify that to
CELERYD_OPTS="--time-limit=6000 --concurrency=1 --config=celeryconfig"
and see if that fixes it without changing the limit inside of the individual task.

[hairmare]

From my CentOS experience the versions of celery, billiard, kombu, python-ampq and, vine need to match up to quite some degree for everything to work smoothly. Among them are some of the rare os packages that I had to replace with versions updated to a working state.

If I remember correctly, celery and CentOS didn't become friends until I realized that celery 3.x is much less buggy than 4.x.

For the record, CentOS has the following combo of versions that seem to work. Some of them might have distro patches applied (most shouldn't).

• billiard = 3.3.0.23
• python-amqp = 2.0.3
• celery = 3.1.20
• kombu = 3.0.33
• vine = 1.1.1

Some of these might also get installed by pip on vagrant boxes, I looked at the rabe rpm collection to get these versions.

[ghost]

Yeah,I looked and found that JohnnyC had already increased the time limit. from 300 to 1200 to cope with big podcasts >120mb

[hairmare]

I tracked down where the 300 is from, let's change the default to something higher. Maybe not as extreme as 6000, I might have gone 900, but 1200 is fine with me.

This is also hardcoded in the systemd unit where it should be increased and also made configurable through an env variable (overriding an ExecStart is much less intuitive).

It would probably make sense to add something explaining how to set this up (and what considerations the value has) to the manual. I'm not sure if it's Expert Install, Troubleshooting or, a new page in it's own right.

We can add something like the following to docs:

Celery Process Time Limit

If you use Celery to download podcasts or use soundcloud with large files you might need to tweak the --time-limit for Celery tasks.

The right value depends on your stations needs. You need to consider your own internet uplink, the podcast hosts uplink and the size of the largest files you intend to be able to download.

You should also factor in general network congestion and that some of your content providers may throttle individual downloads to allow for more concurrent downloads on their uplink.

The default for individual celery tasks is set to 1200 and can be changed through the LIBRETIME_CELERY_TIME_LIMIT env variable in /etc/default/airtime-celery or /path/to/systemd/env/file.

[Robbt]

Ok, so I just realized due station podcasts not updating that with the increased length the podcast timeout is actually causing airtime-celery to crash. Here is the log I received.

[2017-08-30 13:14:09,011: ERROR/MainProcess] Task podcast-download[php_59a6dac9520c84.11909640] raised unexpected: TimeLimitExceeded(6000.0,)
Traceback (most recent call last):
File "/usr/local/lib/python2.7/dist-packages/billiard/pool.py", line 661, in on_hard_timeout
raise TimeLimitExceeded(job._timeout)
TimeLimitExceeded: TimeLimitExceeded(6000.0,)
[2017-08-30 13:14:09,012: ERROR/MainProcess] Hard time limit (6000.0s) exceeded for podcast-download[php_59a6dac9520c84.11909640]
[2017-08-30 13:14:09,277: ERROR/MainProcess] Process 'PoolWorker-1' pid:1965 exited with 'signal 9 (SIGKILL)'
[2017-08-30 13:14:09,288: ERROR/MainProcess] Unrecoverable error: AttributeError("'Process' object has no attribute 'dead'",)
Traceback (most recent call last):
File "/usr/local/lib/python2.7/dist-packages/celery/worker/init.py", line 206, in start
self.blueprint.start(self)
File "/usr/local/lib/python2.7/dist-packages/celery/bootsteps.py", line 123, in start
step.start(parent)
File "/usr/local/lib/python2.7/dist-packages/celery/bootsteps.py", line 374, in start
return self.obj.start()
File "/usr/local/lib/python2.7/dist-packages/celery/worker/consumer.py", line 279, in start
blueprint.start(self)
File "/usr/local/lib/python2.7/dist-packages/celery/bootsteps.py", line 123, in start
step.start(parent)
File "/usr/local/lib/python2.7/dist-packages/celery/worker/consumer.py", line 838, in start
c.loop(*c.loop_args())
File "/usr/local/lib/python2.7/dist-packages/celery/worker/loops.py", line 76, in asynloop
next(loop)
File "/usr/local/lib/python2.7/dist-packages/kombu-3.0.37-py2.7.egg/kombu/async/hub.py", line 340, in create_loop
cb(*cbargs)
File "/usr/local/lib/python2.7/dist-packages/celery/concurrency/asynpool.py", line 420, in _event_process_exit
self.maintain_pool()
File "/usr/local/lib/python2.7/dist-packages/billiard/pool.py", line 1308, in maintain_pool
self._maintain_pool()
File "/usr/local/lib/python2.7/dist-packages/billiard/pool.py", line 1299, in _maintain_pool
joined = self._join_exited_workers()
File "/usr/local/lib/python2.7/dist-packages/billiard/pool.py", line 1203, in _join_exited_workers
self._process_cleanup_queues(worker)
File "/usr/local/lib/python2.7/dist-packages/celery/concurrency/asynpool.py", line 1086, in _process_cleanup_queues
if not proc.dead:
AttributeError: 'Process' object has no attribute 'dead'

[hairmare]

Smells like this: celery/celery#3395 (comment).

I think celery doesn't call _process_cleanup_queues very often and our queues aren't very full of procs most of the time.

[smilingpeanut]

So, after reading through this thread and ones linked back to it, is there a way to fix this? About half of the podcasts I'm attempting to import stall at the 300 second limit and only get about half of the show. Any thoughts? I'd be willing to post a bounty to get this fixed if needed.

[Robbt]

Hey @smilingpeanut welcome to the LibreeTime community. The fix I referenced above should be pretty easy to implement. We should modify the defaults for the install, but if you already have Libretime running, just modify /etc/init/airtime-celery.conf and modify the time-limit in there. It should be under
exec celery worker -A airtime-celery.tasks:celery --time-limit=300 --concurrency=1 --config=celeryconfig -l INFO and your problem should be solved. If you have any issues let us know.

We don't currently have any kind of process to handle bounties or donations at this point but perhaps we should consider it.

[smilingpeanut]

Hi @Robbt, thanks for the reply. Unfortunately, no file exists at that location on my server. Here's everything I could find that was close:

find . -name "airtime-celery*" ./var/lib/lxcfs/cgroup/devices/system.slice/airtime-celery.service ./var/lib/lxcfs/cgroup/pids/system.slice/airtime-celery.service ./var/lib/lxcfs/cgroup/blkio/system.slice/airtime-celery.service ./var/lib/lxcfs/cgroup/memory/system.slice/airtime-celery.service ./var/lib/lxcfs/cgroup/cpu,cpuacct/system.slice/airtime-celery.service ./var/lib/lxcfs/cgroup/name=systemd/system.slice/airtime-celery.service ./home/libretime/python_apps/airtime-celery ./home/libretime/python_apps/airtime-celery/airtime-celery ./home/libretime/python_apps/airtime-celery/build/lib.linux-x86_64-2.7/airtime-celery ./home/libretime/python_apps/airtime-celery/install/conf/airtime-celery ./home/libretime/python_apps/airtime-celery/install/upstart/airtime-celery.conf ./home/libretime/python_apps/airtime-celery/install/initd/airtime-celery ./home/libretime/installer/systemd/airtime-celery.service ./etc/systemd/system/airtime-celery.service ./etc/systemd/system/multi-user.target.wants/airtime-celery.service ./sys/fs/cgroup/devices/system.slice/airtime-celery.service ./sys/fs/cgroup/pids/system.slice/airtime-celery.service ./sys/fs/cgroup/blkio/system.slice/airtime-celery.service ./sys/fs/cgroup/memory/system.slice/airtime-celery.service ./sys/fs/cgroup/cpu,cpuacct/system.slice/airtime-celery.service ./sys/fs/cgroup/systemd/system.slice/airtime-celery.service ./usr/local/lib/python2.7/dist-packages/airtime_celery-0.1-py2.7.egg/airtime-celery

[Robbt]

Ok, it is most likely here then /etc/systemd/system/airtime-celery.service

[smilingpeanut]

Okay, after some further digging (and adjusting the celery timeout in the location indicated, thanks!), it turns out that my LibreTime server is correctly importing the full episodes from the podcast feeds.

But what seems to be happening is that a number of files (from different feeds) are only showing up with about half of their running time, ie. a 1 hour show is listed in LibreTime as only being 29 minutes long. The entire file is there, and it can be manually adjusted using the Edit functionality in LibreTime, but as you can imagine this causes an automation issue when episodes are part of smart blocks that are scheduled. The system has to add more episodes of that show to fill the time because it "thinks" the new episode is not long enough. Has anyone else had issues like this?

[Robbt]

Yeah, it sounds like you are getting hit with the Silan silence detection bug. This is because the version of silan included with certain debian based distros such as Ubuntu had a bug. Here is one way someone fixed it - #197

[frecuencialibre]

i wonder if autoloading playlists should also default to load half an hour before shows...

[lock]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.
Please chat to us on discourse or ask for help on our chat if you have any questions or need further assistance with this issue.