def test_retry(self):
job = ShellJob(name='some_job')
# Empty history.
self.assertFalse(job.retry())
# History with a successful execution.
record = ExecutionRecord(instance=123, exit_code=0)
job.history.append(record)
self.assertRaises(AssertionError, job.retry)
# History with too many failures.
record = ExecutionRecord(instance=1234, exit_code=1)
job.history.append(record)
self.assertFalse(job.retry())
# History without too many failures.
job.max_attempts = 2
self.assertTrue(job.retry())
# History with too many failures in a different instance.
job.history.append(record)
record = ExecutionRecord(instance=12345, exit_code=1)
job.history.append(record)
self.assertTrue(job.retry())
def test_customize_command(self):
job = ShellJob(name='some_job',
inputs=['some_input', 'some_other_input'])
some_event = Event(attributes={'some_attr': 'some_value'})
some_other_event = Event(
attributes={
'some_attr': 'some_other_value',
'yet_another_attr': 'yet_another_value'
})
execution_record = ExecutionRecord(instance=123, start_time=10)
execution_record.events = [some_event, some_other_event]
job.history = [execution_record]
# Empty command.
job.command = ''
self.assertEqual('', job.customize_command())
# Command with no attributes.
job.command = 'some_command'
self.assertEqual('some_command', job.customize_command())
# Command with attributes.
job.command = ('%(non_existent_attr)s %(some_attr)s '
'%(yet_another_attr)s')
self.assertEqual(' some_value,some_other_value yet_another_value',
job.customize_command())
# Command with percentage marks.
job.command = ('%% some_command')
self.assertEqual('% some_command', job.customize_command())
def test_customize_command(self):
job = ShellJob(name='some_job',
inputs=['some_input', 'some_other_input'])
some_event = Event(attributes={'some_attr': 'some_value'})
some_other_event = Event(attributes={
'some_attr': 'some_other_value',
'yet_another_attr': 'yet_another_value'})
execution_record = ExecutionRecord(instance=123, start_time=10)
execution_record.events = [some_event, some_other_event]
job.history = [execution_record]
# Empty command.
job.command = ''
self.assertEqual('', job.customize_command())
# Command with no attributes.
job.command = 'some_command'
self.assertEqual('some_command', job.customize_command())
# Command with attributes.
job.command = ('%(non_existent_attr)s %(some_attr)s '
'%(yet_another_attr)s')
self.assertEqual(' some_value,some_other_value yet_another_value',
job.customize_command())
# Command with percentage marks.
job.command = ('%% some_command')
self.assertEqual('% some_command', job.customize_command())
def test_execute_cleanup(self, subprocess_mock):
self._executor.job.cleanup_template = 'cleanup %(kill_id)s'
execution_record = ExecutionRecord()
execution_record.properties['kill_id'] = ['123', '456']
self._executor.job.history = [execution_record]
self._executor._execute_cleanup()
env = os.environ.copy()
env.pop('DJANGO_SETTINGS_MODULE', None)
subprocess_mock.assert_called_with('cleanup 123,456',
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
shell=True,
env=env,
preexec_fn=os.setsid)
def test_execute_cleanup(self, subprocess_mock):
self._executor.job.cleanup_template = 'cleanup %(kill_id)s'
execution_record = ExecutionRecord()
execution_record.properties['kill_id'] = ['123', '456']
self._executor.job.history = [execution_record]
self._executor._execute_cleanup()
env = os.environ.copy()
env.pop('DJANGO_SETTINGS_MODULE', None)
subprocess_mock.assert_called_with('cleanup 123,456',
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
shell=True,
env=env,
preexec_fn=os.setsid)
def _add_history_to_owned_token(self):
job = pickle.loads(self._worker._owned_job_token.data)
execution_record = ExecutionRecord(start_time=123456,
end_time=1234567,
exit_code=0)
job.history.append(execution_record)
self._worker._owned_job_token.data = pickle.dumps(job)
def test_process_log_line(self):
job = ShellJob(name='some_job',
command="echo ok",
emails=['*****@*****.**'],
warn_timeout_sec=10,
abort_timeout_sec=20)
executor = ShellJobExecutor('some_workflow', '123', 'some_job', job,
self._data_builder, self._emailer)
import time
execution_record = ExecutionRecord(instance=123456,
start_time=time.time())
executor.job.history.append(execution_record)
executor._process_log_line("PINBALL:kv_job_url=j_id1|j_url1\n")
executor._process_log_line("PINBALL:kv_job_url=j_id2|j_url2\n")
executor._process_log_line("PINBALL:kv_job_url=j_id2|j_url2\n")
executor._process_log_line("PINBALL:kill_id=qubole1/123\n")
executor._process_log_line("PINBALL:kill_id=qubole2/456\n")
executor._process_log_line("PINBALL:kill_id=qubole1/123\n")
erp = executor._get_last_execution_record().properties
self.assertEqual(len(erp), 2)
self.assertIn('kv_job_url', erp.keys())
self.assertEqual(type(erp['kv_job_url']), list)
self.assertEqual(len(erp['kv_job_url']), 2)
self.assertEqual(erp['kv_job_url'], ['j_id1|j_url1', 'j_id2|j_url2'])
self.assertIn('kill_id', erp.keys())
self.assertEqual(type(erp['kill_id']), list)
self.assertEqual(len(erp['kill_id']), 2)
self.assertEqual(erp['kill_id'], ['qubole1/123', 'qubole2/456'])
def _from_job(workflow, instance, job_name, job, data_builder, emailer):
execution_record = ExecutionRecord(start_time=123456,
end_time=1234567,
exit_code=0)
executed_job = copy.copy(job)
executed_job.history.append(execution_record)
job_executor = mock.Mock()
job_executor.job = executed_job
job_executor.prepare.return_value = True
job_executor.execute.return_value = True
return job_executor
def _add_active_workflow_tokens(self):
"""Add some active workflow tokens.
The job dependencies form a complete binary tree turned upside down.
I.e., each job has two parents.
"""
self._store = EphemeralStore()
version = 1
for level in range(AnalyzerTestCase._NUM_LEVELS):
jobs_at_level = 2**(AnalyzerTestCase._NUM_LEVELS - level - 1)
for job_index in range(jobs_at_level):
job_name = 'job_%d_%d' % (level, job_index)
event_name = Name(workflow='some_workflow',
instance='123',
job=job_name,
event='some_event')
if level == 0:
inputs = [
Name.WORKFLOW_START_INPUT,
Name.WORKFLOW_START_INPUT + '_prime'
]
event_name.input = Name.WORKFLOW_START_INPUT
else:
inputs = [
'job_%d_%d' % (level - 1, 2 * job_index),
'job_%d_%d' % (level - 1, 2 * job_index + 1)
]
event_name.input = 'job_%d_%d' % (level - 1, 2 * job_index)
if level == AnalyzerTestCase._NUM_LEVELS - 1:
outputs = []
else:
outputs = ['job_%d_%d' % (level + 1, job_index / 2)]
job = ShellJob(name=job_name,
inputs=inputs,
outputs=outputs,
command='some_command')
job.history.append(ExecutionRecord())
name = Name(workflow='some_workflow',
instance='123',
job_state=Name.WAITING_STATE,
job=job_name)
job_token = Token(version=version,
name=name.get_job_token_name(),
priority=10,
data=pickle.dumps(job))
version += 1
event = Event('some_event')
event_token = Token(version=version,
name=event_name.get_event_token_name(),
priority=10,
data=pickle.dumps(event))
self._store.commit_tokens([job_token, event_token])
def test_token_lost(self, open_mock, get_s3_key_mock):
file_mock = mock.MagicMock()
open_mock.return_value = file_mock
file_mock.__enter__.return_value = file_mock
s3_key_mock = mock.MagicMock()
get_s3_key_mock.return_value = s3_key_mock
s3_key_mock.__enter__.return_value = s3_key_mock
execution_record = ExecutionRecord(start_time=10)
self._executor.job.history = [execution_record]
self.assertFalse(self._executor.prepare())
file_mock.write.assert_called_once_with('executor failed to renew job '
'ownership on time\n')
get_s3_key_mock.assert_called_once_with('s3n://pinball/tmp/pinball_job_logs/'
'some_workflow/123/some_job.10.pinlog')
def _generate_job_token(workflow, instance, job, executions, max_jobs):
if job == 0:
inputs = [Name.WORKFLOW_START_INPUT]
else:
inputs = ['job_%d' % (job - 1)]
if job == max_jobs - 1:
outputs = []
else:
outputs = ['job_%d' % (job + 1)]
shell_job = ShellJob(name='job_%d' % job,
inputs=inputs,
outputs=outputs,
command='some command %d' % job)
for e in range(0, executions):
start_time = 1000000 * workflow + 10000 * instance + 100 * job + e + 1
end_time = start_time + 10 * e + 1
DIR = '/tmp/pinball/logs'
if not os.path.exists(DIR):
os.makedirs(DIR)
LOG_PATTERN = '%s/%%s.%%d.%%s' % DIR
info_log_file = LOG_PATTERN % (job, start_time, 'info')
with open(info_log_file, 'w') as f:
f.write('some info log of execution %d' % e)
error_log_file = LOG_PATTERN % (job, start_time, 'error')
with open(error_log_file, 'w') as f:
f.write('some error log of execution %d' % e)
record = ExecutionRecord(info='some_command %d some_args %d' % (e, e),
instance='instance_%d' % instance,
start_time=start_time,
end_time=end_time,
exit_code=(workflow + instance + e) % 2,
logs={
'info': info_log_file,
'error': error_log_file
})
shell_job.history.append(record)
name = Name(workflow='workflow_%d' % workflow,
instance='instance_%d' % instance,
job_state=Name.WAITING_STATE,
job='job_%d' % job)
return Token(name=name.get_job_token_name(),
version=1000000 * workflow + 10000 * instance + 100 * job,
priority=job,
data=pickle.dumps(shell_job))
def test_get_output_event_tokens(self):
self._post_job_tokens()
self._post_workflow_start_event_token()
self._worker._own_runnable_job_token()
self.assertIsNotNone(self._worker._owned_job_token)
job = pickle.loads(self._worker._owned_job_token.data)
execution_record = ExecutionRecord(start_time=123456,
end_time=1234567,
exit_code=0)
job.history.append(execution_record)
event_tokens = self._worker._get_output_event_tokens(job)
self.assertEqual(1, len(event_tokens))
event_token_name = Name.from_event_token_name(event_tokens[0].name)
expected_prefix = Name(workflow='some_workflow',
instance='12345',
job='child_job',
input_name='parent_job').get_input_prefix()
self.assertEqual(expected_prefix, event_token_name.get_input_prefix())
def test_move_job_token_to_waiting(self):
self._post_job_tokens()
self._post_workflow_start_event_token()
self._worker._own_runnable_job_token()
job = pickle.loads(self._worker._owned_job_token.data)
execution_record = ExecutionRecord(start_time=123456,
end_time=1234567,
exit_code=0)
job.history.append(execution_record)
self._worker._owned_job_token.data = pickle.dumps(job)
self._worker._move_job_token_to_waiting(job, True)
parent_token = self._get_token(
Name(workflow='some_workflow',
instance='12345',
job_state=Name.WAITING_STATE,
job='parent_job').get_job_token_name())
job = pickle.loads(parent_token.data)
self.assertEqual(1, len(job.history))
self.assertEqual(execution_record.start_time,
job.history[0].start_time)
def test_check_timeout_noop(self, time_mock):
execution_record = ExecutionRecord(start_time=10)
self._executor.job.history = [execution_record]
time_mock.return_value = 15
self._executor._check_timeouts()
self.assertEqual(
0, self._emailer.send_job_timeout_warning_message.call_count)
time_mock.return_value = 25
self._data_builder.get_schedule.return_value = None
job_execution_data = mock.Mock()
self._data_builder.get_execution.return_value = job_execution_data
self._executor._check_timeouts()
self._data_builder.get_schedule.assert_called_once_with(
'some_workflow')
self._data_builder.get_execution.assert_called_once_with(
'some_workflow', '123', 'some_job', 0)
self._emailer.send_job_timeout_warning_message.assert_called_once_with(
['*****@*****.**'], job_execution_data)
time_mock.return_value = 35
self._executor._check_timeouts()
self.assertTrue(self._executor._aborted)
def test_execute_env_var(self, open_mock, exists_mock, get_s3_key_mock):
file_mock = mock.MagicMock()
open_mock.return_value = file_mock
file_mock.__enter__.return_value = file_mock
s3_key_mock = mock.MagicMock()
get_s3_key_mock.return_value = s3_key_mock
s3_key_mock.__enter__.return_value = s3_key_mock
job_name = 'some_job'
workflow_name = 'some_workflow'
instance = '123'
job = ShellJob(name=job_name,
command="echo $PINBALL_WORKFLOW && "
"echo $PINBALL_JOB && "
"echo $PINBALL_INSTANCE && "
"echo $PINBALL_EXECUTION && "
"echo $PINBALL_BASE_URL",
emails=['*****@*****.**'],
warn_timeout_sec=10,
abort_timeout_sec=20)
executor = ShellJobExecutor(workflow_name, instance, job_name,
job, self._data_builder,
self._emailer)
execution_record = ExecutionRecord(instance=instance,
start_time=time.time())
execution_record.end_time = time.time()
execution_record.exit_code = 1
job.history.append(execution_record)
self.assertTrue(executor.prepare())
self.assertTrue(executor.execute())
file_mock.write.assert_has_calls(
[mock.call(workflow_name + '\n'),
mock.call(job_name + '\n'),
mock.call(instance + '\n'),
mock.call('1\n')])
self.assertEqual(len(executor.job.history), 2)
self.assertEqual(get_s3_key_mock.call_count, len(executor.job.history))
latest_execution_record = executor.job.history[1]
self.assertEqual(latest_execution_record.exit_code, 0)
exists_mock.assert_any_call(
'/tmp/pinball_job_logs/{wf}/{inst}'.format(
wf=workflow_name, inst=instance
),
)
exists_mock.assert_any_call(
'/tmp/pinball_job_logs/{wf}/{inst}/some_job.{ts}.stdout'.format(
wf=workflow_name, inst=instance, ts=int(latest_execution_record.start_time)
),
)
exists_mock.assert_any_call(
'/tmp/pinball_job_logs/{wf}/{inst}/some_job.{ts}.stderr'.format(
wf=workflow_name, inst=instance, ts=int(latest_execution_record.start_time)
),
)
