As an admin I should see Wikilink cron job user_lists_cron running hourly not daily.
Expected behavior:
Cron job runs hourly.
Github link to cron job
Actual behavior:
Cron job runs daily.
Description
Description
Details
Details
- Other Assignee
- jsn.sherman
Related Objects
Related Objects
- Mentioned Here
- T366978: [Wikilink] Aggregates maintenance commands errors
Event Timeline
Comment Actions
Merged! I will leave in QA to check if the cron job runs hourly like it's supposed to.
Comment Actions
from running this locally:
['extlinks.organisations.cron.UserListsCron: lock has been found. Other cron started at 2024-07-24 14:06:44.801583+00:00', "Current timeout for job extlinks.organisations.cron.UserListsCron is 86400 seconds (cache key name is 'extlinks.organisations.cron.UserListsCron')."]
86400 happens to be 24 hours. So, I would suspect that it is a locking issue
Comment Actions
I think I may have fixed this while looking at it:
https://github.com/WikipediaLibrary/externallinks/pull/373
Comment Actions
and that the user list job was getting passed over:
2024-07-24T18:45:56.922134078Z production_crons.1.pkgr1uct4h7v@prod | extlinks.organisations.cron.UserListsCron: lock found. Will try later.
okay, so the issue isn't fixed, but we have more insight. Now that we have db-based cron locks, I was able to look at them in django admin. I noticed that the lock object for the user list cron was staying locked:
and that the user list job was getting passed over:
2024-07-24T18:45:56.922134078Z production_crons.1.pkgr1uct4h7v@prod | extlinks.organisations.cron.UserListsCron: lock found. Will try later.
So I unchecked the "locked" status and saved. The next run resulted in a familiar error:
2024-07-24T17:42:14.211414407Z production_crons.1.vsbxyag6u9tx@prod | Error saving cronjob (<class 'extlinks.organisations.cron.UserListsCron'>) log message: (2006, 'MySQL server has gone away') 2024-07-24T17:42:14.332980083Z production_crons.1.vsbxyag6u9tx@prod | Error saving cronjob (<class 'extlinks.aggregates.cron.LinkAggregatesCron'>) log message: (2006, 'MySQL server has gone away') 2024-07-24T17:42:14.355775276Z production_crons.1.vsbxyag6u9tx@prod | Error saving cronjob (<class 'extlinks.aggregates.cron.UserAggregatesCron'>) log message: (2006, 'MySQL server has gone away') 2024-07-24T17:42:14.374402784Z production_crons.1.vsbxyag6u9tx@prod | Error saving cronjob (<class 'extlinks.aggregates.cron.PageProjectAggregatesCron'>) log message: (2006, 'MySQL server has gone away') 2024-07-24T17:42:14.389592554Z production_crons.1.vsbxyag6u9tx@prod | Error saving cronjob (<class 'extlinks.common.cron.BackupCron'>) log message: (2006, 'MySQL server has gone away') 2024-07-24T17:42:14.406281112Z production_crons.1.vsbxyag6u9tx@prod | Error saving cronjob (<class 'extlinks.links.cron.TotalLinksCron'>) log message: (2006, 'MySQL server has gone away')
I've unlocked it again and reproduced the issue. All containers remain up throughout. I'm thinking that it's a db connection issue. Perhaps django is trying to reuse a connection from the start of the job that has already been closed.
Comment Actions
I'm going to validate this by manually setting
"CONN_MAX_AGE": None, "CONN_HEALTH_CHECKS: True,
for the database on the running production system and then clear the lock again
Comment Actions
okay, we are no longer failing at the database connection itself, though there is still some work to do. The job is now completing as failed and the lock is cleared at the end. That means that we have a stack trace! Though not a super useful one :-/
Traceback (most recent call last):
File "/usr/local/lib/python3.11/site-packages/django_cron/management/commands/runcrons.py", line 82, in run_cron_with_cache_check
manager.run(force)
File "/usr/local/lib/python3.11/site-packages/django_cron/__init__.py", line 272, in run
with self.lock_class(cron_job_class, self.silent):
File "/usr/local/lib/python3.11/site-packages/django_cron/backends/lock/base.py", line 66, in __exit__
self.release()
File "/usr/local/lib/python3.11/contextlib.py", line 81, in inner
return func(*args, **kwds)
^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/django_cron/backends/lock/database.py", line 25, in release
lock.locked = False
^^^^^^^^^^^
AttributeError: 'NoneType' object has no attribute 'locked'Comment Actions
I notice that we have many warnings about our innodb_buffer_pool_size, which is at the tiny default value of 128M. This is a value that is often set to multiple gigabytes. I will increase it to 512M, which is a pretty conservative change.
Comment Actions
I'm going to hotfix these changes into git and we'll see how it does overnight
that seems to have made it happy:
I'm going to hotfix these changes into git and we'll see how it does overnight
Comment Actions
While we have solved the "mystery" that caused us to open this task, I see that the extlinks.aggregates.cron.PageProjectAggregatesCron job is very long running and blocks other jobs from running, including this one. This means that we're not really running hourly.
Comment Actions
Ok, I moved T366978: [Wikilink] Aggregates maintenance commands errors back to in progress to address the PageProjectAggregatesCron. I had a suspicion that it was long running causing locks because some of the jobs were only 1 second long and others were like 24 hours.