def test_event_log_get_stats_for_run(self, storage):
import math
enqueued_time = time.time()
launched_time = enqueued_time + 20
start_time = launched_time + 50
storage.store_event(
EventLogEntry(
None,
"message",
"debug",
"",
DEFAULT_RUN_ID,
enqueued_time,
dagster_event=DagsterEvent(
DagsterEventType.PIPELINE_ENQUEUED.value,
"nonce",
),
))
storage.store_event(
EventLogEntry(
None,
"message",
"debug",
"",
DEFAULT_RUN_ID,
launched_time,
dagster_event=DagsterEvent(
DagsterEventType.PIPELINE_STARTING.value,
"nonce",
),
))
storage.store_event(
EventLogEntry(
None,
"message",
"debug",
"",
DEFAULT_RUN_ID,
start_time,
dagster_event=DagsterEvent(
DagsterEventType.PIPELINE_START.value,
"nonce",
),
))
assert math.isclose(
storage.get_stats_for_run(DEFAULT_RUN_ID).enqueued_time,
enqueued_time)
assert math.isclose(
storage.get_stats_for_run(DEFAULT_RUN_ID).launch_time,
launched_time)
assert math.isclose(
storage.get_stats_for_run(DEFAULT_RUN_ID).start_time, start_time)
def _dequeue_run(self, instance, run, workspace):
# double check that the run is still queued before dequeing
reloaded_run = instance.get_run_by_id(run.run_id)
if reloaded_run.status != PipelineRunStatus.QUEUED:
self._logger.info(
"Run {run_id} is now {status} instead of QUEUED, skipping".
format(run_id=reloaded_run.run_id, status=reloaded_run.status))
return
dequeued_event = DagsterEvent(
event_type_value=DagsterEventType.PIPELINE_DEQUEUED.value,
pipeline_name=run.pipeline_name,
)
event_record = EventLogEntry(
message="",
user_message="",
level=logging.INFO,
pipeline_name=run.pipeline_name,
run_id=run.run_id,
error_info=None,
timestamp=time.time(),
dagster_event=dequeued_event,
)
instance.handle_new_event(event_record)
instance.launch_run(run.run_id, workspace)
def test_correct_timezone(self, storage):
curr_time = time.time()
event = EventLogEntry(
None,
"Message2",
"debug",
"",
"foo",
curr_time,
dagster_event=DagsterEvent(
DagsterEventType.PIPELINE_START.value,
"nonce",
event_specific_data=EngineEventData.in_process(999),
),
)
storage.store_event(event)
logs = storage.get_logs_for_run("foo")
assert len(logs) == 1
log = logs[0]
stats = storage.get_stats_for_run("foo")
assert int(log.timestamp) == int(stats.start_time)
assert int(log.timestamp) == int(curr_time)
def test_event_log_storage_store_with_multiple_runs(self, storage):
runs = ["foo", "bar", "baz"]
for run_id in runs:
assert len(storage.get_logs_for_run(run_id)) == 0
storage.store_event(
EventLogEntry(
None,
"Message2",
"debug",
"",
run_id,
time.time(),
dagster_event=DagsterEvent(
DagsterEventType.STEP_SUCCESS.value,
"nonce",
event_specific_data=StepSuccessData(duration_ms=100.0),
),
))
for run_id in runs:
assert len(storage.get_logs_for_run(run_id)) == 1
assert storage.get_stats_for_run(run_id).steps_succeeded == 1
if self.can_wipe():
storage.wipe()
for run_id in runs:
assert len(storage.get_logs_for_run(run_id)) == 0
def _event_record(run_id,
solid_name,
timestamp,
event_type,
event_specific_data=None):
pipeline_name = "pipeline_name"
solid_handle = NodeHandle(solid_name, None)
step_handle = StepHandle(solid_handle)
return EventLogEntry(
None,
"",
"debug",
"",
run_id,
timestamp,
step_key=step_handle.to_key(),
pipeline_name=pipeline_name,
dagster_event=DagsterEvent(
event_type.value,
pipeline_name,
solid_handle=solid_handle,
step_handle=step_handle,
event_specific_data=event_specific_data,
),
)
def create_event(count: int, run_id: str = RUN_ID):
return EventLogEntry(
error_info=None,
user_message=str(count),
level="debug",
run_id=run_id,
timestamp=time.time(),
dagster_event=DagsterEvent(
DagsterEventType.ENGINE_EVENT.value,
"nonce",
event_specific_data=EngineEventData.in_process(999),
),
)
def create_event(count: int, run_id: str = RUN_ID):
return EventLogEntry(
None,
str(count),
"debug",
"",
run_id,
time.time(),
dagster_event=DagsterEvent(
DagsterEventType.ENGINE_EVENT.value,
"nonce",
event_specific_data=EngineEventData.in_process(999),
),
)
def create_test_event_log_record(message: str, run_id: str = DEFAULT_RUN_ID):
return EventLogEntry(
None,
message,
"debug",
"",
run_id,
time.time(),
dagster_event=DagsterEvent(
DagsterEventType.ENGINE_EVENT.value,
"nonce",
event_specific_data=EngineEventData.in_process(999),
),
)
def report_starting_event(instance, run, timestamp):
launch_started_event = DagsterEvent(
event_type_value=DagsterEventType.PIPELINE_STARTING.value,
pipeline_name=run.pipeline_name,
)
event_record = EventLogEntry(
user_message="",
level=logging.INFO,
pipeline_name=run.pipeline_name,
run_id=run.run_id,
error_info=None,
timestamp=timestamp,
dagster_event=launch_started_event,
)
instance.handle_new_event(event_record)
def _materialization_event_record(run_id, asset_key):
return EventLogEntry(
None,
"",
"debug",
"",
run_id,
time.time() - 25,
step_key="my_step_key",
pipeline_name="my_pipeline",
dagster_event=DagsterEvent(
DagsterEventType.ASSET_MATERIALIZATION.value,
"my_pipeline",
step_key="my_step_key",
event_specific_data=StepMaterializationData(
AssetMaterialization(asset_key=asset_key)),
),
)
def construct_step_failure_event_and_handle(pipeline_run, step_key, err, instance):
step_failure_event = DagsterEvent(
event_type_value=DagsterEventType.STEP_FAILURE.value,
pipeline_name=pipeline_run.pipeline_name,
step_key=step_key,
event_specific_data=StepFailureData(
error=serializable_error_info_from_exc_info(sys.exc_info()),
user_failure_data=UserFailureData(label="K8sError"),
),
)
event_record = EventLogEntry(
user_message=str(err),
level=logging.ERROR,
pipeline_name=pipeline_run.pipeline_name,
run_id=pipeline_run.run_id,
error_info=None,
step_key=step_key,
timestamp=time.time(),
dagster_event=step_failure_event,
)
instance.handle_new_event(event_record)
return step_failure_event
def test_event_log_storage_store_events_and_wipe(self, storage):
assert len(storage.get_logs_for_run(DEFAULT_RUN_ID)) == 0
storage.store_event(
EventLogEntry(
None,
"Message2",
"debug",
"",
DEFAULT_RUN_ID,
time.time(),
dagster_event=DagsterEvent(
DagsterEventType.ENGINE_EVENT.value,
"nonce",
event_specific_data=EngineEventData.in_process(999),
),
))
assert len(storage.get_logs_for_run(DEFAULT_RUN_ID)) == 1
assert storage.get_stats_for_run(DEFAULT_RUN_ID)
if self.can_wipe():
storage.wipe()
assert len(storage.get_logs_for_run(DEFAULT_RUN_ID)) == 0
def submit_run(self, context: SubmitRunContext) -> PipelineRun:
pipeline_run = context.pipeline_run
check.invariant(pipeline_run.status == PipelineRunStatus.NOT_STARTED)
enqueued_event = DagsterEvent(
event_type_value=DagsterEventType.PIPELINE_ENQUEUED.value,
pipeline_name=pipeline_run.pipeline_name,
)
event_record = EventLogEntry(
user_message="",
level=logging.INFO,
pipeline_name=pipeline_run.pipeline_name,
run_id=pipeline_run.run_id,
error_info=None,
timestamp=time.time(),
dagster_event=enqueued_event,
)
self._instance.handle_new_event(event_record)
run = self._instance.get_run_by_id(pipeline_run.run_id)
if run is None:
check.failed(f"Failed to reload run {pipeline_run.run_id}")
return run
def test_legacy_event_log_load():
# ensure EventLogEntry 0.14.3+ can still be loaded by older dagster versions
# to avoid downgrades etc from creating operational issues
legacy_env = WhitelistMap.create()
# snapshot of EventLogEntry pre commit ea19544
@_whitelist_for_serdes(
whitelist_map=legacy_env,
storage_name="EventLogEntry", # use this to avoid collision with current EventLogEntry
)
class OldEventLogEntry( # pylint: disable=unused-variable
NamedTuple(
"_OldEventLogEntry",
[
("error_info", Optional[SerializableErrorInfo]),
("message", str),
("level", Union[str, int]),
("user_message", str),
("run_id", str),
("timestamp", float),
("step_key", Optional[str]),
("pipeline_name", Optional[str]),
("dagster_event", Optional[DagsterEvent]),
],
)
):
def __new__(
cls,
error_info,
message,
level,
user_message,
run_id,
timestamp,
step_key=None,
pipeline_name=None,
dagster_event=None,
job_name=None,
):
pipeline_name = pipeline_name or job_name
return super().__new__(
cls,
check.opt_inst_param(error_info, "error_info", SerializableErrorInfo),
check.str_param(message, "message"),
level, # coerce_valid_log_level call omitted
check.str_param(user_message, "user_message"),
check.str_param(run_id, "run_id"),
check.float_param(timestamp, "timestamp"),
check.opt_str_param(step_key, "step_key"),
check.opt_str_param(pipeline_name, "pipeline_name"),
check.opt_inst_param(dagster_event, "dagster_event", DagsterEvent),
)
# current event log entry
new_event = EventLogEntry(
user_message="test 1 2 3",
error_info=None,
level="debug",
run_id="fake_run_id",
timestamp=time.time(),
)
storage_str = serialize_dagster_namedtuple(new_event)
result = _deserialize_json(storage_str, legacy_env)
assert result.message is not None