bug logging: fix dynamic logs flush

commit_hash:cdf462caf648f4f765de7b70df6ac789eb3c26f9

.mapping.json

@@ -472,6 +472,7 @@
   "core/functional_tests/basic_chaos/tests-nonchaos/metrics/test_has_reopening_error_metric.py":"taxi/uservices/userver/core/functional_tests/basic_chaos/tests-nonchaos/metrics/test_has_reopening_error_metric.py",
   "core/functional_tests/basic_chaos/tests-nonchaos/middlewares/test_testsuite_middleware.py":"taxi/uservices/userver/core/functional_tests/basic_chaos/tests-nonchaos/middlewares/test_testsuite_middleware.py",
   "core/functional_tests/basic_chaos/tests-nonchaos/network/test_interfaces.py":"taxi/uservices/userver/core/functional_tests/basic_chaos/tests-nonchaos/network/test_interfaces.py",
+  "core/functional_tests/basic_chaos/tests-nonchaos/test_dynamic_debug_log.py":"taxi/uservices/userver/core/functional_tests/basic_chaos/tests-nonchaos/test_dynamic_debug_log.py",
   "core/functional_tests/basic_chaos/tests-restart/conftest.py":"taxi/uservices/userver/core/functional_tests/basic_chaos/tests-restart/conftest.py",
   "core/functional_tests/basic_chaos/tests-restart/test_restart.py":"taxi/uservices/userver/core/functional_tests/basic_chaos/tests-restart/test_restart.py",
   "core/functional_tests/basic_chaos/tests/conftest.py":"taxi/uservices/userver/core/functional_tests/basic_chaos/tests/conftest.py",

core/functional_tests/basic_chaos/service.cpp

@@ -6,6 +6,7 @@
 #include <userver/components/minimal_server_component_list.hpp>
 #include <userver/dynamic_config/client/component.hpp>
 #include <userver/dynamic_config/updater/component.hpp>
+#include <userver/server/handlers/dynamic_debug_log.hpp>
 #include <userver/server/handlers/on_log_rotate.hpp>
 #include <userver/server/handlers/ping.hpp>
 #include <userver/server/handlers/restart.hpp>
