Projet

Général

Profil

0001-misc-add-log-mecanism-for-cron-jobs-57604.patch

Lauréline Guérin, 21 octobre 2021 15:09

Télécharger (9,48 ko)

Voir les différences:

Subject: [PATCH 1/2] misc: add log mecanism for cron jobs (#57604)

 tests/test_publisher.py                | 74 ++++++++++++++++++++++++--
 wcs/qommon/cron.py                     | 32 ++++++++++-
 wcs/qommon/management/commands/cron.py |  5 +-
 3 files changed, 105 insertions(+), 6 deletions(-)
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
-