def simulate_logging(self,
execution_id=None,
user_name=None,
user_id=None,
script_name=None,
command=None,
log_lines=None,
start_time_millis=None,
exit_code=0,
write_post_execution_info=True):
output_stream = Observable()
execution_id = self.start_logging(command=command,
execution_id=execution_id,
output_stream=output_stream,
script_name=script_name,
start_time_millis=start_time_millis,
user_id=user_id,
user_name=user_name)
if log_lines:
for line in log_lines:
output_stream.push(line + '\n')
output_stream.close()
if write_post_execution_info:
self.logging_service.write_post_execution_info(execution_id, exit_code)
def __init__(self, command, working_directory):
self.process = None
self.working_directory = working_directory
self.command = command
self.finish_listeners = []
self.output_stream = Observable()
def test_write_post_execution_info_before_log_closed(self):
output_stream = Observable()
execution_id = '999'
self.start_logging(output_stream, execution_id=execution_id)
output_stream.push('abcde')
self.logging_service.write_post_execution_info(execution_id, 255)
old_entry = self.logging_service.find_history_entry(execution_id)
self.validate_history_entry(old_entry, id=execution_id, exit_code=None)
output_stream.close()
new_entry = self.logging_service.find_history_entry(execution_id)
self.validate_history_entry(new_entry, id=execution_id, exit_code=255)
def simulate_logging(self,
execution_id=None,
user_name=None,
user_id=None,
script_name=None,
command=None,
log_lines=None,
start_time_millis=None,
exit_code=0,
write_post_execution_info=True):
output_stream = Observable()
execution_id = self.start_logging(command=command,
execution_id=execution_id,
output_stream=output_stream,
script_name=script_name,
start_time_millis=start_time_millis,
user_id=user_id,
user_name=user_name)
if log_lines:
for line in log_lines:
output_stream.push(line + '\n')
output_stream.close()
if write_post_execution_info:
self.logging_service.write_post_execution_info(execution_id, exit_code)
def simulate_logging(self,
execution_id=None,
user='******',
script_name='my_script',
command='cmd',
log_lines=None,
start_time_millis=None):
if not execution_id:
execution_id = str(uuid.uuid1())
output_stream = Observable()
all_audit_names = {}
all_audit_names[audit_utils.AUTH_USERNAME] = user
self.logging_service.start_logging(
execution_id,
user,
script_name,
command,
output_stream,
self.post_info_provider,
all_audit_names,
start_time_millis)
if log_lines:
for line in log_lines:
output_stream.push(line + '\n')
output_stream.close()
def test_write_post_execution_info_before_log_closed(self):
output_stream = Observable()
execution_id = '999'
self.start_logging(output_stream, execution_id=execution_id)
output_stream.push('abcde')
self.logging_service.write_post_execution_info(execution_id, 255)
old_entry = self.logging_service.find_history_entry(execution_id, 'userX')
self.validate_history_entry(old_entry, id=execution_id, exit_code=None)
output_stream.close()
new_entry = self.logging_service.find_history_entry(execution_id, 'userX')
self.validate_history_entry(new_entry, id=execution_id, exit_code=255)
def setUp(self):
self.output_stream = Observable()
test_utils.setup()
super().setUp()
class TestScriptOutputLogging(unittest.TestCase):
def test_open(self):
self.output_logger = self.create_logger()
self.output_logger.start()
self.assertTrue(self.is_file_opened())
def test_close(self):
self.output_logger = self.create_logger()
self.output_logger.start()
self.output_stream.close()
self.assertFalse(self.is_file_opened())
def test_simple_log(self):
self.output_logger = self.create_logger()
self.output_logger.start()
self.output_stream.push('some text')
self.output_stream.close()
self.assertEqual(self.read_log(), 'some text')
def test_multiple_logs(self):
self.output_logger = self.create_logger()
self.output_logger.start()
self.output_stream.push('some text')
self.output_stream.push('\nand a new line')
self.output_stream.push(' with some long long text')
self.output_stream.close()
self.assertEqual(self.read_log(),
'some text\nand a new line with some long long text')
def test_log_without_open(self):
self.output_logger = self.create_logger()
self.output_stream.push('some text')
self.assertIsNone(self.read_log())
def create_logger(self):
self.file_path = os.path.join(test_utils.temp_folder,
'TestScriptOutputLogging.log')
self.logger = ScriptOutputLogger(self.file_path, self.output_stream)
return self.logger
def read_log(self):
if self.file_path and os.path.exists(self.file_path):
return file_utils.read_file(self.file_path)
return None
def is_file_opened(self):
if self.output_logger.log_file:
return not self.output_logger.log_file.closed
return False
def setUp(self):
self.output_stream = Observable()
test_utils.setup()
super().setUp()
def tearDown(self):
self.output_stream.close()
self.output_logger._close()
test_utils.cleanup()
super().tearDown()
class ProcessWrapper(metaclass=abc.ABCMeta):
def __init__(self, command, working_directory):
self.process = None
self.working_directory = working_directory
self.command = command
self.finish_listeners = []
self.output_stream = Observable()
def start(self):
self.start_execution(self.command, self.working_directory)
read_output_thread = threading.Thread(target=self.pipe_process_output)
read_output_thread.start()
notify_finish_thread = threading.Thread(target=self.notify_finished)
notify_finish_thread.start()
@abc.abstractmethod
def pipe_process_output(self):
pass
@abc.abstractmethod
def start_execution(self, command, working_directory):
pass
@abc.abstractmethod
def write_to_input(self, value):
pass
@abc.abstractmethod
def wait_finish(self):
pass
def _get_process_id(self):
return self.process.pid
def is_finished(self):
return self.process.poll() is not None
def get_return_code(self):
return self.process.returncode
def _write_script_output(self, text):
self.output_stream.push(text)
def stop(self):
if not self.is_finished():
if not os_utils.is_win():
group_id = os.getpgid(self._get_process_id())
os.killpg(group_id, signal.SIGTERM)
class KillChildren(object):
def finished(self):
try:
os.killpg(group_id, signal.SIGKILL)
except ProcessLookupError:
# probably there are no children left
pass
self.add_finish_listener(KillChildren())
else:
self.process.terminate()
self._write_script_output('\n>> STOPPED BY USER\n')
def kill(self):
if not self.is_finished():
if not os_utils.is_win():
group_id = os.getpgid(self._get_process_id())
os.killpg(group_id, signal.SIGKILL)
self._write_script_output('\n>> KILLED\n')
else:
subprocess.Popen("taskkill /F /T /PID " + self._get_process_id())
def add_finish_listener(self, listener):
self.finish_listeners.append(listener)
if self.is_finished():
self.notify_finished()
def notify_finished(self):
self.wait_finish()
for listener in self.finish_listeners:
listener.finished()
class TestScriptOutputLogging(unittest.TestCase):
def test_open(self):
self.output_logger = self.create_logger()
self.output_logger.start()
self.assertTrue(self.is_file_opened())
def test_close(self):
self.output_logger = self.create_logger()
self.output_logger.start()
self.output_stream.close()
self.assertFalse(self.is_file_opened())
def test_simple_log(self):
self.output_logger = self.create_logger()
self.output_logger.start()
self.output_stream.push('some text')
self.output_stream.close()
self.assertEqual(self.read_log(), 'some text')
def test_multiple_logs(self):
self.output_logger = self.create_logger()
self.output_logger.start()
self.output_stream.push('some text')
self.output_stream.push('\nand a new line')
self.output_stream.push(' with some long long text')
self.output_stream.close()
self.assertEqual(self.read_log(), 'some text\nand a new line with some long long text')
def test_log_without_open(self):
self.output_logger = self.create_logger()
self.output_stream.push('some text')
self.assertIsNone(self.read_log())
def test_caret_return(self):
self.output_logger = self.create_logger()
self.output_logger.start()
self.output_stream.push('some text\r')
self.output_stream.push('another text')
self.output_stream.close()
self.assertEqual(self.read_log(), 'some text\ranother text')
def create_logger(self):
self.file_path = os.path.join(test_utils.temp_folder, 'TestScriptOutputLogging.log')
self.logger = ScriptOutputLogger(self.file_path, self.output_stream)
return self.logger
def read_log(self):
if self.file_path and os.path.exists(self.file_path):
return file_utils.read_file(self.file_path, keep_newlines=True)
return None
def is_file_opened(self):
if self.output_logger.log_file:
return not self.output_logger.log_file.closed
return False
def setUp(self):
self.output_stream = Observable()
test_utils.setup()
super().setUp()
def tearDown(self):
self.output_stream.close()
self.output_logger._close()
test_utils.cleanup()
super().tearDown()
def setUp(self):
self.output_stream = Observable()
test_utils.setup()
super().setUp()
def create_observable(self):
observable = Observable()
self._track(observable)
return observable
class TestObservable(unittest.TestCase):
def test_no_updates(self):
observable = self.create_observable()
observable.close()
self.assertEqual([], observable.get_old_data())
def test_single_update(self):
observable = self.create_observable()
observer = SimpleStoringObserver()
observable.subscribe(observer)
observable.push('test')
self.assertEqual(['test'], observer.data)
def test_multiple_updates(self):
observable = self.create_observable()
observer = SimpleStoringObserver()
observable.subscribe(observer)
observable.push('1')
observable.push('2')
observable.push('3')
self.assertEqual(['1', '2', '3'], observer.data)
def test_multiple_observers_single_update(self):
observable = self.create_observable()
observer1 = SimpleStoringObserver()
observable.subscribe(observer1)
observer2 = SimpleStoringObserver()
observable.subscribe(observer2)
observer3 = SimpleStoringObserver()
observable.subscribe(observer3)
observable.push('message')
self.assertEqual(['message'], observer1.data)
self.assertEqual(['message'], observer2.data)
self.assertEqual(['message'], observer3.data)
def test_multiple_observers_multiple_updates(self):
observable = self.create_observable()
observer1 = SimpleStoringObserver()
observable.subscribe(observer1)
observer2 = SimpleStoringObserver()
observable.subscribe(observer2)
observer3 = SimpleStoringObserver()
observable.subscribe(observer3)
observable.push('message')
observable.push('and another one')
observable.push('and the third')
self.assertEqual(['message', 'and another one', 'and the third'],
observer1.data)
self.assertEqual(['message', 'and another one', 'and the third'],
observer2.data)
self.assertEqual(['message', 'and another one', 'and the third'],
observer3.data)
def test_single_update_late_subscription(self):
observable = self.create_observable()
observable.push('test')
observer = SimpleStoringObserver()
observable.subscribe(observer)
self.assertEqual(['test'], observer.data)
def test_multiple_updates_late_subscription(self):
observable = self.create_observable()
observable.push('test1')
observable.push('test2')
observable.push('test3')
observer = SimpleStoringObserver()
observable.subscribe(observer)
self.assertEqual(['test1', 'test2', 'test3'], observer.data)
def test_close(self):
observable = self.create_observable()
observable.push('test')
observer = SimpleStoringObserver()
observable.subscribe(observer)
observable.close()
self.assertTrue(observer.closed)
def test_close_multiple_subscribers(self):
observable = self.create_observable()
observable.push('test')
observer1 = SimpleStoringObserver()
observable.subscribe(observer1)
observer2 = SimpleStoringObserver()
observable.subscribe(observer2)
observable.close()
self.assertTrue(observer1.closed)
self.assertTrue(observer2.closed)
def test_close_late_subscription(self):
observable = self.create_observable()
observable.push('test')
observable.close()
observer = SimpleStoringObserver()
observable.subscribe(observer)
self.assertTrue(observer.closed)
def test_close_multiple_subscribers_late_subscription(self):
observable = self.create_observable()
observable.push('test')
observable.close()
observer1 = SimpleStoringObserver()
observable.subscribe(observer1)
observer2 = SimpleStoringObserver()
observable.subscribe(observer2)
self.assertTrue(observer1.closed)
self.assertTrue(observer2.closed)
def test_wait_close(self):
observable = self.create_observable()
thread = threading.Thread(target=self.close_delayed,
args=[observable],
daemon=True)
thread.start()
observable.wait_close()
self.assertTrue(observable.closed)
def test_get_old_data(self):
observable = self.create_observable()
observable.push('m1')
observable.push('m2')
self.assertEqual(['m1', 'm2'], observable.get_old_data())
def test_on_next_exception_once(self):
observable = self.create_observable()
class FailingObserver(SimpleStoringObserver):
def __init__(self):
super().__init__()
self.count = 0
def on_next(self, chunk):
self.count += 1
if self.count == 1:
raise Exception
super().on_next(chunk)
observer = FailingObserver()
observable.subscribe(observer)
observable.push('m1')
observable.push('m2')
self.assertEqual(['m2'], observer.data)
def test_on_next_exception_close_afterwards(self):
observable = self.create_observable()
class FailingObserver(SimpleStoringObserver):
def on_next(self, chunk):
raise Exception
observer = FailingObserver()
observable.subscribe(observer)
observable.push('m1')
observable.push('m2')
observable.close()
self.assertEqual([], observer.data)
self.assertTrue(observer.closed)
def test_on_next_exception_different_observers(self):
observable = self.create_observable()
class FailingObserver(SimpleStoringObserver):
def on_next(self, chunk):
raise Exception
failing_observer = FailingObserver()
observable.subscribe(failing_observer)
normal_observer = SimpleStoringObserver()
observable.subscribe(normal_observer)
observable.push('m1')
observable.push('m2')
self.assertEqual([], failing_observer.data)
self.assertEqual(['m1', 'm2'], normal_observer.data)
def test_on_close_exception_single_observer(self):
observable = self.create_observable()
class FailingObserver(SimpleStoringObserver):
def on_close(self):
raise Exception
observer = FailingObserver()
observable.subscribe(observer)
observable.close()
self.assertTrue(observable.closed)
def test_on_close_exception_different_observers(self):
observable = self.create_observable()
class FailingObserver(SimpleStoringObserver):
def on_close(self):
raise Exception
failing_observer = FailingObserver()
observable.subscribe(failing_observer)
normal_observer = SimpleStoringObserver()
observable.subscribe(normal_observer)
observable.close()
self.assertTrue(observable.closed)
self.assertTrue(normal_observer.closed)
def test_map_single_update(self):
observable = self.create_observable()
mapped_observable = observable.map(lambda chunk: chunk + '_x')
observer = SimpleStoringObserver()
mapped_observable.subscribe(observer)
observable.push('message')
self.assertEqual(['message_x'], observer.data)
def test_map_multiple_updates(self):
observable = self.create_observable()
mapped_observable = observable.map(lambda chunk: chunk + '_x')
observer = SimpleStoringObserver()
mapped_observable.subscribe(observer)
observable.push('message1')
observable.push('')
observable.push('message2')
self.assertEqual(['message1_x', '_x', 'message2_x'], observer.data)
def test_map_multiple_updates_late_subscription(self):
observable = self.create_observable()
observable.push('a')
observable.push('b')
observable.push('c')
mapped_observable = observable.map(lambda chunk: chunk + '_x')
observer = SimpleStoringObserver()
mapped_observable.subscribe(observer)
self.assertEqual(['a_x', 'b_x', 'c_x'], observer.data)
def test_map_get_old_data(self):
observable = self.create_observable()
mapped_observable = observable.map(lambda chunk: chunk + '_x')
observable.push('message1')
observable.push('message2')
self.assertEqual(['message1_x', 'message2_x'],
mapped_observable.get_old_data())
def test_map_close(self):
observable = self.create_observable()
mapped_observable = observable.map(lambda chunk: chunk + '_x')
observer = SimpleStoringObserver()
mapped_observable.subscribe(observer)
observable.close()
self.assertTrue(observer.closed)
self.assertTrue(mapped_observable.closed)
def test_map_close_late_subscription(self):
observable = self.create_observable()
mapped_observable = observable.map(lambda chunk: chunk + '_x')
observable.close()
observer = SimpleStoringObserver()
mapped_observable.subscribe(observer)
self.assertTrue(observer.closed)
def test_map_wait_close(self):
observable = self.create_observable()
mapped_observable = observable.map(lambda chunk: chunk + '_x')
observer = SimpleStoringObserver()
mapped_observable.subscribe(observer)
thread = threading.Thread(target=self.close_delayed,
args=[observable],
daemon=True)
thread.start()
mapped_observable.wait_close()
self.assertTrue(observer.closed)
def test_map_prohibit_push(self):
observable = self.create_observable()
mapped_observable = observable.map(lambda chunk: chunk + '_x')
self.assertRaises(RuntimeError, mapped_observable.push,
['any_message'])
def test_map_prohibit_close(self):
observable = self.create_observable()
mapped_observable = observable.map(lambda chunk: chunk + '_x')
self.assertRaises(RuntimeError, mapped_observable.close)
def test_time_buffer_single_update(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(10)
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
observable.push('message1')
self.wait_buffer_flush(buffered_observable)
self.assertEqual(['message1'], observer.data)
def test_time_buffer_multiple_updates(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(10)
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
observable.push('a')
observable.push('b')
observable.push('c')
self.wait_buffer_flush(buffered_observable)
self.assertEqual(['a', 'b', 'c'], observer.data)
def test_time_buffer_multiple_buffers(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(10)
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
observable.push('message1')
self.wait_buffer_flush(buffered_observable)
observable.push('message2')
self.wait_buffer_flush(buffered_observable)
observable.push('message3')
self.wait_buffer_flush(buffered_observable)
self.assertEqual(['message1', 'message2', 'message3'], observer.data)
def test_time_buffer_not_flushed(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(300)
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
observable.push('message1')
self.assertEqual([], observer.data)
self.wait_buffer_flush(buffered_observable)
self.assertEqual(['message1'], observer.data)
def test_time_buffer_aggregate_single_update(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(
100, lambda chunks: ['|||'.join(chunks)])
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
observable.push('message1')
self.wait_buffer_flush(buffered_observable)
self.assertEqual(['message1'], observer.data)
def test_time_buffer_aggregate_multiple_updates(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(
100, lambda chunks: ['|||'.join(chunks)])
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
observable.push('a')
observable.push('b')
observable.push('c')
self.wait_buffer_flush(buffered_observable)
self.assertEqual(['a|||b|||c'], observer.data)
def test_time_buffer_aggregate_multiple_updates_multiple_buffers(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(
100, lambda chunks: ['|||'.join(chunks)])
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
observable.push('a')
observable.push('b')
observable.push('c')
self.wait_buffer_flush(buffered_observable)
observable.push('d')
observable.push('e')
observable.push('f')
self.wait_buffer_flush(buffered_observable)
self.assertEqual(['a|||b|||c', 'd|||e|||f'], observer.data)
def test_time_buffer_close(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(10)
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
observable.close()
self.wait_buffer_flush(buffered_observable)
self.assertTrue(observer.closed)
self.assertTrue(buffered_observable.closed)
def test_time_buffer_flush_before_close(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(100)
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
observable.push('m1')
observable.push('m2')
observable.close()
self.assertEqual([], observer.data)
self.assertFalse(observer.closed)
self.wait_buffer_flush(buffered_observable)
self.assertEqual(['m1', 'm2'], observer.data)
self.assertTrue(observer.closed)
def test_time_buffer_prohibit_push(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(10)
self.assertRaises(RuntimeError, buffered_observable.push,
['any_message'])
def test_time_buffer_prohibit_close(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(10)
self.assertRaises(RuntimeError, buffered_observable.close)
def test_time_buffer_get_old_data(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(10)
observable.push('m1')
observable.push('m2')
self.wait_buffer_flush(buffered_observable)
self.assertEqual(['m1', 'm2'], buffered_observable.get_old_data())
def test_time_buffer_get_old_data_not_flushed(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(300)
observable.push('m1')
observable.push('m2')
self.assertEqual([], buffered_observable.get_old_data())
def test_time_buffer_get_old_data_aggregated(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(
100, lambda chunks: ['|'.join(chunks)])
observable.push('a')
observable.push('b')
observable.push('c')
self.wait_buffer_flush(buffered_observable)
self.assertEqual(['a|b|c'], buffered_observable.get_old_data())
def test_time_buffer_wait_close(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(10)
self.close_delayed(observable)
buffered_observable.wait_close()
self.assertTrue(buffered_observable.closed)
def test_time_buffer_late_subscription(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(10)
observable.push('m1')
observable.push('m2')
self.wait_buffer_flush(buffered_observable)
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
self.assertEqual(['m1', 'm2'], observer.data)
def test_time_buffer_aggregated_late_subscription(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(
100, lambda chunks: ['|'.join(chunks)])
observable.push('m1')
observable.push('m2')
observable.push('m3')
self.wait_buffer_flush(buffered_observable)
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
self.assertEqual(['m1|m2|m3'], observer.data)
def test_time_buffer_close_late_subscription(self):
observable = self.create_observable()
buffered_observable = observable.time_buffered(10)
observable.push('message')
observable.close()
self.wait_buffer_flush(buffered_observable)
observer = SimpleStoringObserver()
buffered_observable.subscribe(observer)
self.assertTrue(observer.closed)
def create_observable(self):
self.observable = Observable()
return self.observable
def tearDown(self):
super().tearDown()
if not self.observable.closed:
self.observable.close()
@staticmethod
def close_delayed(observable):
time.sleep(0.1)
observable.close()
@staticmethod
def wait_buffer_flush(buffered_observable):
time.sleep(buffered_observable.period_millis * 1.3 / 1000.0 + 0.01)
def create_observable(self):
self.observable = Observable()
return self.observable