async def test_custom_serializer():
class Foobar:
def __getstate__(self):
raise TypeError("this doesn't pickle")
def custom_serializer(x):
return b'0123456789'
r1 = serialize_result('foobar', (1, ), {},
1,
123,
True,
Foobar(),
123,
123,
'testing',
'test-queue',
serializer=custom_serializer)
assert r1 == b'0123456789'
r2 = serialize_result(
'foobar',
(Foobar(), ),
{},
1,
123,
True,
Foobar(),
123,
123,
'testing',
'test-queue',
serializer=custom_serializer,
)
assert r2 == b'0123456789'
async def test_cant_unpickle_at_all():
class Foobar:
def __getstate__(self):
raise TypeError("this doesn't pickle")
r1 = serialize_result('foobar', (1,), {}, 1, 123, True, Foobar(), 123, 123, 'testing')
assert isinstance(r1, bytes)
r2 = serialize_result('foobar', (Foobar(),), {}, 1, 123, True, Foobar(), 123, 123, 'testing')
assert r2 is None
async def test_result_pole_delay_dep(arq_redis: ArqRedis):
j = Job('foobar', arq_redis)
r = serialize_result('foobar', (1, ), {}, 1, 123, True, 42, 123, 123,
'testing', 'test-queue')
await arq_redis.set(result_key_prefix + j.job_id, r)
with pytest.warns(
DeprecationWarning,
match=
'"pole_delay" is deprecated, use the correct spelling "poll_delay" instead'
):
assert await j.result(pole_delay=0) == 42
async def job_failed(exc: Exception) -> None:
self.jobs_failed += 1
result_data_ = serialize_result(
function=function_name,
args=args,
kwargs=kwargs,
job_try=job_try,
enqueue_time_ms=enqueue_time_ms,
success=False,
result=exc,
start_ms=start_ms,
finished_ms=timestamp_ms(),
ref=f'{job_id}:{function_name}',
serializer=self.job_serializer,
)
await asyncio.shield(self.abort_job(job_id, result_data_))
async def run_job(self, job_id: str, score: int) -> None: # noqa: C901
start_ms = timestamp_ms()
coros = (
self.pool.get(job_key_prefix + job_id, encoding=None),
self.pool.incr(retry_key_prefix + job_id),
self.pool.expire(retry_key_prefix + job_id, 88400),
)
if self.allow_abort_jobs:
abort_job, v, job_try, _ = await asyncio.gather(
self.pool.zrem(abort_jobs_ss, job_id), *coros)
else:
v, job_try, _ = await asyncio.gather(*coros)
abort_job = False
function_name, enqueue_time_ms = '<unknown>', 0
args: Tuple[Any, ...] = ()
kwargs: Dict[Any, Any] = {}
async def job_failed(exc: BaseException) -> None:
self.jobs_failed += 1
result_data_ = serialize_result(
function=function_name,
args=args,
kwargs=kwargs,
job_try=job_try,
enqueue_time_ms=enqueue_time_ms,
success=False,
result=exc,
start_ms=start_ms,
finished_ms=timestamp_ms(),
ref=f'{job_id}:{function_name}',
serializer=self.job_serializer,
queue_name=self.queue_name,
)
await asyncio.shield(self.finish_failed_job(job_id, result_data_))
if not v:
logger.warning('job %s expired', job_id)
return await job_failed(JobExecutionFailed('job expired'))
try:
function_name, args, kwargs, enqueue_job_try, enqueue_time_ms = deserialize_job_raw(
v, deserializer=self.job_deserializer)
except SerializationError as e:
logger.exception('deserializing job %s failed', job_id)
return await job_failed(e)
if abort_job:
t = (timestamp_ms() - enqueue_time_ms) / 1000
logger.info('%6.2fs ⊘ %s:%s aborted before start', t, job_id,
function_name)
return await job_failed(asyncio.CancelledError())
try:
function: Union[Function, CronJob] = self.functions[function_name]
except KeyError:
logger.warning('job %s, function %r not found', job_id,
function_name)
return await job_failed(
JobExecutionFailed(f'function {function_name!r} not found'))
if hasattr(function, 'next_run'):
# cron_job
ref = function_name
keep_in_progress: Optional[float] = keep_cronjob_progress
else:
ref = f'{job_id}:{function_name}'
keep_in_progress = None
if enqueue_job_try and enqueue_job_try > job_try:
job_try = enqueue_job_try
await self.pool.setex(retry_key_prefix + job_id, 88400,
str(job_try))
max_tries = self.max_tries if function.max_tries is None else function.max_tries
if job_try > max_tries:
t = (timestamp_ms() - enqueue_time_ms) / 1000
logger.warning('%6.2fs ! %s max retries %d exceeded', t, ref,
max_tries)
self.jobs_failed += 1
result_data = serialize_result(
function_name,
args,
kwargs,
job_try,
enqueue_time_ms,
False,
JobExecutionFailed(f'max {max_tries} retries exceeded'),
start_ms,
timestamp_ms(),
ref,
self.queue_name,
serializer=self.job_serializer,
)
return await asyncio.shield(
self.finish_failed_job(job_id, result_data))
result = no_result
exc_extra = None
finish = False
timeout_s = self.job_timeout_s if function.timeout_s is None else function.timeout_s
incr_score: Optional[int] = None
job_ctx = {
'job_id': job_id,
'job_try': job_try,
'enqueue_time': ms_to_datetime(enqueue_time_ms),
'score': score,
}
ctx = {**self.ctx, **job_ctx}
start_ms = timestamp_ms()
success = False
try:
s = args_to_string(args, kwargs)
extra = f' try={job_try}' if job_try > 1 else ''
if (start_ms - score) > 1200:
extra += f' delayed={(start_ms - score) / 1000:0.2f}s'
logger.info('%6.2fs → %s(%s)%s',
(start_ms - enqueue_time_ms) / 1000, ref, s, extra)
self.job_tasks[job_id] = task = self.loop.create_task(
function.coroutine(ctx, *args, **kwargs))
cancel_handler = self.loop.call_at(self.loop.time() + timeout_s,
task.cancel)
# run repr(result) and extra inside try/except as they can raise exceptions
try:
result = await task
except (Exception, asyncio.CancelledError) as e:
exc_extra = getattr(e, 'extra', None)
if callable(exc_extra):
exc_extra = exc_extra()
raise
else:
result_str = '' if result is None else truncate(repr(result))
finally:
del self.job_tasks[job_id]
cancel_handler.cancel()
except (Exception, asyncio.CancelledError) as e:
finished_ms = timestamp_ms()
t = (finished_ms - start_ms) / 1000
if self.retry_jobs and isinstance(e, Retry):
incr_score = e.defer_score
logger.info('%6.2fs ↻ %s retrying job in %0.2fs', t, ref,
(e.defer_score or 0) / 1000)
if e.defer_score:
incr_score = e.defer_score + (timestamp_ms() - score)
self.jobs_retried += 1
elif job_id in self.aborting_tasks and isinstance(
e, asyncio.CancelledError):
logger.info('%6.2fs ⊘ %s aborted', t, ref)
result = e
finish = True
self.aborting_tasks.remove(job_id)
self.jobs_failed += 1
elif self.retry_jobs and isinstance(
e, (asyncio.CancelledError, RetryJob)):
logger.info('%6.2fs ↻ %s cancelled, will be run again', t, ref)
self.jobs_retried += 1
else:
logger.exception('%6.2fs ! %s failed, %s: %s',
t,
ref,
e.__class__.__name__,
e,
extra={'extra': exc_extra})
result = e
finish = True
self.jobs_failed += 1
else:
success = True
finished_ms = timestamp_ms()
logger.info('%6.2fs ← %s ● %s', (finished_ms - start_ms) / 1000,
ref, result_str)
finish = True
self.jobs_complete += 1
keep_result_forever = (self.keep_result_forever
if function.keep_result_forever is None else
function.keep_result_forever)
result_timeout_s = self.keep_result_s if function.keep_result_s is None else function.keep_result_s
result_data = None
if result is not no_result and (keep_result_forever
or result_timeout_s > 0):
result_data = serialize_result(
function_name,
args,
kwargs,
job_try,
enqueue_time_ms,
success,
result,
start_ms,
finished_ms,
ref,
self.queue_name,
serializer=self.job_serializer,
)
await asyncio.shield(
self.finish_job(
job_id,
finish,
result_data,
result_timeout_s,
keep_result_forever,
incr_score,
keep_in_progress,
))
async def run_job(self, job_id, score): # noqa: C901
start_ms = timestamp_ms()
v, job_try, _ = await asyncio.gather(
self.pool.get(job_key_prefix + job_id, encoding=None),
self.pool.incr(retry_key_prefix + job_id),
self.pool.expire(retry_key_prefix + job_id, 88400),
)
function_name, args, kwargs, enqueue_time_ms = '<unknown>', (), {}, 0
async def job_failed(exc: Exception):
self.jobs_failed += 1
result_data_ = serialize_result(
function=function_name,
args=args,
kwargs=kwargs,
job_try=job_try,
enqueue_time_ms=enqueue_time_ms,
success=False,
result=exc,
start_ms=start_ms,
finished_ms=timestamp_ms(),
ref=f'{job_id}:{function_name}',
serializer=self.job_serializer,
)
await asyncio.shield(self.abort_job(job_id, result_data_))
if not v:
logger.warning('job %s expired', job_id)
return await job_failed(JobExecutionFailed('job expired'))
try:
function_name, args, kwargs, enqueue_job_try, enqueue_time_ms = deserialize_job_raw(
v, deserializer=self.job_deserializer
)
except SerializationError as e:
logger.exception('deserializing job %s failed', job_id)
return await job_failed(e)
try:
function: Union[Function, CronJob] = self.functions[function_name]
except KeyError:
logger.warning('job %s, function %r not found', job_id, function_name)
return await job_failed(JobExecutionFailed(f'function {function_name!r} not found'))
if hasattr(function, 'next_run'):
# cron_job
ref = function_name
else:
ref = f'{job_id}:{function_name}'
if enqueue_job_try and enqueue_job_try > job_try:
job_try = enqueue_job_try
await self.pool.setex(retry_key_prefix + job_id, 88400, str(job_try))
max_tries = self.max_tries if function.max_tries is None else function.max_tries
if job_try > max_tries:
t = (timestamp_ms() - enqueue_time_ms) / 1000
logger.warning('%6.2fs ! %s max retries %d exceeded', t, ref, max_tries)
self.jobs_failed += 1
result_data = serialize_result(
function_name,
args,
kwargs,
job_try,
enqueue_time_ms,
False,
JobExecutionFailed(f'max {max_tries} retries exceeded'),
start_ms,
timestamp_ms(),
ref,
serializer=self.job_serializer,
)
return await asyncio.shield(self.abort_job(job_id, result_data))
result = no_result
exc_extra = None
finish = False
timeout_s = self.job_timeout_s if function.timeout_s is None else function.timeout_s
incr_score = None
job_ctx = {
'job_id': job_id,
'job_try': job_try,
'enqueue_time': ms_to_datetime(enqueue_time_ms),
'score': score,
}
ctx = {**self.ctx, **job_ctx}
start_ms = timestamp_ms()
success = False
try:
s = args_to_string(args, kwargs)
extra = f' try={job_try}' if job_try > 1 else ''
if (start_ms - score) > 1200:
extra += f' delayed={(start_ms - score) / 1000:0.2f}s'
logger.info('%6.2fs → %s(%s)%s', (start_ms - enqueue_time_ms) / 1000, ref, s, extra)
# run repr(result) and extra inside try/except as they can raise exceptions
try:
async with async_timeout.timeout(timeout_s):
result = await function.coroutine(ctx, *args, **kwargs)
except Exception as e:
exc_extra = getattr(e, 'extra', None)
if callable(exc_extra):
exc_extra = exc_extra()
raise
else:
result_str = '' if result is None else truncate(repr(result))
except Exception as e:
finished_ms = timestamp_ms()
t = (finished_ms - start_ms) / 1000
if self.retry_jobs and isinstance(e, Retry):
incr_score = e.defer_score
logger.info('%6.2fs ↻ %s retrying job in %0.2fs', t, ref, (e.defer_score or 0) / 1000)
if e.defer_score:
incr_score = e.defer_score + (timestamp_ms() - score)
self.jobs_retried += 1
elif self.retry_jobs and isinstance(e, asyncio.CancelledError):
logger.info('%6.2fs ↻ %s cancelled, will be run again', t, ref)
self.jobs_retried += 1
else:
logger.exception(
'%6.2fs ! %s failed, %s: %s', t, ref, e.__class__.__name__, e, extra={'extra': exc_extra}
)
result = e
finish = True
self.jobs_failed += 1
else:
success = True
finished_ms = timestamp_ms()
logger.info('%6.2fs ← %s ● %s', (finished_ms - start_ms) / 1000, ref, result_str)
finish = True
self.jobs_complete += 1
result_timeout_s = self.keep_result_s if function.keep_result_s is None else function.keep_result_s
result_data = None
if result is not no_result and result_timeout_s > 0:
result_data = serialize_result(
function_name,
args,
kwargs,
job_try,
enqueue_time_ms,
success,
result,
start_ms,
finished_ms,
ref,
serializer=self.job_serializer,
)
await asyncio.shield(self.finish_job(job_id, finish, result_data, result_timeout_s, incr_score))