@@ -30,6 +31,7 @@ int main(int argc, char* argv[]) {
                                     .Append<components::LoggingConfigurator>()
                                     .Append<components::HttpClient>()
                                     .Append<components::TestsuiteSupport>()
+                                    .Append<server::handlers::DynamicDebugLog>()
                                     .Append<server::handlers::TestsControl>()
                                     .Append<server::handlers::ServerMonitor>()
                                     .Append<server::handlers::Ping>()

core/functional_tests/basic_chaos/static_config.yaml

@@ -50,6 +50,11 @@ components_manager:
             method: POST
             task_processor: monitor-task-processor
 
+        handler-dynamic-debug-log:
+            path: /log/dynamic-debug
+            method: GET,PUT,DELETE
+            task_processor: monitor-task-processor
+
         testsuite-support:
 
         http-client:

core/functional_tests/basic_chaos/tests-nonchaos/test_dynamic_debug_log.py

@@ -0,0 +1,270 @@
+import logging
+import os
+
+import pytest
+
+logger = logging.getLogger('test')
+
+USERVER_LOGGED_TEXT = 'headers complete'
+SERVICE_LOGGED_TEXT = 'Everything is OK'
+
+try:
+    import yatest.common  # noqa: F401
+
+    # arcadia
+    USERVER_LOCATION_FILE = (
+        'taxi/uservices/userver/core/src/server/http/http_request_parser.cpp'
+    )
+    SERVICE_LOCATION = (
+        'taxi/uservices/userver/core/src/server/handlers/ping.cpp:100'
+    )
+    PREFIX = 'taxi/'
+except ModuleNotFoundError:
+    # cmake
+    USERVER_LOCATION_FILE = (
+        'userver/core/src/server/http/http_request_parser.cpp'
+    )
+    SERVICE_LOCATION = 'userver/core/src/server/handlers/ping.cpp:100'
+    PREFIX = 'userver/'
+
+
+SKIP_BROKEN_LOGS = pytest.mark.skipif(
+    os.environ.get('TESTSUITE_SKIP_BROKEN_LOGS'), reason='TAXICOMMON-9730',
+)
+
+
+@pytest.fixture(name='taxi_bodyless_headers_mock')
+def _taxi_bodyless_headers_mock(mockserver):
+    @mockserver.json_handler(
+        '/test-service/response-with-headers-without-body',
+    )
+    async def _handler(request):
+        return mockserver.make_response(headers={'something': 'nothing'})
+
+
+@SKIP_BROKEN_LOGS
+async def test_service_debug_logs_off(
+    service_client, taxi_bodyless_headers_mock,
+):
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+
+    assert not capture.select(text=SERVICE_LOGGED_TEXT)
+
+
+@SKIP_BROKEN_LOGS
+async def test_service_debug_logs_on(
+    service_client, monitor_client, taxi_bodyless_headers_mock,
+):
+    resp = await monitor_client.put(
+        '/log/dynamic-debug', params={'location': SERVICE_LOCATION},
+    )
+    assert resp.status_code == 200
+
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+
+    assert capture.select(text=SERVICE_LOGGED_TEXT)
+
+
+@SKIP_BROKEN_LOGS
+async def test_service_debug_logs_prefix(
+    service_client, monitor_client, taxi_bodyless_headers_mock,
+):
+    resp = await monitor_client.get('/log/dynamic-debug')
+
+    assert resp.status_code == 200
+    lines = resp.text.split('\n')
+    for line in lines:
+        if len(line) == 0:
+            continue
+        path, _ = line.split()
+        logger.info(path)
+        assert path.startswith(PREFIX)
+
+
+@SKIP_BROKEN_LOGS
+async def test_service_debug_logs_on_off(
+    service_client, monitor_client, taxi_bodyless_headers_mock,
+):
+    resp = await monitor_client.put(
+        '/log/dynamic-debug', params={'location': SERVICE_LOCATION},
+    )
+    assert resp.status_code == 200
+    resp = await monitor_client.delete(
+        '/log/dynamic-debug', params={'location': SERVICE_LOCATION},
+    )
+    assert resp.status_code == 200
+
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+
+    assert not capture.select(text=SERVICE_LOGGED_TEXT)
+
+
+@SKIP_BROKEN_LOGS
+async def test_userver_debug_logs_file_off(
+    service_client, taxi_bodyless_headers_mock,
+):
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+
+    assert not capture.select(text=USERVER_LOGGED_TEXT)
+
+
+@SKIP_BROKEN_LOGS
+async def test_userver_debug_logs_file(
+    service_client, monitor_client, taxi_bodyless_headers_mock,
+):
+    resp = await monitor_client.put(
+        '/log/dynamic-debug', params={'location': USERVER_LOCATION_FILE},
+    )
+    assert resp.status_code == 200
+
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+
+    assert capture.select(text=USERVER_LOGGED_TEXT)
+
+
+@SKIP_BROKEN_LOGS
+async def test_userver_dynamic_config_debug_logs_on(
+    service_client, dynamic_config, monitor_client, taxi_bodyless_headers_mock,
+):
+    dynamic_config.set_values({
+        'USERVER_LOG_DYNAMIC_DEBUG': {
+            'force-enabled': [SERVICE_LOCATION],
+            'force-disabled': [],
+        },
+    })
+
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+
+    assert capture.select(text=SERVICE_LOGGED_TEXT)
+
+
+@SKIP_BROKEN_LOGS
+async def test_userver_dynamic_config_debug_logs_file_on(
+    service_client, dynamic_config, monitor_client, taxi_bodyless_headers_mock,
+):
+    dynamic_config.set_values({
+        'USERVER_LOG_DYNAMIC_DEBUG': {
+            'force-enabled': [USERVER_LOCATION_FILE],
+            'force-disabled': [],
+        },
+    })
+
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+
+    assert capture.select(text=USERVER_LOGGED_TEXT)
+
+
+@SKIP_BROKEN_LOGS
+async def test_userver_dynamic_config_debug_logs_level_on(
+    service_client, dynamic_config, monitor_client, taxi_bodyless_headers_mock,
+):
+    dynamic_config.set_values({
+        'USERVER_LOG_DYNAMIC_DEBUG': {
+            'force-enabled': [],
+            'force-disabled': [],
+            'force-enabled-level': {SERVICE_LOCATION: 'TRACE'},
+            'force-disabled-level': {},
+        },
+    })
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+    assert capture.select(text=SERVICE_LOGGED_TEXT)
+
+    dynamic_config.set_values({
+        'USERVER_LOG_DYNAMIC_DEBUG': {
+            'force-enabled': [],
+            'force-disabled': [],
+            'force-enabled-level': {},
+            'force-disabled-level': {},
+        },
+    })
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+    assert not capture.select(text=SERVICE_LOGGED_TEXT)
+
+
+@SKIP_BROKEN_LOGS
+async def test_userver_dynamic_config_debug_logs_off(
+    service_client, dynamic_config, monitor_client, taxi_bodyless_headers_mock,
+):
+    resp = await monitor_client.put(
+        '/log/dynamic-debug', params={'location': SERVICE_LOCATION},
+    )
+    assert resp.status_code == 200
+
+    dynamic_config.set_values({
+        'USERVER_LOG_DYNAMIC_DEBUG': {
+            'force-enabled': [],
+            'force-disabled': [SERVICE_LOCATION],
+        },
+    })
+
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+
+    assert not capture.select(text=SERVICE_LOGGED_TEXT)
+
+
+@SKIP_BROKEN_LOGS
+async def test_userver_dynamic_config_debug_logs_file_off(
+    service_client, dynamic_config, monitor_client, taxi_bodyless_headers_mock,
+):
+    resp = await monitor_client.put(
+        '/log/dynamic-debug', params={'location': USERVER_LOCATION_FILE},
+    )
+    assert resp.status_code == 200
+
+    dynamic_config.set_values({
+        'USERVER_LOG_DYNAMIC_DEBUG': {
+            'force-enabled': [],
+            'force-disabled': [USERVER_LOCATION_FILE],
+        },
+    })
+
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+
+    assert not capture.select(text=USERVER_LOGGED_TEXT)
+
+
+@SKIP_BROKEN_LOGS
+async def test_userver_dynamic_config_debug_logs_level_off(
+    service_client, dynamic_config, monitor_client, taxi_bodyless_headers_mock,
+):
+    resp = await monitor_client.put(
+        '/log/dynamic-debug', params={'location': SERVICE_LOCATION},
+    )
+    assert resp.status_code == 200
+
+    dynamic_config.set_values({
+        'USERVER_LOG_DYNAMIC_DEBUG': {
+            'force-enabled': [],
+            'force-disabled': [],
+            'force-enabled-level': {},
+            'force-disabled-level': {SERVICE_LOCATION: 'TRACE'},
+        },
+    })
+
+    async with service_client.capture_logs() as capture:
+        response = await service_client.get('/ping')
+        assert response.status_code == 200
+
+    assert not capture.select(text=SERVICE_LOGGED_TEXT)

core/src/components/logging_configurator.cpp

@@ -68,7 +68,7 @@ void LoggingConfigurator::OnConfigUpdate(const dynamic_config::Snapshot& config)
              */
 
             // Flush
-            logging::RemoveDynamicDebugLog("", logging::kAnyLine);
+            logging::RemoveAllDynamicDebugLog();
 
             for (const auto& [location, level] : dd.force_disabled) {
                 const auto [path, line] = logging::SplitLocation(location);

core/src/server/handlers/ping.cpp

@@ -23,6 +23,9 @@ std::string Ping::HandleRequestThrow(const http::HttpRequest& request, request::
     auto& response = request.GetHttpResponse();
     AppendWeightHeaders(response);
 
+#line 100  // for test_dynamic_debug_log.py
+    LOG_TRACE() << "Everything is OK";
+
     return {};
 }
 

universal/src/logging/dynamic_debug.cpp

@@ -85,6 +85,14 @@ void RemoveDynamicDebugLog(const std::string& location_relative, int line) {
     }
 }
 
+void RemoveAllDynamicDebugLog() {
+    utils::impl::AssertStaticRegistrationFinished();
+    auto& all_locations = GetAllLocations();
+    for (auto& location : all_locations) {
+        location.state.store(EntryState{});
+    }
+}
+
 const LogEntryContentSet& GetDynamicDebugLocations() {
     utils::impl::AssertStaticRegistrationFinished();
     return GetAllLocations();

universal/src/logging/dynamic_debug.hpp

@@ -57,6 +57,8 @@ void AddDynamicDebugLog(
 
 void RemoveDynamicDebugLog(const std::string& location_relative, int line);
 
+void RemoveAllDynamicDebugLog();
+
 const LogEntryContentSet& GetDynamicDebugLocations();
 
 void RegisterLogLocation(LogEntryContent& location);