0001-misc-add-log-mecanism-for-cron-jobs-57604.patch
tests/test_publisher.py | ||
---|---|---|
16 | 16 |
from django.core.management.base import CommandError |
17 | 17 |
from django.http import Http404 |
18 | 18 |
from django.test import override_settings |
19 |
from django.utils.timezone import localtime |
|
19 | 20 |
from quixote import cleanup |
20 | 21 | |
21 | 22 |
from wcs.qommon import get_publisher_class |
... | ... | |
206 | 207 |
assert pub.cfg['sp'] == {'what': 'ever'} |
207 | 208 | |
208 | 209 | |
209 |
def test_cron_command(): |
|
210 |
def test_cron_command(settings):
|
|
210 | 211 |
pub = create_temporary_pub() |
212 | ||
213 |
def clear_log_file(): |
|
214 |
now = localtime() |
|
215 |
with open(os.path.join(pub.APP_DIR, 'cron.log-%s' % now.strftime('%Y%m%d')), 'w'): |
|
216 |
pass |
|
217 | ||
218 |
def get_logs(): |
|
219 |
now = localtime() |
|
220 |
with open(os.path.join(pub.APP_DIR, 'cron.log-%s' % now.strftime('%Y%m%d'))) as fd: |
|
221 |
lines = fd.readlines() |
|
222 |
lines = [line[33:].strip() for line in lines] # 33 chars for date & time |
|
223 |
return lines |
|
224 | ||
225 |
offset = ord(settings.SECRET_KEY[-1]) % 60 |
|
211 | 226 |
with mock.patch('tempfile.gettempdir') as gettempdir: |
212 | 227 |
gettempdir.side_effect = lambda: pub.app_dir |
213 | 228 | |
... | ... | |
221 | 236 |
mock_tenants.return_value = [ |
222 | 237 |
Tenant(os.path.join(pub.app_dir, x)) for x in ('example.net', 'foo.bar', 'something.com') |
223 | 238 |
] |
239 |
clear_log_file() |
|
224 | 240 |
call_command('cron') |
225 | 241 |
assert cron_worker.call_count == 3 |
242 |
assert get_logs() == [ |
|
243 |
'starting cron (minutes offset is %s)' % offset, |
|
244 |
'[tenant example.net] start', |
|
245 |
'[tenant foo.bar] start', |
|
246 |
'[tenant something.com] start', |
|
247 |
] |
|
226 | 248 |
cron_worker.reset_mock() |
249 |
clear_log_file() |
|
227 | 250 |
call_command('cron', domain='example.net') |
228 | 251 |
assert cron_worker.call_count == 1 |
252 |
assert get_logs() == [ |
|
253 |
'starting cron (minutes offset is %s)' % offset, |
|
254 |
'[tenant example.net] start', |
|
255 |
] |
|
229 | 256 |
cron_worker.reset_mock() |
230 | 257 | |
231 | 258 |
# disable cron on something.com |
... | ... | |
238 | 265 |
''' |
239 | 266 |
) |
240 | 267 | |
268 |
clear_log_file() |
|
241 | 269 |
call_command('cron') |
242 | 270 |
assert cron_worker.call_count == 2 |
271 |
assert get_logs() == [ |
|
272 |
'starting cron (minutes offset is %s)' % offset, |
|
273 |
'[tenant example.net] start', |
|
274 |
'[tenant foo.bar] start', |
|
275 |
] |
|
243 | 276 |
cron_worker.reset_mock() |
244 | 277 |
os.unlink(site_options_path) |
245 | 278 | |
... | ... | |
283 | 316 |
# run a specific job |
284 | 317 |
jobs = [] |
285 | 318 | |
286 |
def job1(pub): |
|
319 |
def job1(pub, job=None):
|
|
287 | 320 |
jobs.append('job1') |
288 | 321 | |
289 |
def job2(pub): |
|
322 |
def job2(pub, job=None):
|
|
290 | 323 |
jobs.append('job2') |
291 | 324 | |
292 |
def job3(pub): |
|
325 |
def job3(pub, job=None):
|
|
293 | 326 |
jobs.append('job3') |
327 |
for key in ['foo', 'bar', 'blah']: |
|
328 |
with job.log_long_job(key): |
|
329 |
pass |
|
294 | 330 | |
295 | 331 |
@classmethod |
296 | 332 |
def register_test_cronjobs(cls): |
... | ... | |
303 | 339 |
call_command('cron', job_name='job1', domain='example.net') |
304 | 340 |
assert jobs == [] |
305 | 341 |
get_publisher_class().cronjobs = [] |
342 |
clear_log_file() |
|
306 | 343 |
call_command('cron', job_name='job2', domain='example.net') |
307 | 344 |
assert jobs == ['job2'] |
345 |
assert get_logs() == [ |
|
346 |
'starting cron (minutes offset is %s)' % offset, |
|
347 |
'[tenant example.net] start', |
|
348 |
] |
|
349 |
get_publisher_class().cronjobs = [] |
|
350 |
jobs = [] |
|
351 |
clear_log_file() |
|
352 |
with mock.patch('wcs.qommon.cron.CronJob.LONG_JOB_DURATION', 0): |
|
353 |
call_command('cron', job_name='job2', domain='example.net') |
|
354 |
assert get_logs() == [ |
|
355 |
'starting cron (minutes offset is %s)' % offset, |
|
356 |
'[tenant example.net] start', |
|
357 |
'[tenant example.net] long job: job2 (took 0 minutes)', |
|
358 |
] |
|
359 |
assert jobs == ['job2'] |
|
360 |
get_publisher_class().cronjobs = [] |
|
361 |
jobs = [] |
|
362 |
clear_log_file() |
|
363 |
with mock.patch('wcs.qommon.cron.CronJob.LONG_JOB_DURATION', 0): |
|
364 |
call_command('cron', job_name='job3', domain='example.net') |
|
365 |
assert get_logs() == [ |
|
366 |
'starting cron (minutes offset is %s)' % offset, |
|
367 |
'[tenant example.net] start', |
|
368 |
'[tenant example.net] job3: running on "foo" took 0 minutes', |
|
369 |
'[tenant example.net] job3: running on "bar" took 0 minutes', |
|
370 |
'[tenant example.net] job3: running on "blah" took 0 minutes', |
|
371 |
'[tenant example.net] long job: job3 (took 0 minutes)', |
|
372 |
] |
|
373 |
assert jobs == ['job3'] |
|
308 | 374 | |
309 | 375 | |
310 | 376 |
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 os |
|
18 |
from contextlib import contextmanager |
|
19 |
from time import perf_counter |
|
20 | ||
17 | 21 |
from django.conf import settings |
22 |
from django.utils.timezone import localtime |
|
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 |
LONG_JOB_DURATION = 2 * 60 # 2 minutes |
|
35 | ||
28 | 36 |
def __init__(self, function, name=None, hours=None, minutes=None, weekdays=None, days=None): |
29 | 37 |
self.function = function |
30 | 38 |
self.name = name |
... | ... | |
33 | 41 |
self.weekdays = weekdays |
34 | 42 |
self.days = days |
35 | 43 | |
44 |
@contextmanager |
|
45 |
def log_long_job(self, obj_description=None): |
|
46 |
start = perf_counter() |
|
47 |
yield |
|
48 |
duration = perf_counter() - start |
|
49 |
if duration > self.LONG_JOB_DURATION: |
|
50 |
minutes = int(duration / 60) |
|
51 |
if obj_description: |
|
52 |
self.log('%s: running on "%s" took %d minutes' % (self.name, obj_description, minutes)) |
|
53 |
else: |
|
54 |
self.log('long job: %s (took %s minutes)' % (self.name, minutes)) |
|
55 | ||
56 |
@staticmethod |
|
57 |
def log(message, with_tenant=True): |
|
58 |
tenant_prefix = '' |
|
59 |
now = localtime() |
|
60 |
if with_tenant: |
|
61 |
tenant_prefix = '[tenant %s] ' % get_publisher().tenant.hostname |
|
62 |
with open(os.path.join(get_publisher().APP_DIR, 'cron.log-%s' % now.strftime('%Y%m%d')), 'a+') as fd: |
|
63 |
fd.write('%s %s%s\n' % (now.isoformat(), tenant_prefix, message)) |
|
64 | ||
36 | 65 | |
37 | 66 |
def cron_worker(publisher, now, job_name=None): |
38 | 67 |
# reindex user and formdata if needed (should only be run once) |
... | ... | |
66 | 95 |
for extra_source in publisher.extra_sources: |
67 | 96 |
publisher.substitutions.feed(extra_source(publisher, None)) |
68 | 97 |
try: |
69 |
job.function(publisher) |
|
98 |
with job.log_long_job(): |
|
99 |
job.function(publisher, job=job) |
|
70 | 100 |
except Exception as e: |
71 | 101 |
publisher.record_error(exception=e, context='[CRON]', notify=True) |
wcs/qommon/management/commands/cron.py | ||
---|---|---|
21 | 21 |
from django.conf import settings |
22 | 22 |
from django.core.management.base import BaseCommand, CommandError |
23 | 23 | |
24 |
from wcs.qommon.cron import cron_worker |
|
24 |
from wcs.qommon.cron import CronJob, cron_worker
|
|
25 | 25 |
from wcs.qommon.publisher import get_publisher_class |
26 | 26 |
from wcs.qommon.vendor import locket |
27 | 27 |
from wcs.wf.jump import JUMP_TIMEOUT_INTERVAL |
... | ... | |
59 | 59 |
publisher_class = get_publisher_class() |
60 | 60 |
publisher_class.register_cronjobs() |
61 | 61 |
publisher = publisher_class.create_publisher() |
62 |
offset = ord(settings.SECRET_KEY[-1]) % 60 |
|
63 |
CronJob.log('starting cron (minutes offset is %s)' % offset, with_tenant=False) |
|
62 | 64 |
for hostname in domains: |
63 | 65 |
publisher.set_tenant_by_hostname(hostname) |
64 | 66 |
if publisher.get_site_option('disable_cron_jobs', 'variables'): |
... | ... | |
67 | 69 |
continue |
68 | 70 |
if verbosity > 1: |
69 | 71 |
print('cron work on %s' % hostname) |
72 |
CronJob.log('start') |
|
70 | 73 |
cron_worker(publisher, now, job_name=options.get('job_name')) |
71 | 74 |
if verbosity > 2: |
72 | 75 |
print('cron end (release lock %s)' % lockfile) |
73 |
- |