# 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.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//", "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