| # 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. |
| import logging |
| import time |
| import unittest |
| from datetime import datetime, timedelta |
| from typing import Any, Callable, cast, Dict, Iterator, Optional, Type, Union |
| from unittest.mock import patch |
| |
| from flask import current_app |
| from freezegun import freeze_time |
| |
| from superset import security_manager |
| from superset.utils.log import ( |
| AbstractEventLogger, |
| DBEventLogger, |
| get_event_logger_from_cfg_value, |
| ) |
| from tests.integration_tests.test_app import app |
| |
| |
| class TestEventLogger(unittest.TestCase): |
| def test_correct_config_object(self): |
| # test that assignment of concrete AbstractBaseClass impl returns |
| # unmodified object |
| obj = DBEventLogger() |
| res = get_event_logger_from_cfg_value(obj) |
| self.assertIs(obj, res) |
| |
| def test_config_class_deprecation(self): |
| # test that assignment of a class object to EVENT_LOGGER is correctly |
| # deprecated |
| res = None |
| |
| # print warning if a class is assigned to EVENT_LOGGER |
| with self.assertLogs(level="WARNING"): |
| res = get_event_logger_from_cfg_value(DBEventLogger) |
| |
| # class is instantiated and returned |
| self.assertIsInstance(res, DBEventLogger) |
| |
| def test_raises_typerror_if_not_abc(self): |
| # test that assignment of non AbstractEventLogger derived type raises |
| # TypeError |
| with self.assertRaises(TypeError): |
| get_event_logger_from_cfg_value(logging.getLogger()) |
| |
| @patch.object(DBEventLogger, "log") |
| def test_log_this(self, mock_log): |
| logger = DBEventLogger() |
| |
| @logger.log_this |
| def test_func(): |
| time.sleep(0.05) |
| return 1 |
| |
| with app.test_request_context("/superset/dashboard/1/?myparam=foo"): |
| result = test_func() |
| payload = mock_log.call_args[1] |
| self.assertEqual(result, 1) |
| self.assertEqual( |
| payload["records"], |
| [ |
| { |
| "myparam": "foo", |
| "path": "/superset/dashboard/1/", |
| "url_rule": "/superset/dashboard/<dashboard_id_or_slug>/", |
| "object_ref": test_func.__qualname__, |
| } |
| ], |
| ) |
| self.assertGreaterEqual(payload["duration_ms"], 50) |
| |
| @patch.object(DBEventLogger, "log") |
| def test_log_this_with_extra_payload(self, mock_log): |
| logger = DBEventLogger() |
| |
| @logger.log_this_with_extra_payload |
| def test_func(arg1, add_extra_log_payload, karg1=1): |
| time.sleep(0.1) |
| add_extra_log_payload(foo="bar") |
| return arg1 * karg1 |
| |
| with app.test_request_context(): |
| result = test_func(1, karg1=2) # pylint: disable=no-value-for-parameter |
| payload = mock_log.call_args[1] |
| self.assertEqual(result, 2) |
| self.assertEqual( |
| payload["records"], |
| [ |
| { |
| "foo": "bar", |
| "path": "/", |
| "karg1": 2, |
| "object_ref": test_func.__qualname__, |
| } |
| ], |
| ) |
| self.assertGreaterEqual(payload["duration_ms"], 100) |
| |
| @patch("superset.utils.log.g", spec={}) |
| @freeze_time("Jan 14th, 2020", auto_tick_seconds=15) |
| def test_context_manager_log(self, mock_g): |
| class DummyEventLogger(AbstractEventLogger): |
| def __init__(self): |
| self.records = [] |
| |
| def log( |
| self, |
| user_id: Optional[int], |
| action: str, |
| dashboard_id: Optional[int], |
| duration_ms: Optional[int], |
| slice_id: Optional[int], |
| referrer: Optional[str], |
| *args: Any, |
| **kwargs: Any, |
| ): |
| self.records.append( |
| {**kwargs, "user_id": user_id, "duration": duration_ms} |
| ) |
| |
| logger = DummyEventLogger() |
| |
| with app.test_request_context(): |
| mock_g.user = security_manager.find_user("gamma") |
| with logger(action="foo", engine="bar"): |
| pass |
| |
| assert logger.records == [ |
| { |
| "records": [{"path": "/", "engine": "bar"}], |
| "user_id": "2", |
| "duration": 15000.0, |
| } |
| ] |
| |
| @patch("superset.utils.log.g", spec={}) |
| def test_context_manager_log_with_context(self, mock_g): |
| class DummyEventLogger(AbstractEventLogger): |
| def __init__(self): |
| self.records = [] |
| |
| def log( |
| self, |
| user_id: Optional[int], |
| action: str, |
| dashboard_id: Optional[int], |
| duration_ms: Optional[int], |
| slice_id: Optional[int], |
| referrer: Optional[str], |
| *args: Any, |
| **kwargs: Any, |
| ): |
| self.records.append( |
| {**kwargs, "user_id": user_id, "duration": duration_ms} |
| ) |
| |
| logger = DummyEventLogger() |
| |
| with app.test_request_context(): |
| mock_g.user = security_manager.find_user("gamma") |
| logger.log_with_context( |
| action="foo", |
| duration=timedelta(days=64, seconds=29156, microseconds=10), |
| object_ref={"baz": "food"}, |
| log_to_statsd=False, |
| payload_override={"engine": "sqllite"}, |
| ) |
| |
| assert logger.records == [ |
| { |
| "records": [ |
| { |
| "path": "/", |
| "object_ref": {"baz": "food"}, |
| "payload_override": {"engine": "sqllite"}, |
| } |
| ], |
| "user_id": "2", |
| "duration": 5558756000, |
| } |
| ] |
| |
| @patch("superset.utils.log.g", spec={}) |
| def test_log_with_context_user_null(self, mock_g): |
| class DummyEventLogger(AbstractEventLogger): |
| def __init__(self): |
| self.records = [] |
| |
| def log( |
| self, |
| user_id: Optional[int], |
| action: str, |
| dashboard_id: Optional[int], |
| duration_ms: Optional[int], |
| slice_id: Optional[int], |
| referrer: Optional[str], |
| *args: Any, |
| **kwargs: Any, |
| ): |
| self.records.append( |
| {**kwargs, "user_id": user_id, "duration": duration_ms} |
| ) |
| |
| logger = DummyEventLogger() |
| |
| with app.test_request_context(): |
| mock_g.side_effect = Exception("oops") |
| logger.log_with_context( |
| action="foo", |
| duration=timedelta(days=64, seconds=29156, microseconds=10), |
| object_ref={"baz": "food"}, |
| log_to_statsd=False, |
| payload_override={"engine": "sqllite"}, |
| ) |
| |
| assert logger.records[0]["user_id"] == None |