You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@superset.apache.org by wi...@apache.org on 2021/03/30 15:47:04 UTC
[superset] branch master updated: feat(alerts & reports): Easier to
read execution logs (#13752)
This is an automated email from the ASF dual-hosted git repository.
willbarrett pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/superset.git
The following commit(s) were added to refs/heads/master by this push:
new 304e3b3 feat(alerts & reports): Easier to read execution logs (#13752)
304e3b3 is described below
commit 304e3b36ebe3792eddd54da5336a2a95bf12c329
Author: Jack Fragassi <jf...@gmail.com>
AuthorDate: Tue Mar 30 08:46:16 2021 -0700
feat(alerts & reports): Easier to read execution logs (#13752)
* Prep for migration
* Migration for execution id column
* Generate execution ids for alerts and reports
* Change execution id range
* Add execution id to API endpoint
* Add execution id to execution log view
* Change execution id range
* Change execution id to a uuid
* Fix execution id type
* Switch state and exec. id columns
* Change db column to UUIDType
* Python lint
* Fix failing frontend tests
* execution_id -> uuid
* Fix migration head
* lint
* Use celery task id as the execution id
* lint
* lint for real
* Fix tests
---
.../views/CRUD/alert/ExecutionLog_spec.jsx | 1 +
.../src/views/CRUD/alert/ExecutionLog.tsx | 11 +++++
superset-frontend/src/views/CRUD/alert/types.ts | 1 +
...411006_add_execution_id_to_report_execution_.py | 39 +++++++++++++++
superset/models/reports.py | 2 +
superset/reports/commands/execute.py | 16 +++++--
superset/reports/logs/api.py | 2 +
superset/tasks/scheduler.py | 5 +-
tests/reports/commands_tests.py | 55 ++++++++++++----------
9 files changed, 102 insertions(+), 30 deletions(-)
diff --git a/superset-frontend/spec/javascripts/views/CRUD/alert/ExecutionLog_spec.jsx b/superset-frontend/spec/javascripts/views/CRUD/alert/ExecutionLog_spec.jsx
index f8f9b21..5029a2c 100644
--- a/superset-frontend/spec/javascripts/views/CRUD/alert/ExecutionLog_spec.jsx
+++ b/superset-frontend/spec/javascripts/views/CRUD/alert/ExecutionLog_spec.jsx
@@ -43,6 +43,7 @@ const mockannotations = [...new Array(3)].map((_, i) => ({
start_dttm: new Date().toISOString,
state: 'Success',
value: `report ${i} value`,
+ uuid: 'f44da495-b067-4645-b463-3be98d5f3206',
}));
fetchMock.get(executionLogsEndpoint, {
diff --git a/superset-frontend/src/views/CRUD/alert/ExecutionLog.tsx b/superset-frontend/src/views/CRUD/alert/ExecutionLog.tsx
index 185266e..b35f486 100644
--- a/superset-frontend/src/views/CRUD/alert/ExecutionLog.tsx
+++ b/superset-frontend/src/views/CRUD/alert/ExecutionLog.tsx
@@ -98,6 +98,17 @@ function ExecutionLog({ addDangerToast, isReportEnabled }: ExecutionLogProps) {
{
Cell: ({
row: {
+ original: { uuid: executionId },
+ },
+ }: any) => executionId.slice(0, 6),
+ accessor: 'uuid',
+ Header: t('Execution ID'),
+ size: 'xs',
+ disableSortBy: true,
+ },
+ {
+ Cell: ({
+ row: {
original: { scheduled_dttm: scheduledDttm },
},
}: any) =>
diff --git a/superset-frontend/src/views/CRUD/alert/types.ts b/superset-frontend/src/views/CRUD/alert/types.ts
index 9e1128e..556dbb9 100644
--- a/superset-frontend/src/views/CRUD/alert/types.ts
+++ b/superset-frontend/src/views/CRUD/alert/types.ts
@@ -91,6 +91,7 @@ export type LogObject = {
start_dttm: string;
state: string;
value: string;
+ uuid: string;
};
export enum AlertState {
diff --git a/superset/migrations/versions/301362411006_add_execution_id_to_report_execution_.py b/superset/migrations/versions/301362411006_add_execution_id_to_report_execution_.py
new file mode 100644
index 0000000..c7af8f6
--- /dev/null
+++ b/superset/migrations/versions/301362411006_add_execution_id_to_report_execution_.py
@@ -0,0 +1,39 @@
+# Licensed to the Apache Software Foundation (ASF) under one
+# or more contributor license agreements. See the NOTICE file
+# distributed with this work for additional information
+# regarding copyright ownership. The ASF licenses this file
+# to you under the Apache License, Version 2.0 (the
+# "License"); you may not use this file except in compliance
+# with the License. You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing,
+# software distributed under the License is distributed on an
+# "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+# KIND, either express or implied. See the License for the
+# specific language governing permissions and limitations
+# under the License.
+"""add_execution_id_to_report_execution_log_model.py
+
+Revision ID: 301362411006
+Revises: 989bbe479899
+Create Date: 2021-03-23 05:23:15.641856
+
+"""
+
+# revision identifiers, used by Alembic.
+revision = "301362411006"
+down_revision = "989bbe479899"
+
+import sqlalchemy as sa
+from alembic import op
+from sqlalchemy_utils import UUIDType
+
+
+def upgrade():
+ op.add_column("report_execution_log", sa.Column("uuid", UUIDType(binary=True)))
+
+
+def downgrade():
+ op.drop_column("report_execution_log", "execution_id")
diff --git a/superset/models/reports.py b/superset/models/reports.py
index 822bbb0..be40733 100644
--- a/superset/models/reports.py
+++ b/superset/models/reports.py
@@ -33,6 +33,7 @@ from sqlalchemy import (
)
from sqlalchemy.orm import backref, relationship
from sqlalchemy.schema import UniqueConstraint
+from sqlalchemy_utils import UUIDType
from superset.extensions import security_manager
from superset.models.core import Database
@@ -171,6 +172,7 @@ class ReportExecutionLog(Model): # pylint: disable=too-few-public-methods
__tablename__ = "report_execution_log"
id = Column(Integer, primary_key=True)
+ uuid = Column(UUIDType(binary=True))
# Timestamps
scheduled_dttm = Column(DateTime, nullable=False)
diff --git a/superset/reports/commands/execute.py b/superset/reports/commands/execute.py
index 821f074..c3a3d67 100644
--- a/superset/reports/commands/execute.py
+++ b/superset/reports/commands/execute.py
@@ -17,6 +17,7 @@
import logging
from datetime import datetime, timedelta
from typing import Any, List, Optional
+from uuid import UUID
from celery.exceptions import SoftTimeLimitExceeded
from flask_appbuilder.security.sqla.models import User
@@ -73,11 +74,13 @@ class BaseReportState:
session: Session,
report_schedule: ReportSchedule,
scheduled_dttm: datetime,
+ execution_id: UUID,
) -> None:
self._session = session
self._report_schedule = report_schedule
self._scheduled_dttm = scheduled_dttm
self._start_dttm = datetime.utcnow()
+ self._execution_id = execution_id
def set_state_and_log(
self, state: ReportState, error_message: Optional[str] = None,
@@ -117,6 +120,7 @@ class BaseReportState:
state=state,
error_message=error_message,
report_schedule=self._report_schedule,
+ uuid=self._execution_id,
)
self._session.add(log)
self._session.commit()
@@ -397,10 +401,12 @@ class ReportScheduleStateMachine: # pylint: disable=too-few-public-methods
def __init__(
self,
session: Session,
+ task_uuid: UUID,
report_schedule: ReportSchedule,
scheduled_dttm: datetime,
):
self._session = session
+ self._execution_id = task_uuid
self._report_schedule = report_schedule
self._scheduled_dttm = scheduled_dttm
@@ -411,7 +417,10 @@ class ReportScheduleStateMachine: # pylint: disable=too-few-public-methods
self._report_schedule.last_state in state_cls.current_states
):
state_cls(
- self._session, self._report_schedule, self._scheduled_dttm
+ self._session,
+ self._report_schedule,
+ self._scheduled_dttm,
+ self._execution_id,
).next()
state_found = True
break
@@ -426,10 +435,11 @@ class AsyncExecuteReportScheduleCommand(BaseCommand):
- On Alerts uses related Command AlertCommand and sends configured notifications
"""
- def __init__(self, model_id: int, scheduled_dttm: datetime):
+ def __init__(self, task_id: str, model_id: int, scheduled_dttm: datetime):
self._model_id = model_id
self._model: Optional[ReportSchedule] = None
self._scheduled_dttm = scheduled_dttm
+ self._execution_id = UUID(task_id)
def run(self) -> None:
with session_scope(nullpool=True) as session:
@@ -438,7 +448,7 @@ class AsyncExecuteReportScheduleCommand(BaseCommand):
if not self._model:
raise ReportScheduleExecuteUnexpectedError()
ReportScheduleStateMachine(
- session, self._model, self._scheduled_dttm
+ session, self._execution_id, self._model, self._scheduled_dttm
).run()
except CommandException as ex:
raise ex
diff --git a/superset/reports/logs/api.py b/superset/reports/logs/api.py
index 44fdf3f..5cba1ea 100644
--- a/superset/reports/logs/api.py
+++ b/superset/reports/logs/api.py
@@ -49,6 +49,7 @@ class ReportExecutionLogRestApi(BaseSupersetModelRestApi):
"value_row_json",
"state",
"error_message",
+ "uuid",
]
list_columns = [
"id",
@@ -59,6 +60,7 @@ class ReportExecutionLogRestApi(BaseSupersetModelRestApi):
"value_row_json",
"state",
"error_message",
+ "uuid",
]
order_columns = [
"state",
diff --git a/superset/tasks/scheduler.py b/superset/tasks/scheduler.py
index 878812b..73005e7 100644
--- a/superset/tasks/scheduler.py
+++ b/superset/tasks/scheduler.py
@@ -63,8 +63,11 @@ def scheduler() -> None:
@celery_app.task(name="reports.execute")
def execute(report_schedule_id: int, scheduled_dttm: str) -> None:
try:
+ task_id = execute.request.id
scheduled_dttm_ = parser.parse(scheduled_dttm)
- AsyncExecuteReportScheduleCommand(report_schedule_id, scheduled_dttm_).run()
+ AsyncExecuteReportScheduleCommand(
+ task_id, report_schedule_id, scheduled_dttm_,
+ ).run()
except ReportScheduleUnexpectedError as ex:
logger.error("An unexpected occurred while executing the report: %s", ex)
except CommandException as ex:
diff --git a/tests/reports/commands_tests.py b/tests/reports/commands_tests.py
index 9234adb..fee74e5 100644
--- a/tests/reports/commands_tests.py
+++ b/tests/reports/commands_tests.py
@@ -18,6 +18,7 @@ import json
from datetime import datetime, timedelta
from typing import List, Optional
from unittest.mock import Mock, patch
+from uuid import uuid4
import pytest
from contextlib2 import contextmanager
@@ -64,6 +65,8 @@ pytestmark = pytest.mark.usefixtures(
"load_world_bank_dashboard_with_slices_module_scope"
)
+test_id = str(uuid4())
+
def get_target_from_report_schedule(report_schedule: ReportSchedule) -> List[str]:
return [
@@ -518,7 +521,7 @@ def test_email_chart_report_schedule(
with freeze_time("2020-01-01T00:00:00Z"):
AsyncExecuteReportScheduleCommand(
- create_report_email_chart.id, datetime.utcnow()
+ test_id, create_report_email_chart.id, datetime.utcnow()
).run()
notification_targets = get_target_from_report_schedule(
@@ -556,7 +559,7 @@ def test_email_dashboard_report_schedule(
with freeze_time("2020-01-01T00:00:00Z"):
AsyncExecuteReportScheduleCommand(
- create_report_email_dashboard.id, datetime.utcnow()
+ test_id, create_report_email_dashboard.id, datetime.utcnow()
).run()
notification_targets = get_target_from_report_schedule(
@@ -588,7 +591,7 @@ def test_slack_chart_report_schedule(
with freeze_time("2020-01-01T00:00:00Z"):
AsyncExecuteReportScheduleCommand(
- create_report_slack_chart.id, datetime.utcnow()
+ test_id, create_report_slack_chart.id, datetime.utcnow()
).run()
notification_targets = get_target_from_report_schedule(
@@ -608,7 +611,7 @@ def test_report_schedule_not_found(create_report_slack_chart):
"""
max_id = db.session.query(func.max(ReportSchedule.id)).scalar()
with pytest.raises(ReportScheduleNotFoundError):
- AsyncExecuteReportScheduleCommand(max_id + 1, datetime.utcnow()).run()
+ AsyncExecuteReportScheduleCommand(test_id, max_id + 1, datetime.utcnow()).run()
@pytest.mark.usefixtures("create_report_slack_chart_working")
@@ -620,7 +623,7 @@ def test_report_schedule_working(create_report_slack_chart_working):
with freeze_time("2020-01-01T00:00:00Z"):
with pytest.raises(ReportSchedulePreviousWorkingError):
AsyncExecuteReportScheduleCommand(
- create_report_slack_chart_working.id, datetime.utcnow()
+ test_id, create_report_slack_chart_working.id, datetime.utcnow()
).run()
assert_log(
@@ -643,7 +646,7 @@ def test_report_schedule_working_timeout(create_report_slack_chart_working):
with freeze_time(current_time):
with pytest.raises(ReportScheduleWorkingTimeoutError):
AsyncExecuteReportScheduleCommand(
- create_report_slack_chart_working.id, datetime.utcnow()
+ test_id, create_report_slack_chart_working.id, datetime.utcnow()
).run()
# Only needed for MySQL, understand why
@@ -668,7 +671,7 @@ def test_report_schedule_success_grace(create_alert_slack_chart_success):
with freeze_time(current_time):
AsyncExecuteReportScheduleCommand(
- create_alert_slack_chart_success.id, datetime.utcnow()
+ test_id, create_alert_slack_chart_success.id, datetime.utcnow()
).run()
db.session.commit()
@@ -687,7 +690,7 @@ def test_report_schedule_success_grace_end(create_alert_slack_chart_grace):
with freeze_time(current_time):
AsyncExecuteReportScheduleCommand(
- create_alert_slack_chart_grace.id, datetime.utcnow()
+ test_id, create_alert_slack_chart_grace.id, datetime.utcnow()
).run()
db.session.commit()
@@ -711,7 +714,7 @@ def test_alert_limit_is_applied(screenshot_mock, email_mock, create_alert_email_
return_value=None,
) as fetch_data_mock:
AsyncExecuteReportScheduleCommand(
- create_alert_email_chart.id, datetime.utcnow()
+ test_id, create_alert_email_chart.id, datetime.utcnow()
).run()
assert "LIMIT 2" in execute_mock.call_args[0][1]
@@ -736,7 +739,7 @@ def test_email_dashboard_report_fails(
with pytest.raises(ReportScheduleNotificationError):
AsyncExecuteReportScheduleCommand(
- create_report_email_dashboard.id, datetime.utcnow()
+ test_id, create_report_email_dashboard.id, datetime.utcnow()
).run()
assert_log(ReportState.ERROR, error_message="Could not connect to SMTP XPTO")
@@ -757,7 +760,7 @@ def test_slack_chart_alert(screenshot_mock, email_mock, create_alert_email_chart
with freeze_time("2020-01-01T00:00:00Z"):
AsyncExecuteReportScheduleCommand(
- create_alert_email_chart.id, datetime.utcnow()
+ test_id, create_alert_email_chart.id, datetime.utcnow()
).run()
notification_targets = get_target_from_report_schedule(create_alert_email_chart)
@@ -789,7 +792,7 @@ def test_slack_token_callable_chart_report(
with freeze_time("2020-01-01T00:00:00Z"):
AsyncExecuteReportScheduleCommand(
- create_report_slack_chart.id, datetime.utcnow()
+ test_id, create_report_slack_chart.id, datetime.utcnow()
).run()
app.config["SLACK_API_TOKEN"].assert_called_once()
assert slack_client_mock_class.called_with(token="cool_code", proxy="")
@@ -803,7 +806,7 @@ def test_email_chart_no_alert(create_no_alert_email_chart):
"""
with freeze_time("2020-01-01T00:00:00Z"):
AsyncExecuteReportScheduleCommand(
- create_no_alert_email_chart.id, datetime.utcnow()
+ test_id, create_no_alert_email_chart.id, datetime.utcnow()
).run()
assert_log(ReportState.NOOP)
@@ -818,7 +821,7 @@ def test_email_mul_alert(create_mul_alert_email_chart):
(AlertQueryMultipleRowsError, AlertQueryMultipleColumnsError)
):
AsyncExecuteReportScheduleCommand(
- create_mul_alert_email_chart.id, datetime.utcnow()
+ test_id, create_mul_alert_email_chart.id, datetime.utcnow()
).run()
@@ -839,7 +842,7 @@ def test_soft_timeout_alert(email_mock, create_alert_email_chart):
execute_mock.side_effect = SoftTimeLimitExceeded()
with pytest.raises(AlertQueryTimeout):
AsyncExecuteReportScheduleCommand(
- create_alert_email_chart.id, datetime.utcnow()
+ test_id, create_alert_email_chart.id, datetime.utcnow()
).run()
notification_targets = get_target_from_report_schedule(create_alert_email_chart)
@@ -866,7 +869,7 @@ def test_soft_timeout_screenshot(screenshot_mock, email_mock, create_alert_email
screenshot_mock.side_effect = SoftTimeLimitExceeded()
with pytest.raises(ReportScheduleScreenshotTimeout):
AsyncExecuteReportScheduleCommand(
- create_alert_email_chart.id, datetime.utcnow()
+ test_id, create_alert_email_chart.id, datetime.utcnow()
).run()
notification_targets = get_target_from_report_schedule(create_alert_email_chart)
@@ -893,7 +896,7 @@ def test_fail_screenshot(screenshot_mock, email_mock, create_alert_email_chart):
screenshot_mock.side_effect = Exception("Unexpected error")
with pytest.raises(ReportScheduleScreenshotFailedError):
AsyncExecuteReportScheduleCommand(
- create_alert_email_chart.id, datetime.utcnow()
+ test_id, create_alert_email_chart.id, datetime.utcnow()
).run()
notification_targets = get_target_from_report_schedule(create_alert_email_chart)
@@ -914,7 +917,7 @@ def test_invalid_sql_alert(email_mock, create_invalid_sql_alert_email_chart):
with freeze_time("2020-01-01T00:00:00Z"):
with pytest.raises((AlertQueryError, AlertQueryInvalidTypeError)):
AsyncExecuteReportScheduleCommand(
- create_invalid_sql_alert_email_chart.id, datetime.utcnow()
+ test_id, create_invalid_sql_alert_email_chart.id, datetime.utcnow()
).run()
notification_targets = get_target_from_report_schedule(
@@ -933,7 +936,7 @@ def test_grace_period_error(email_mock, create_invalid_sql_alert_email_chart):
with freeze_time("2020-01-01T00:00:00Z"):
with pytest.raises((AlertQueryError, AlertQueryInvalidTypeError)):
AsyncExecuteReportScheduleCommand(
- create_invalid_sql_alert_email_chart.id, datetime.utcnow()
+ test_id, create_invalid_sql_alert_email_chart.id, datetime.utcnow()
).run()
# Only needed for MySQL, understand why
@@ -950,7 +953,7 @@ def test_grace_period_error(email_mock, create_invalid_sql_alert_email_chart):
with freeze_time("2020-01-01T00:30:00Z"):
with pytest.raises((AlertQueryError, AlertQueryInvalidTypeError)):
AsyncExecuteReportScheduleCommand(
- create_invalid_sql_alert_email_chart.id, datetime.utcnow()
+ test_id, create_invalid_sql_alert_email_chart.id, datetime.utcnow()
).run()
db.session.commit()
assert (
@@ -961,7 +964,7 @@ def test_grace_period_error(email_mock, create_invalid_sql_alert_email_chart):
with freeze_time("2020-01-01T01:30:00Z"):
with pytest.raises((AlertQueryError, AlertQueryInvalidTypeError)):
AsyncExecuteReportScheduleCommand(
- create_invalid_sql_alert_email_chart.id, datetime.utcnow()
+ test_id, create_invalid_sql_alert_email_chart.id, datetime.utcnow()
).run()
db.session.commit()
assert (
@@ -981,7 +984,7 @@ def test_grace_period_error_flap(
with freeze_time("2020-01-01T00:00:00Z"):
with pytest.raises((AlertQueryError, AlertQueryInvalidTypeError)):
AsyncExecuteReportScheduleCommand(
- create_invalid_sql_alert_email_chart.id, datetime.utcnow()
+ test_id, create_invalid_sql_alert_email_chart.id, datetime.utcnow()
).run()
db.session.commit()
# Assert we have 1 notification sent on the log
@@ -992,7 +995,7 @@ def test_grace_period_error_flap(
with freeze_time("2020-01-01T00:30:00Z"):
with pytest.raises((AlertQueryError, AlertQueryInvalidTypeError)):
AsyncExecuteReportScheduleCommand(
- create_invalid_sql_alert_email_chart.id, datetime.utcnow()
+ test_id, create_invalid_sql_alert_email_chart.id, datetime.utcnow()
).run()
db.session.commit()
assert (
@@ -1008,11 +1011,11 @@ def test_grace_period_error_flap(
with freeze_time("2020-01-01T00:31:00Z"):
# One success
AsyncExecuteReportScheduleCommand(
- create_invalid_sql_alert_email_chart.id, datetime.utcnow()
+ test_id, create_invalid_sql_alert_email_chart.id, datetime.utcnow()
).run()
# Grace period ends
AsyncExecuteReportScheduleCommand(
- create_invalid_sql_alert_email_chart.id, datetime.utcnow()
+ test_id, create_invalid_sql_alert_email_chart.id, datetime.utcnow()
).run()
db.session.commit()
@@ -1027,7 +1030,7 @@ def test_grace_period_error_flap(
with freeze_time("2020-01-01T00:32:00Z"):
with pytest.raises((AlertQueryError, AlertQueryInvalidTypeError)):
AsyncExecuteReportScheduleCommand(
- create_invalid_sql_alert_email_chart.id, datetime.utcnow()
+ test_id, create_invalid_sql_alert_email_chart.id, datetime.utcnow()
).run()
db.session.commit()
assert (