0001-misc-add-log-mecanism-for-cron-jobs-57604.patch
| tests/test_publisher.py | ||
|---|---|---|
| 1 | 1 |
import datetime |
| 2 | 2 |
import io |
| 3 | 3 |
import json |
| 4 |
import logging |
|
| 4 | 5 |
import os |
| 5 | 6 |
import pickle |
| 6 | 7 |
import re |
| ... | ... | |
| 206 | 207 |
assert pub.cfg['sp'] == {'what': 'ever'}
|
| 207 | 208 | |
| 208 | 209 | |
| 209 |
def test_cron_command(): |
|
| 210 |
def test_cron_command(caplog, settings): |
|
| 211 |
caplog.set_level(logging.INFO, logger="wcs.cron") |
|
| 212 |
offset = ord(settings.SECRET_KEY[-1]) % 60 |
|
| 210 | 213 |
pub = create_temporary_pub() |
| 211 | 214 |
with mock.patch('tempfile.gettempdir') as gettempdir:
|
| 212 | 215 |
gettempdir.side_effect = lambda: pub.app_dir |
| ... | ... | |
| 221 | 224 |
mock_tenants.return_value = [ |
| 222 | 225 |
Tenant(os.path.join(pub.app_dir, x)) for x in ('example.net', 'foo.bar', 'something.com')
|
| 223 | 226 |
] |
| 227 |
caplog.clear() |
|
| 224 | 228 |
call_command('cron')
|
| 225 | 229 |
assert cron_worker.call_count == 3 |
| 230 |
assert caplog.record_tuples == [ |
|
| 231 |
('wcs.cron', logging.INFO, 'starting cron (minutes offset is %s)' % offset),
|
|
| 232 |
('wcs.cron', logging.INFO, '[tenant example.net] start'),
|
|
| 233 |
('wcs.cron', logging.INFO, '[tenant foo.bar] start'),
|
|
| 234 |
('wcs.cron', logging.INFO, '[tenant something.com] start'),
|
|
| 235 |
] |
|
| 226 | 236 |
cron_worker.reset_mock() |
| 237 |
caplog.clear() |
|
| 227 | 238 |
call_command('cron', domain='example.net')
|
| 228 | 239 |
assert cron_worker.call_count == 1 |
| 240 |
assert caplog.record_tuples == [ |
|
| 241 |
('wcs.cron', logging.INFO, 'starting cron (minutes offset is %s)' % offset),
|
|
| 242 |
('wcs.cron', logging.INFO, '[tenant example.net] start'),
|
|
| 243 |
] |
|
| 229 | 244 |
cron_worker.reset_mock() |
| 230 | 245 | |
| 231 | 246 |
# disable cron on something.com |
| ... | ... | |
| 238 | 253 |
''' |
| 239 | 254 |
) |
| 240 | 255 | |
| 256 |
caplog.clear() |
|
| 241 | 257 |
call_command('cron')
|
| 242 | 258 |
assert cron_worker.call_count == 2 |
| 259 |
assert caplog.record_tuples == [ |
|
| 260 |
('wcs.cron', logging.INFO, 'starting cron (minutes offset is %s)' % offset),
|
|
| 261 |
('wcs.cron', logging.INFO, '[tenant example.net] start'),
|
|
| 262 |
('wcs.cron', logging.INFO, '[tenant foo.bar] start'),
|
|
| 263 |
] |
|
| 243 | 264 |
cron_worker.reset_mock() |
| 244 | 265 |
os.unlink(site_options_path) |
| 245 | 266 | |
| ... | ... | |
| 289 | 310 |
def job2(pub): |
| 290 | 311 |
jobs.append('job2')
|
| 291 | 312 | |
| 292 |
def job3(pub): |
|
| 313 |
def job3(pub, job):
|
|
| 293 | 314 |
jobs.append('job3')
|
| 315 |
for key in ['foo', 'bar', 'blah']: |
|
| 316 |
with job.log_long_job(key): |
|
| 317 |
pass |
|
| 294 | 318 | |
| 295 | 319 |
@classmethod |
| 296 | 320 |
def register_test_cronjobs(cls): |
| ... | ... | |
| 303 | 327 |
call_command('cron', job_name='job1', domain='example.net')
|
| 304 | 328 |
assert jobs == [] |
| 305 | 329 |
get_publisher_class().cronjobs = [] |
| 330 |
caplog.clear() |
|
| 306 | 331 |
call_command('cron', job_name='job2', domain='example.net')
|
| 307 | 332 |
assert jobs == ['job2'] |
| 333 |
assert caplog.record_tuples == [ |
|
| 334 |
('wcs.cron', logging.INFO, 'starting cron (minutes offset is %s)' % offset),
|
|
| 335 |
('wcs.cron', logging.INFO, '[tenant example.net] start'),
|
|
| 336 |
] |
|
| 337 |
get_publisher_class().cronjobs = [] |
|
| 338 |
jobs = [] |
|
| 339 |
caplog.clear() |
|
| 340 |
with mock.patch('wcs.qommon.cron.CronJob.LONG_JOB_DURATION', 0):
|
|
| 341 |
call_command('cron', job_name='job2', domain='example.net')
|
|
| 342 |
assert caplog.record_tuples == [ |
|
| 343 |
('wcs.cron', logging.INFO, 'starting cron (minutes offset is %s)' % offset),
|
|
| 344 |
('wcs.cron', logging.INFO, '[tenant example.net] start'),
|
|
| 345 |
('wcs.cron', logging.INFO, '[tenant example.net] long job: job2 (took 0 minutes)'),
|
|
| 346 |
] |
|
| 347 |
assert jobs == ['job2'] |
|
| 348 |
get_publisher_class().cronjobs = [] |
|
| 349 |
jobs = [] |
|
| 350 |
caplog.clear() |
|
| 351 |
with mock.patch('wcs.qommon.cron.CronJob.LONG_JOB_DURATION', 0):
|
|
| 352 |
call_command('cron', job_name='job3', domain='example.net')
|
|
| 353 |
assert caplog.record_tuples == [ |
|
| 354 |
('wcs.cron', logging.INFO, 'starting cron (minutes offset is %s)' % offset),
|
|
| 355 |
('wcs.cron', logging.INFO, '[tenant example.net] start'),
|
|
| 356 |
('wcs.cron', logging.INFO, '[tenant example.net] job3: running on "foo" took 0 minutes'),
|
|
| 357 |
('wcs.cron', logging.INFO, '[tenant example.net] job3: running on "bar" took 0 minutes'),
|
|
| 358 |
('wcs.cron', logging.INFO, '[tenant example.net] job3: running on "blah" took 0 minutes'),
|
|
| 359 |
('wcs.cron', logging.INFO, '[tenant example.net] long job: job3 (took 0 minutes)'),
|
|
| 360 |
] |
|
| 361 |
assert jobs == ['job3'] |
|
| 308 | 362 | |
| 309 | 363 | |
| 310 | 364 |
def test_clean_afterjobs(): |
| wcs/qommon/cron.py | ||
|---|---|---|
| 14 | 14 |
# You should have received a copy of the GNU General Public License |
| 15 | 15 |
# along with this program; if not, see <http://www.gnu.org/licenses/>. |
| 16 | 16 | |
| 17 |
import inspect |
|
| 18 |
import logging |
|
| 19 |
from contextlib import contextmanager |
|
| 20 |
from time import perf_counter |
|
| 21 | ||
| 17 | 22 |
from django.conf import settings |
| 23 |
from quixote import get_publisher |
|
| 18 | 24 | |
| 19 | 25 | |
| 20 | 26 |
class CronJob: |
| ... | ... | |
| 25 | 31 |
days = None |
| 26 | 32 |
function = None |
| 27 | 33 | |
| 34 |
logger = logging.getLogger('wcs.cron')
|
|
| 35 |
LONG_JOB_DURATION = 2 * 60 # 2 minutes |
|
| 36 | ||
| 28 | 37 |
def __init__(self, function, name=None, hours=None, minutes=None, weekdays=None, days=None): |
| 29 | 38 |
self.function = function |
| 30 | 39 |
self.name = name |
| ... | ... | |
| 33 | 42 |
self.weekdays = weekdays |
| 34 | 43 |
self.days = days |
| 35 | 44 | |
| 45 |
@contextmanager |
|
| 46 |
def log_long_job(self, message=None): |
|
| 47 |
start = perf_counter() |
|
| 48 |
yield |
|
| 49 |
duration = perf_counter() - start |
|
| 50 |
if duration > self.LONG_JOB_DURATION: |
|
| 51 |
minutes = int(duration / 60) |
|
| 52 |
if message: |
|
| 53 |
self.log('%s: running on "%s" took %d minutes' % (self.name, message, minutes))
|
|
| 54 |
else: |
|
| 55 |
self.log('long job: %s (took %s minutes)' % (self.name, minutes))
|
|
| 56 | ||
| 57 |
def log(self, message): |
|
| 58 |
self.logger.info('[tenant %s] %s', get_publisher().tenant.hostname, message)
|
|
| 59 | ||
| 36 | 60 | |
| 37 | 61 |
def cron_worker(publisher, now, job_name=None): |
| 38 | 62 |
# reindex user and formdata if needed (should only be run once) |
| ... | ... | |
| 66 | 90 |
for extra_source in publisher.extra_sources: |
| 67 | 91 |
publisher.substitutions.feed(extra_source(publisher, None)) |
| 68 | 92 |
try: |
| 69 |
job.function(publisher) |
|
| 93 |
with job.log_long_job(): |
|
| 94 |
if 'job' in inspect.getargspec(job.function).args: |
|
| 95 |
job.function(publisher, job=job) |
|
| 96 |
else: |
|
| 97 |
job.function(publisher) |
|
| 70 | 98 |
except Exception as e: |
| 71 | 99 |
publisher.record_error(exception=e, context='[CRON]', notify=True) |
| wcs/qommon/management/commands/cron.py | ||
|---|---|---|
| 14 | 14 |
# You should have received a copy of the GNU General Public License |
| 15 | 15 |
# along with this program; if not, see <http://www.gnu.org/licenses/>. |
| 16 | 16 | |
| 17 |
import logging |
|
| 17 | 18 |
import os |
| 18 | 19 |
import tempfile |
| 19 | 20 |
import time |
| ... | ... | |
| 29 | 30 | |
| 30 | 31 |
class Command(BaseCommand): |
| 31 | 32 |
help = 'Execute cronjobs' |
| 33 |
logger = logging.getLogger('wcs.cron')
|
|
| 32 | 34 | |
| 33 | 35 |
def add_arguments(self, parser): |
| 34 | 36 |
parser.set_defaults(verbosity=0) |
| ... | ... | |
| 46 | 48 |
if verbosity > 1: |
| 47 | 49 |
print('Command is ignored because DISABLE_CRON_JOBS is set in settings')
|
| 48 | 50 |
return |
| 51 |
offset = ord(settings.SECRET_KEY[-1]) % 60 |
|
| 52 |
self.logger.info('starting cron (minutes offset is %s)', offset)
|
|
| 49 | 53 |
lockfile = os.path.join(tempfile.gettempdir(), 'wcs-cron-in-progress.lock') |
| 50 | 54 |
if options.get('domain'):
|
| 51 | 55 |
domains = [options.get('domain')]
|
| ... | ... | |
| 67 | 71 |
continue |
| 68 | 72 |
if verbosity > 1: |
| 69 | 73 |
print('cron work on %s' % hostname)
|
| 74 |
self.logger.info('[tenant %s] start', hostname)
|
|
| 70 | 75 |
cron_worker(publisher, now, job_name=options.get('job_name'))
|
| 71 | 76 |
if verbosity > 2: |
| 72 | 77 |
print('cron end (release lock %s)' % lockfile)
|
| 73 |
- |
|