diff --git a/Solutions/Clienttelemetry/Clienttelemetry.vcxitems b/Solutions/Clienttelemetry/Clienttelemetry.vcxitems index 065ca3118..630ac25c4 100644 --- a/Solutions/Clienttelemetry/Clienttelemetry.vcxitems +++ b/Solutions/Clienttelemetry/Clienttelemetry.vcxitems @@ -161,6 +161,7 @@ + diff --git a/Solutions/Clienttelemetry/Clienttelemetry.vcxitems.filters b/Solutions/Clienttelemetry/Clienttelemetry.vcxitems.filters index 376e1dfba..a065ed5bf 100644 --- a/Solutions/Clienttelemetry/Clienttelemetry.vcxitems.filters +++ b/Solutions/Clienttelemetry/Clienttelemetry.vcxitems.filters @@ -147,6 +147,9 @@ + + Header Files + diff --git a/Solutions/before.targets b/Solutions/before.targets index 43e18d434..1be68446e 100644 --- a/Solutions/before.targets +++ b/Solutions/before.targets @@ -2,6 +2,14 @@ $(SolutionDir)\..\third_party\krabsetw\krabs;$(CustomIncludePath) + + + + _SILENCE_EXPERIMENTAL_COROUTINE_DEPRECATION_WARNINGS;%(PreprocessorDefinitions) + $(SolutionDir)..\zlib;$(SolutionDir)..\sqlite;$(SolutionDir)..\lib\pal\universal;%(AdditionalIncludeDirectories) + + diff --git a/Solutions/net40/net40.vcxproj b/Solutions/net40/net40.vcxproj index d21aede17..6ae472e0f 100644 --- a/Solutions/net40/net40.vcxproj +++ b/Solutions/net40/net40.vcxproj @@ -21,7 +21,7 @@ {DC91621E-A203-42DF-8E03-3A23DD0602B1} - v4.0 + v4.8.1 ManagedCProj Microsoft.Applications.Telemetry.Windows net40 @@ -32,30 +32,30 @@ DynamicLibrary true - false + true Unicode false DynamicLibrary false - true + false Unicode - false + true DynamicLibrary true Unicode false - false + true DynamicLibrary false false Unicode - false + true diff --git a/Solutions/win32-cs/win32-cs.csproj b/Solutions/win32-cs/win32-cs.csproj index a93a15fa7..a2e37de23 100644 --- a/Solutions/win32-cs/win32-cs.csproj +++ b/Solutions/win32-cs/win32-cs.csproj @@ -10,7 +10,7 @@ Properties CLI win32-cs - v4.0 + v4.8.1 512 false @@ -39,7 +39,7 @@ prompt MinimumRecommendedRules.ruleset true - v4.0 + v4.8.1 true ..\..\out\Debug\x86\win32-cs\bin\ true @@ -52,7 +52,7 @@ prompt MinimumRecommendedRules.ruleset true - v4.0 + v4.8.1 true @@ -62,7 +62,7 @@ prompt MinimumRecommendedRules.ruleset false - v4.0 + v4.8.1 TRACE @@ -73,7 +73,7 @@ MinimumRecommendedRules.ruleset false true - v4.0 + v4.8.1 CLI.Program @@ -117,9 +117,9 @@ - + False - Microsoft .NET Framework 4 %28x86 and x64%29 + Microsoft .NET Framework 4.8.1 %28x86 and x64%29 true diff --git a/Solutions/win32-lib/win32-lib.vcxproj b/Solutions/win32-lib/win32-lib.vcxproj index 1b9fb6a7c..aeed3a4c6 100644 --- a/Solutions/win32-lib/win32-lib.vcxproj +++ b/Solutions/win32-lib/win32-lib.vcxproj @@ -253,7 +253,7 @@ Level4 Disabled ZLIB_WINAPI;WIN32;WIN32;NOMINMAX;_DEBUG;_WINDOWS;_USRDLL;WINVER=_WIN32_WINNT_WIN7;NOMINMAX;%(PreprocessorDefinitions) - $(ProjectDir)..\..\lib;$(ProjectDir)..\..\lib\include\public;$(ProjectDir)..\..\lib\include\mat;$(ProjectDir)..\..\lib\include;$(ProjectDir)..\..\bondlite\include;$(ProjectDir);$(GeneratedFilesDir);$(IntDir);%(AdditionalIncludeDirectories) + $(ProjectDir)..\..\lib;$(ProjectDir)..\..\lib\pal;$(ProjectDir)..\..\lib\include\public;$(ProjectDir)..\..\lib\include\mat;$(ProjectDir)..\..\lib\include;$(ProjectDir)..\..\bondlite\include;$(ProjectDir)..\..\zlib;$(ProjectDir)..\..\sqlite;$(ProjectDir);$(GeneratedFilesDir);$(IntDir);%(AdditionalIncludeDirectories) ProgramDatabase false false @@ -321,7 +321,7 @@ Level4 Disabled ZLIB_WINAPI;WIN32;NOMINMAX;_DEBUG;_WINDOWS;_USRDLL;WINVER=_WIN32_WINNT_WIN7;%(PreprocessorDefinitions) - $(ProjectDir)..\..\lib;$(ProjectDir)..\..\lib\include\public;$(ProjectDir)..\..\lib\include\mat;$(ProjectDir)..\..\lib\include;$(ProjectDir)..\..\bondlite\include;$(ProjectDir);$(GeneratedFilesDir);$(IntDir);%(AdditionalIncludeDirectories) + $(ProjectDir)..\..\lib;$(ProjectDir)..\..\lib\pal;$(ProjectDir)..\..\lib\include\public;$(ProjectDir)..\..\lib\include\mat;$(ProjectDir)..\..\lib\include;$(ProjectDir)..\..\bondlite\include;$(ProjectDir)..\..\zlib;$(ProjectDir)..\..\sqlite;$(ProjectDir);$(GeneratedFilesDir);$(IntDir);%(AdditionalIncludeDirectories) ProgramDatabase false false @@ -396,7 +396,7 @@ true false ZLIB_WINAPI;WIN32;NOMINMAX;NDEBUG;_WINDOWS;_USRDLL;WINVER=_WIN32_WINNT_WIN7;%(PreprocessorDefinitions) - $(ProjectDir)..\..\lib;$(ProjectDir)..\..\lib\include\public;$(ProjectDir)..\..\lib\include\mat;$(ProjectDir)..\..\lib\include;$(ProjectDir)..\..\bondlite\include;$(ProjectDir);$(GeneratedFilesDir);$(IntDir);%(AdditionalIncludeDirectories) + $(ProjectDir)..\..\lib;$(ProjectDir)..\..\lib\pal;$(ProjectDir)..\..\lib\include\public;$(ProjectDir)..\..\lib\include\mat;$(ProjectDir)..\..\lib\include;$(ProjectDir)..\..\bondlite\include;$(ProjectDir)..\..\zlib;$(ProjectDir)..\..\sqlite;$(ProjectDir);$(GeneratedFilesDir);$(IntDir);%(AdditionalIncludeDirectories) false false All @@ -472,7 +472,7 @@ true false ZLIB_WINAPI;WIN32;NOMINMAX;NDEBUG;_WINDOWS;_USRDLL;WINVER=_WIN32_WINNT_WIN7;%(PreprocessorDefinitions) - $(ProjectDir)..\..\lib;$(ProjectDir)..\..\lib\include\public;$(ProjectDir)..\..\lib\include\mat;$(ProjectDir)..\..\lib\include;$(ProjectDir)..\..\bondlite\include;$(ProjectDir);$(GeneratedFilesDir);$(IntDir);%(AdditionalIncludeDirectories) + $(ProjectDir)..\..\lib;$(ProjectDir)..\..\lib\pal;$(ProjectDir)..\..\lib\include\public;$(ProjectDir)..\..\lib\include\mat;$(ProjectDir)..\..\lib\include;$(ProjectDir)..\..\bondlite\include;$(ProjectDir)..\..\zlib;$(ProjectDir)..\..\sqlite;$(ProjectDir);$(GeneratedFilesDir);$(IntDir);%(AdditionalIncludeDirectories) false false All diff --git a/examples/c/SampleC-Guest/CMakeLists.txt b/examples/c/SampleC-Guest/CMakeLists.txt index 06a7d85b5..f64d0bcd6 100644 --- a/examples/c/SampleC-Guest/CMakeLists.txt +++ b/examples/c/SampleC-Guest/CMakeLists.txt @@ -6,8 +6,10 @@ project(SampleC-Guest) include(${CMAKE_CURRENT_LIST_DIR}/../../cmake/MSTelemetrySample.cmake) -set(CMAKE_C_FLAGS "${CMAKE_C_FLAGS} -O0 -ggdb -gdwarf-2 -std=c11") -set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -O0 -ggdb -gdwarf-2 -std=c++11") +if(NOT MSVC) + set(CMAKE_C_FLAGS "${CMAKE_C_FLAGS} -O0 -ggdb -gdwarf-2 -std=c11") + set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -O0 -ggdb -gdwarf-2 -std=c++11") +endif() find_package (Threads) @@ -20,4 +22,4 @@ source_group(" " REGULAR_EXPRESSION "") # The 1DS SDK's required Apple frameworks are provided by MATSDK_SAMPLE_PLATFORM_LIBS. -target_link_libraries(SampleC-Guest ${MATSDK_LIBRARY} curl z ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} dl) +target_link_libraries(SampleC-Guest ${MATSDK_LIBRARY} ${MATSDK_SAMPLE_DEPENDENCY_LIBS} ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS}) diff --git a/examples/cmake/MSTelemetrySample.cmake b/examples/cmake/MSTelemetrySample.cmake index 5a7eca8ab..684a19893 100644 --- a/examples/cmake/MSTelemetrySample.cmake +++ b/examples/cmake/MSTelemetrySample.cmake @@ -13,9 +13,20 @@ if(NOT EXISTS "${MATSDK_LIB_DIR}/libmat.a" set(MATSDK_LIB_DIR "${MATSDK_LIB_DIR}/${CMAKE_SYSTEM_PROCESSOR}-linux-gnu" CACHE PATH "MSTelemetry library directory" FORCE) endif() -find_library(MATSDK_LIBRARY NAMES mat HINTS "${MATSDK_LIB_DIR}" NO_DEFAULT_PATH) -if(NOT MATSDK_LIBRARY) - message(FATAL_ERROR "Could not find libmat under ${MATSDK_LIB_DIR}. Set MATSDK_INSTALL_DIR or MATSDK_LIB_DIR.") +find_package(MSTelemetry CONFIG QUIET + PATHS "${MATSDK_INSTALL_DIR}/lib/cmake/MSTelemetry" + NO_DEFAULT_PATH) +if(TARGET MSTelemetry::mat) + set(MATSDK_LIBRARY MSTelemetry::mat) + set(MATSDK_SAMPLE_DEPENDENCY_LIBS "") +else() + find_library(MATSDK_LIBRARY NAMES mat HINTS "${MATSDK_LIB_DIR}" NO_DEFAULT_PATH) + if(NOT MATSDK_LIBRARY) + message(FATAL_ERROR "Could not find libmat under ${MATSDK_LIB_DIR}. Set MATSDK_INSTALL_DIR or MATSDK_LIB_DIR.") + endif() + find_package(CURL REQUIRED) + find_package(ZLIB REQUIRED) + set(MATSDK_SAMPLE_DEPENDENCY_LIBS CURL::libcurl ZLIB::ZLIB) endif() if(NOT EXISTS "${MATSDK_INCLUDE_DIR}") @@ -40,9 +51,13 @@ if(APPLE) endif() endif() -find_library(MATSDK_SQLITE3_LIB NAMES sqlite3 HINTS "${MATSDK_INSTALL_DIR}/lib" NO_DEFAULT_PATH) -if(NOT MATSDK_SQLITE3_LIB) - set(MATSDK_SQLITE3_LIB sqlite3) +if(TARGET MSTelemetry::mat) + set(MATSDK_SQLITE3_LIB "") +else() + find_library(MATSDK_SQLITE3_LIB NAMES sqlite3 sqlite3_bundled HINTS "${MATSDK_INSTALL_DIR}/lib" NO_DEFAULT_PATH) + if(NOT MATSDK_SQLITE3_LIB) + set(MATSDK_SQLITE3_LIB sqlite3) + endif() endif() mark_as_advanced(MATSDK_INSTALL_DIR MATSDK_INCLUDE_DIR MATSDK_LIB_DIR MATSDK_LIBRARY MATSDK_SQLITE3_LIB) diff --git a/examples/cpp/EventSender/CMakeLists.txt b/examples/cpp/EventSender/CMakeLists.txt index 223ebb785..76a86982b 100644 --- a/examples/cpp/EventSender/CMakeLists.txt +++ b/examples/cpp/EventSender/CMakeLists.txt @@ -23,4 +23,4 @@ source_group(" " REGULAR_EXPRESSION "") #tcmalloc turned off by default #target_link_libraries(EventSender ${MATSDK_LIBRARY} curl z ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} dl tcmalloc) -target_link_libraries(EventSender ${MATSDK_LIBRARY} curl z ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} dl) +target_link_libraries(EventSender ${MATSDK_LIBRARY} ${MATSDK_SAMPLE_DEPENDENCY_LIBS} ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS}) diff --git a/examples/cpp/MacProxy/CMakeLists.txt b/examples/cpp/MacProxy/CMakeLists.txt index 04dfa5d01..082ee5fed 100644 --- a/examples/cpp/MacProxy/CMakeLists.txt +++ b/examples/cpp/MacProxy/CMakeLists.txt @@ -26,4 +26,4 @@ if (CMAKE_SYSTEM_PROCESSOR STREQUAL "armv7l") set (PLATFORM_LIBS "atomic") endif() -target_link_libraries(MacProxy ${MATSDK_LIBRARY} curl z ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} ${PLATFORM_LIBS} dl) +target_link_libraries(MacProxy ${MATSDK_LIBRARY} ${MATSDK_SAMPLE_DEPENDENCY_LIBS} ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} ${PLATFORM_LIBS}) diff --git a/examples/cpp/SampleCpp/CMakeLists.txt b/examples/cpp/SampleCpp/CMakeLists.txt index bfa90995e..4cc763ceb 100644 --- a/examples/cpp/SampleCpp/CMakeLists.txt +++ b/examples/cpp/SampleCpp/CMakeLists.txt @@ -6,8 +6,10 @@ project(SampleCpp) include(${CMAKE_CURRENT_LIST_DIR}/../../cmake/MSTelemetrySample.cmake) -set(CMAKE_C_FLAGS "${CMAKE_C_FLAGS} -O0 -ggdb -gdwarf-2 -std=c11") -set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -O0 -ggdb -gdwarf-2 -std=c++11") +if(NOT MSVC) + set(CMAKE_C_FLAGS "${CMAKE_C_FLAGS} -O0 -ggdb -gdwarf-2 -std=c11") + set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -O0 -ggdb -gdwarf-2 -std=c++11") +endif() find_package (Threads) @@ -30,4 +32,4 @@ endif() #target_link_libraries(SampleCpp ${MATSDK_LIBRARY} curl z ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} ${PLATFORM_LIBS} dl tcmalloc) # TODO: use add_library to allow linking against a proper exported SDK target -target_link_libraries(SampleCpp ${MATSDK_LIBRARY} curl z ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} ${PLATFORM_LIBS} dl) +target_link_libraries(SampleCpp ${MATSDK_LIBRARY} ${MATSDK_SAMPLE_DEPENDENCY_LIBS} ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} ${PLATFORM_LIBS}) diff --git a/examples/cpp/SampleCppMini/CMakeLists.txt b/examples/cpp/SampleCppMini/CMakeLists.txt index a2c33224f..181aff4ce 100644 --- a/examples/cpp/SampleCppMini/CMakeLists.txt +++ b/examples/cpp/SampleCppMini/CMakeLists.txt @@ -6,8 +6,10 @@ project(SampleCppMini) include(${CMAKE_CURRENT_LIST_DIR}/../../cmake/MSTelemetrySample.cmake) -set(CMAKE_C_FLAGS "${CMAKE_C_FLAGS} -O0 -ggdb -gdwarf-2 -std=c11") -set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -O0 -ggdb -gdwarf-2 -std=c++11") +if(NOT MSVC) + set(CMAKE_C_FLAGS "${CMAKE_C_FLAGS} -O0 -ggdb -gdwarf-2 -std=c11") + set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -O0 -ggdb -gdwarf-2 -std=c++11") +endif() find_package (Threads) @@ -23,4 +25,4 @@ source_group(" " REGULAR_EXPRESSION "") #tcmalloc turned off by default #target_link_libraries(SampleCppMini ${MATSDK_LIBRARY} curl z ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} dl tcmalloc) -target_link_libraries(SampleCppMini ${MATSDK_LIBRARY} curl z ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} dl) +target_link_libraries(SampleCppMini ${MATSDK_LIBRARY} ${MATSDK_SAMPLE_DEPENDENCY_LIBS} ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS}) diff --git a/examples/cs/SampleCsNet40/SampleCsNet40.csproj b/examples/cs/SampleCsNet40/SampleCsNet40.csproj index 5d30599df..7a06273e8 100644 --- a/examples/cs/SampleCsNet40/SampleCsNet40.csproj +++ b/examples/cs/SampleCsNet40/SampleCsNet40.csproj @@ -11,7 +11,7 @@ Properties CLI SampleCsNet40 - v4.0 + v4.8.1 512 false @@ -43,7 +43,7 @@ prompt MinimumRecommendedRules.ruleset true - v4.0 + v4.8.1 true true .\ @@ -56,7 +56,7 @@ prompt MinimumRecommendedRules.ruleset true - v4.0 + v4.8.1 .\ @@ -67,7 +67,7 @@ prompt MinimumRecommendedRules.ruleset false - v4.0 + v4.8.1 bin\ @@ -79,7 +79,7 @@ MinimumRecommendedRules.ruleset false true - v4.0 + v4.8.1 bin\ @@ -114,9 +114,9 @@ - + False - Microsoft .NET Framework 4 %28x86 and x64%29 + Microsoft .NET Framework 4.8.1 %28x86 and x64%29 true @@ -132,7 +132,7 @@ - C:\Program Files (x86)\Reference Assemblies\Microsoft\Framework\.NETFramework\v4.0\Microsoft.CSharp.dll + C:\Program Files (x86)\Reference Assemblies\Microsoft\Framework\.NETFramework\v4.8.1\Microsoft.CSharp.dll diff --git a/examples/cs/SampleCsUWP/SampleCsUWP.csproj b/examples/cs/SampleCsUWP/SampleCsUWP.csproj index 4c73a88f9..c488e2bdc 100644 --- a/examples/cs/SampleCsUWP/SampleCsUWP.csproj +++ b/examples/cs/SampleCsUWP/SampleCsUWP.csproj @@ -11,7 +11,7 @@ SampleCsUWP en-US UAP - 10.0.17763.0 + 10.0.22621.0 10.0.10240.0 14 512 diff --git a/examples/objc/cocoa-app/CMakeLists.txt b/examples/objc/cocoa-app/CMakeLists.txt index 353098e92..70285039a 100644 --- a/examples/objc/cocoa-app/CMakeLists.txt +++ b/examples/objc/cocoa-app/CMakeLists.txt @@ -42,4 +42,4 @@ set_target_properties( ${CMAKE_CURRENT_LIST_DIR}/plist.in ) -target_link_libraries(foo ${MATSDK_LIBRARY} curl z ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} ${PLATFORM_LIBS} dl) +target_link_libraries(foo ${MATSDK_LIBRARY} ${MATSDK_SAMPLE_DEPENDENCY_LIBS} ${CMAKE_THREAD_LIBS_INIT} ${MATSDK_SQLITE3_LIB} ${MATSDK_SAMPLE_PLATFORM_LIBS} ${PLATFORM_LIBS}) diff --git a/lib/api/LogConfiguration.cpp b/lib/api/LogConfiguration.cpp index 23a7e53cd..0eb6581b2 100644 --- a/lib/api/LogConfiguration.cpp +++ b/lib/api/LogConfiguration.cpp @@ -19,6 +19,7 @@ namespace MAT_NS_BEGIN { { CFG_BOOL_ENABLE_ANALYTICS, false }, { CFG_INT_CACHE_FILE_SIZE, 3145728 }, { CFG_INT_RAM_QUEUE_SIZE, 524288 }, + { CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH, true }, { CFG_BOOL_ENABLE_MULTITENANT, true }, { CFG_BOOL_ENABLE_DB_DROP_IF_FULL, false }, { CFG_INT_MAX_TEARDOWN_TIME, 0 }, @@ -51,6 +52,7 @@ namespace MAT_NS_BEGIN { { CFG_BOOL_ENABLE_ANALYTICS, src.enableLifecycleSession }, { CFG_INT_CACHE_FILE_SIZE, src.cacheFileSizeLimitInBytes }, { CFG_INT_RAM_QUEUE_SIZE, src.cacheMemorySizeLimitInBytes }, + { CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH, true }, { CFG_BOOL_ENABLE_MULTITENANT, src.multiTenantEnabled }, { CFG_INT_MAX_TEARDOWN_TIME, src.maxTeardownUploadTimeInSec }, { CFG_INT_MAX_PENDING_REQ, src.maxPendingHTTPRequests }, @@ -128,4 +130,3 @@ namespace MAT_NS_BEGIN { } } MAT_NS_END - diff --git a/lib/api/LogManagerFactory.hpp b/lib/api/LogManagerFactory.hpp index 5e26267d8..63adfb646 100644 --- a/lib/api/LogManagerFactory.hpp +++ b/lib/api/LogManagerFactory.hpp @@ -67,7 +67,15 @@ namespace MAT_NS_BEGIN { // C++11 Magic Statics (N2660) static LogManagerFactory& instance() { - static LogManagerFactory impl; + // Deliberately never destroyed. LogManagerProvider::Release() must be + // able to walk this factory's registries during process teardown, but + // a normal function-local static's destruction order relative to that + // teardown call is unspecified -- if this were destroyed first, + // Release() would walk already-freed std::map nodes (a downstream + // consumer observed this as EXC_BAD_ACCESS in release() at process + // exit). Leaking one small, fixed-size object avoids the ordering + // hazard entirely; the OS reclaims it when the process exits. + static LogManagerFactory& impl = *new LogManagerFactory(); return impl; } diff --git a/lib/api/LogManagerImpl.cpp b/lib/api/LogManagerImpl.cpp index 24215c0cd..2e8a0f896 100644 --- a/lib/api/LogManagerImpl.cpp +++ b/lib/api/LogManagerImpl.cpp @@ -2,11 +2,16 @@ // Copyright (c) Microsoft Corporation. All rights reserved. // SPDX-License-Identifier: Apache-2.0 // -#ifdef _MSC_VER -// evntprov.h(838) : warning C4459 : declaration of 'Version' hides global declaration -#pragma warning(disable : 4459) +#ifdef _WIN32 +// Include the SDK declaration before the telemetry Version symbol enters scope. +#ifndef WIN32_LEAN_AND_MEAN +#define WIN32_LEAN_AND_MEAN +#endif +#include +#include #endif #include "LogManagerImpl.hpp" +#include #include "mat/config.h" #include "offline/LogSessionDataProvider.hpp" @@ -368,9 +373,27 @@ namespace MAT_NS_BEGIN LogManagerImpl::~LogManagerImpl() noexcept { - FlushAndTeardown(); - LOCKGUARD(ILogManagerInternal::managers_lock); - ILogManagerInternal::managers.erase(this); + try + { + FlushAndTeardown(); + } + catch (const std::exception& e) + { + std::fprintf(stderr, "Log manager teardown failed: %s\n", e.what()); + } + catch (...) + { + std::fputs("Log manager teardown failed with an unknown exception\n", stderr); + } + try + { + LOCKGUARD(ILogManagerInternal::managers_lock); + ILogManagerInternal::managers.erase(this); + } + catch (...) + { + std::fputs("Log manager registry cleanup failed\n", stderr); + } } size_t LogManagerImpl::GetDeadLoggerCount() @@ -959,19 +982,30 @@ namespace MAT_NS_BEGIN return true; } - void LogManagerImpl::EndActivity() + void LogManagerImpl::EndActivity() noexcept { - std::unique_lock lock(m_pause_mutex); - if (m_pause_active_count == 0) { - return; + try + { + std::unique_lock lock(m_pause_mutex); + if (m_pause_active_count == 0) { + return; + } + m_pause_active_count -= 1; + if (m_pause_active_count > 0) { + return; + } + if (m_pause_state == PauseState::Pausing) { + m_pause_state = PauseState::Paused; + m_pause_cv.notify_all(); + } } - m_pause_active_count -= 1; - if (m_pause_active_count > 0) { - return; + catch (const std::exception& e) + { + std::fprintf(stderr, "Failed to end telemetry activity: %s\n", e.what()); } - if (m_pause_state == PauseState::Pausing) { - m_pause_state = PauseState::Paused; - m_pause_cv.notify_all(); + catch (...) + { + std::fputs("Failed to end telemetry activity\n", stderr); } } } diff --git a/lib/api/LogManagerImpl.hpp b/lib/api/LogManagerImpl.hpp index 7dd7f7442..75e062868 100644 --- a/lib/api/LogManagerImpl.hpp +++ b/lib/api/LogManagerImpl.hpp @@ -306,7 +306,7 @@ namespace MAT_NS_BEGIN virtual void ResumeActivity() override; virtual void WaitPause() override; virtual bool StartActivity() override; - virtual void EndActivity() override; + virtual void EndActivity() noexcept override; protected: std::unique_ptr& GetSystem(); diff --git a/lib/api/Logger.cpp b/lib/api/Logger.cpp index aec4b9e52..75d3bd292 100644 --- a/lib/api/Logger.cpp +++ b/lib/api/Logger.cpp @@ -127,7 +127,8 @@ namespace MAT_NS_BEGIN Logger::~Logger() noexcept { - LOG_TRACE("%p: Destroyed", this); + // Intentionally empty — logging here triggers a static-destruction-order + // crash on iOS simulator (recursive_mutex used after teardown). } ISemanticContext* Logger::GetSemanticContext() const diff --git a/lib/config/RuntimeConfig_Default.hpp b/lib/config/RuntimeConfig_Default.hpp index 504aeefe3..4b2da9612 100644 --- a/lib/config/RuntimeConfig_Default.hpp +++ b/lib/config/RuntimeConfig_Default.hpp @@ -16,6 +16,7 @@ namespace MAT_NS_BEGIN {CFG_BOOL_ENABLE_ANALYTICS, false}, {CFG_INT_CACHE_FILE_SIZE, 3145728}, {CFG_INT_RAM_QUEUE_SIZE, 524288}, + {CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH, true}, {CFG_BOOL_ENABLE_MULTITENANT, true}, {CFG_BOOL_ENABLE_DB_DROP_IF_FULL, false}, {CFG_INT_MAX_TEARDOWN_TIME, 1}, @@ -233,4 +234,3 @@ namespace MAT_NS_BEGIN } MAT_NS_END - diff --git a/lib/http/HttpClient_Apple.mm b/lib/http/HttpClient_Apple.mm index 1a047f5d6..834f58706 100644 --- a/lib/http/HttpClient_Apple.mm +++ b/lib/http/HttpClient_Apple.mm @@ -207,9 +207,11 @@ void HandleResponse(NSData* data, NSURLResponse* response, NSError* error) NSHTTPURLResponse *httpResp = static_cast(response); auto simpleResponse = new SimpleHttpResponse { NextRespId() }; - simpleResponse->m_statusCode = static_cast(httpResp.statusCode); + simpleResponse->m_statusCode = httpResp != nil + ? static_cast(httpResp.statusCode) + : 0; - NSDictionary *responseHeaders = [httpResp allHeaderFields]; + NSDictionary *responseHeaders = httpResp != nil ? [httpResp allHeaderFields] : nil; for (id key in responseHeaders) { simpleResponse->m_headers.add([key UTF8String], [responseHeaders[key] UTF8String]); @@ -299,7 +301,6 @@ void Cancel() LOG_TRACE("HTTP request=%p id=%s being aborted...", request, id.c_str()); request->Cancel(); } - m_requests.erase(id); } } } @@ -317,17 +318,6 @@ void Cancel() for (const auto &id : ids) CancelRequestAsync(id); - for (;;) - { - { - std::lock_guard lock(m_requestsMtx); - if (m_requests.empty()) - { - return; - } - } - PAL::sleep(100); - } } void HttpClient_Apple::Erase(IHttpRequest* req) diff --git a/lib/http/HttpClient_WinInet.cpp b/lib/http/HttpClient_WinInet.cpp index 2ec8be9b0..4f7d18a03 100644 --- a/lib/http/HttpClient_WinInet.cpp +++ b/lib/http/HttpClient_WinInet.cpp @@ -6,8 +6,6 @@ #include "mat/config.h" #ifdef HAVE_MAT_DEFAULT_HTTP_CLIENT -#pragma warning(push) -#pragma warning(disable:4189) /* Turn off Level 4: local variable is initialized but not referenced. dwError unused in Release without printing it. */ #include "HttpClient_WinInet.hpp" #include "utils/StringUtils.hpp" @@ -55,6 +53,9 @@ class WinInetRequestWrapper if (m_hWinInetRequest != nullptr) { ::InternetCloseHandle(m_hWinInetRequest); + } + if (m_hWinInetSession != nullptr) + { ::InternetCloseHandle(m_hWinInetSession); } } @@ -187,6 +188,7 @@ class WinInetRequestWrapper if (!::InternetCrackUrlA(m_request->m_url.data(), (DWORD)m_request->m_url.size(), 0, &urlc)) { DWORD dwError = ::GetLastError(); + (void)dwError; LOG_WARN("InternetCrackUrl() failed: dwError=%d url=%s", dwError, m_request->m_url.data()); // Invalid URL passed to WinInet API DispatchEvent(OnConnectFailed); @@ -198,6 +200,7 @@ class WinInetRequestWrapper NULL, NULL, INTERNET_SERVICE_HTTP, 0, reinterpret_cast(this)); if (m_hWinInetSession == NULL) { DWORD dwError = ::GetLastError(); + (void)dwError; LOG_WARN("InternetConnect() failed: %d", dwError); // Cannot connect to host DispatchEvent(OnConnectFailed); @@ -215,6 +218,7 @@ class WinInetRequestWrapper reinterpret_cast(this)); if (m_hWinInetRequest == NULL) { DWORD dwError = ::GetLastError(); + (void)dwError; LOG_WARN("HttpOpenRequest() failed: %d", dwError); // Request cannot be opened to given URL because of some connectivity issue DispatchEvent(OnConnectFailed); @@ -244,6 +248,7 @@ class WinInetRequestWrapper if (!::HttpAddRequestHeadersA(m_hWinInetRequest, os.str().data(), static_cast(os.tellp()), HTTP_ADDREQ_FLAG_ADD | HTTP_ADDREQ_FLAG_REPLACE)) { DWORD dwError = ::GetLastError(); + (void)dwError; LOG_WARN("HttpAddRequestHeadersA() failed: %d", dwError); // Unable to add request headers. There's no point in proceeding with upload because // our server is expecting those custom request headers to always be there. @@ -604,6 +609,5 @@ bool HttpClient_WinInet::IsMsRootCheckRequired() } } MAT_NS_END -#pragma warning(pop) #endif // HAVE_MAT_DEFAULT_HTTP_CLIENT // clang-format on diff --git a/lib/http/HttpResponseDecoder.cpp b/lib/http/HttpResponseDecoder.cpp index 6014cec19..b46eeff98 100644 --- a/lib/http/HttpResponseDecoder.cpp +++ b/lib/http/HttpResponseDecoder.cpp @@ -67,13 +67,11 @@ namespace MAT_NS_BEGIN { break; case HttpResult_Aborted: - ctx->httpResponse = nullptr; outcome = Abort; break; case HttpResult_LocalFailure: case HttpResult_NetworkFailure: - ctx->httpResponse = nullptr; outcome = RetryNetwork; break; } @@ -132,7 +130,6 @@ namespace MAT_NS_BEGIN { evt.param2 = ctx->recordIdsAndTenantIds.size(); DispatchEvent(evt); } - ctx->httpResponse = nullptr; // eventsRejected(ctx); // FIXME: [MG] - investigate why ctx gets corrupt after eventsRejected requestAborted(ctx); break; diff --git a/lib/include/mat/config-default.h b/lib/include/mat/config-default.h index 2ddce7dfc..f4d1af2ae 100644 --- a/lib/include/mat/config-default.h +++ b/lib/include/mat/config-default.h @@ -8,7 +8,9 @@ #if defined(_WIN32) #if defined __has_include # if __has_include ("modules/azmon/AITelemetrySystem.hpp") +# ifndef HAVE_MAT_AI # define HAVE_MAT_AI +# endif # endif # if __has_include ("modules/utc/UtcTelemetrySystem.hpp") # define HAVE_MAT_UTC @@ -51,4 +53,3 @@ //#define HAVE_CS4 //#define HAVE_CS4_FULL //#define HAVE_ONEDS_BOUNDCHECK_METHODS - diff --git a/lib/include/public/ILogConfiguration.hpp b/lib/include/public/ILogConfiguration.hpp index af1bc44c2..f1119c11d 100644 --- a/lib/include/public/ILogConfiguration.hpp +++ b/lib/include/public/ILogConfiguration.hpp @@ -154,6 +154,12 @@ namespace MAT_NS_BEGIN /// static constexpr const char* const CFG_INT_RAM_QUEUE_BUFFERS = "maxDBFlushQueues"; + /// + /// Batch records when flushing the RAM queue to disk storage. + /// Set to false to use per-record disk stores during flush. + /// + static constexpr const char* const CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH = "enableBatchedStorageFlush"; + /// /// SQLite DB will be checkpointed when flushing. /// @@ -481,4 +487,3 @@ namespace MAT_NS_BEGIN } MAT_NS_END #endif - diff --git a/lib/include/public/ITaskDispatcher.hpp b/lib/include/public/ITaskDispatcher.hpp index 070f054bc..943b29b03 100644 --- a/lib/include/public/ITaskDispatcher.hpp +++ b/lib/include/public/ITaskDispatcher.hpp @@ -115,12 +115,17 @@ namespace MAT_NS_BEGIN virtual void Queue(Task* task) = 0; /// - /// Cancel a previously queued tasks + /// Cancel a previously queued task /// - /// Task to be cancelled + /// + /// Opaque task identity to cancel. The task may complete concurrently; + /// implementations must not dereference this pointer outside their own + /// queue/execution synchronization. + /// /// Amount of time to wait for if the task is currently executing /// True if successfully cancelled, else false virtual bool Cancel(Task* task, uint64_t waitTime = 0) = 0; + }; /// @endcond @@ -128,4 +133,3 @@ namespace MAT_NS_BEGIN } MAT_NS_END #endif // ITASKDISPATCHER_HPP - diff --git a/lib/jni/PrivacyGuard_jni.cpp b/lib/jni/PrivacyGuard_jni.cpp index 8fd23867a..e070577b0 100644 --- a/lib/jni/PrivacyGuard_jni.cpp +++ b/lib/jni/PrivacyGuard_jni.cpp @@ -7,6 +7,9 @@ #include "modules/privacyguard/PrivacyGuard.hpp" #include "PrivacyGuardHelper.hpp" +#include +#include + using namespace MAT; CommonDataContext GenerateCommonDataContextObject(JNIEnv* env, @@ -36,10 +39,61 @@ CommonDataContext GenerateCommonDataContextObject(JNIEnv* env, return cdc; } -std::shared_ptr spPrivacyGuard; +namespace +{ + std::shared_ptr spPrivacyGuard; + std::mutex privacyGuardMutex; + + struct EventNameStorage + { + std::string notification; + std::string semanticContext; + std::string summary; + }; + + void SetEventNames( + JNIEnv* env, + jstring notificationEventName, + jstring semanticContextEventName, + jstring summaryEventName, + EventNameStorage& storage, + InitializationConfiguration& config) + { + if (notificationEventName != nullptr) { + storage.notification = JStringToStdString(env, notificationEventName); + config.NotificationEventName = storage.notification.c_str(); + } + + if (semanticContextEventName != nullptr) { + storage.semanticContext = JStringToStdString(env, semanticContextEventName); + config.SemanticContextNotificationEventName = storage.semanticContext.c_str(); + } + + if (summaryEventName != nullptr) { + storage.summary = JStringToStdString(env, summaryEventName); + config.SummaryEventName = storage.summary.c_str(); + } + } + + std::shared_ptr CreatePrivacyGuard( + const InitializationConfiguration& config, + std::shared_ptr eventNameStorage) + { + // Log managers can retain the guard after JNI uninitialization. Keep the + // strings backing its raw event-name pointers alive until the last owner + // releases the guard. + return std::shared_ptr( + new PrivacyGuard(config), + [eventNameStorage](PrivacyGuard* privacyGuard) { + (void)eventNameStorage; + delete privacyGuard; + }); + } +} std::shared_ptr PrivacyGuardHelper::GetPrivacyGuardPtr() noexcept { + std::lock_guard lock(privacyGuardMutex); return spPrivacyGuard; } @@ -55,6 +109,7 @@ Java_com_microsoft_applications_events_PrivacyGuard_nativeInitializePrivacyGuard jboolean ScanForUrls, jboolean DisableAdvancedScans, jboolean StampEventIKeyForConcerns) { + std::lock_guard lock(privacyGuardMutex); if (spPrivacyGuard != nullptr) { return false; } @@ -62,24 +117,15 @@ Java_com_microsoft_applications_events_PrivacyGuard_nativeInitializePrivacyGuard InitializationConfiguration config( reinterpret_cast(iLoggerNativePtr), CommonDataContext{}); - if (NotificationEventName != nullptr) { - config.NotificationEventName = JStringToStdString(env, NotificationEventName).c_str(); - } - - if (SemanticContextEventName != nullptr) { - config.SemanticContextNotificationEventName = JStringToStdString(env, SemanticContextEventName).c_str(); - } - - if (SummaryEventName != nullptr) { - config.SummaryEventName = JStringToStdString(env, SummaryEventName).c_str(); - } + auto eventNameStorage = std::make_shared(); + SetEventNames(env, NotificationEventName, SemanticContextEventName, SummaryEventName, *eventNameStorage, config); config.UseEventFieldPrefix = static_cast(UseEventFieldPrefix); config.ScanForUrls = static_cast(ScanForUrls); config.DisableAdvancedScans = static_cast(DisableAdvancedScans); config.StampEventIKeyForConcerns = static_cast(StampEventIKeyForConcerns); - spPrivacyGuard = std::make_shared(config); + spPrivacyGuard = CreatePrivacyGuard(config, std::move(eventNameStorage)); return true; } @@ -103,6 +149,7 @@ Java_com_microsoft_applications_events_PrivacyGuard_nativeInitializePrivacyGuard jobjectArray languageIdentifiers, jobjectArray machineIds, jobjectArray outOfScopeIdentifiers) { + std::lock_guard lock(privacyGuardMutex); if (spPrivacyGuard != nullptr) { return false; } @@ -119,24 +166,15 @@ Java_com_microsoft_applications_events_PrivacyGuard_nativeInitializePrivacyGuard machineIds, outOfScopeIdentifiers)); - if (NotificationEventName != NULL) { - config.NotificationEventName = JStringToStdString(env, NotificationEventName).c_str(); - } - - if (SemanticContextEventName != NULL) { - config.SemanticContextNotificationEventName = JStringToStdString(env, SemanticContextEventName).c_str(); - } - - if (SummaryEventName != NULL) { - config.SummaryEventName = JStringToStdString(env, SummaryEventName).c_str(); - } + auto eventNameStorage = std::make_shared(); + SetEventNames(env, NotificationEventName, SemanticContextEventName, SummaryEventName, *eventNameStorage, config); config.UseEventFieldPrefix = static_cast(UseEventFieldPrefix); config.ScanForUrls = static_cast(ScanForUrls); config.DisableAdvancedScans = static_cast(DisableAdvancedScans); config.StampEventIKeyForConcerns = static_cast(StampEventIKeyForConcerns); - spPrivacyGuard = std::make_shared(config); + spPrivacyGuard = CreatePrivacyGuard(config, std::move(eventNameStorage)); return true; } @@ -144,11 +182,11 @@ extern "C" JNIEXPORT jboolean JNICALL Java_com_microsoft_applications_events_PrivacyGuard_uninitialize(const JNIEnv *env, jclass /*this*/) { + std::lock_guard lock(privacyGuardMutex); if(spPrivacyGuard == nullptr) { return false; } - spPrivacyGuard.reset(); return true; @@ -157,17 +195,19 @@ Java_com_microsoft_applications_events_PrivacyGuard_uninitialize(const JNIEnv *e extern "C" JNIEXPORT jboolean JNICALL Java_com_microsoft_applications_events_PrivacyGuard_setEnabled(const JNIEnv *env, jclass /*this*/, jboolean isEnabled) { - if (spPrivacyGuard == nullptr) { + auto privacyGuard = PrivacyGuardHelper::GetPrivacyGuardPtr(); + if (privacyGuard == nullptr) { return false; } - spPrivacyGuard->SetEnabled(static_cast(isEnabled)); + privacyGuard->SetEnabled(static_cast(isEnabled)); return true; } extern "C" JNIEXPORT jboolean JNICALL Java_com_microsoft_applications_events_PrivacyGuard_isEnabled(const JNIEnv *env, jclass /*this*/) { - return spPrivacyGuard != nullptr && spPrivacyGuard->IsEnabled(); + auto privacyGuard = PrivacyGuardHelper::GetPrivacyGuardPtr(); + return privacyGuard != nullptr && privacyGuard->IsEnabled(); } extern "C" @@ -182,11 +222,12 @@ Java_com_microsoft_applications_events_PrivacyGuard_nativeAppendCommonDataContex jobjectArray languageIdentifiers, jobjectArray machineIds, jobjectArray outOfScopeIdentifiers) { - if (spPrivacyGuard == nullptr) { + auto privacyGuard = PrivacyGuardHelper::GetPrivacyGuardPtr(); + if (privacyGuard == nullptr) { return false; } - spPrivacyGuard->AppendCommonDataContext(GenerateCommonDataContextObject(env, + privacyGuard->AppendCommonDataContext(GenerateCommonDataContextObject(env, domainName, machineName, userNames, @@ -206,19 +247,19 @@ Java_com_microsoft_applications_events_PrivacyGuard_nativeAddIgnoredConcern(JNIE jstring eventName, jstring fieldName, jint dataConcern) { - if (spPrivacyGuard == nullptr) { + auto privacyGuard = PrivacyGuardHelper::GetPrivacyGuardPtr(); + if (privacyGuard == nullptr) { return; } auto eventNameStr = JStringToStdString(env, eventName); auto fieldNameStr = JStringToStdString(env, fieldName); auto dataConcernInt = static_cast(dataConcern); - spPrivacyGuard->AddIgnoredConcern(eventNameStr, fieldNameStr, static_cast(dataConcernInt)); + privacyGuard->AddIgnoredConcern(eventNameStr, fieldNameStr, static_cast(dataConcernInt)); } extern "C" JNIEXPORT jboolean JNICALL Java_com_microsoft_applications_events_PrivacyGuard_isInitialized(const JNIEnv *env, jclass/* this */){ - return spPrivacyGuard != nullptr; + return PrivacyGuardHelper::GetPrivacyGuardPtr() != nullptr; } - diff --git a/lib/modules b/lib/modules index 7bd8b516e..feea32d3b 160000 --- a/lib/modules +++ b/lib/modules @@ -1 +1 @@ -Subproject commit 7bd8b516e2d93d1704834e0895733ae7bc2d1f43 +Subproject commit feea32d3b6008662f9e00b32ac7c5a07af90cdfa diff --git a/lib/offline/IOfflineStorageProvider.hpp b/lib/offline/IOfflineStorageProvider.hpp new file mode 100644 index 000000000..3883893b8 --- /dev/null +++ b/lib/offline/IOfflineStorageProvider.hpp @@ -0,0 +1,30 @@ +// +// Copyright (c) Microsoft Corporation. All rights reserved. +// SPDX-License-Identifier: Apache-2.0 +// +#ifndef IOFFLINESTORAGEPROVIDER_HPP +#define IOFFLINESTORAGEPROVIDER_HPP + +#include "IOfflineStorage.hpp" + +#include + +namespace MAT_NS_BEGIN +{ + class IOfflineStorageProvider + { + public: + virtual ~IOfflineStorageProvider() = default; + + // Implementations may be shared by multiple handlers and must be + // thread-safe when Initialize is called concurrently. + virtual std::shared_ptr CreateDiskStorage( + ILogManager& logManager, IRuntimeConfig& runtimeConfig) = 0; + + virtual std::shared_ptr CreateMemoryStorage( + ILogManager& logManager, IRuntimeConfig& runtimeConfig) = 0; + }; +} +MAT_NS_END + +#endif // IOFFLINESTORAGEPROVIDER_HPP diff --git a/lib/offline/MemoryStorage.cpp b/lib/offline/MemoryStorage.cpp index 1d4ec5664..77ff0fc7c 100644 --- a/lib/offline/MemoryStorage.cpp +++ b/lib/offline/MemoryStorage.cpp @@ -224,6 +224,16 @@ namespace MAT_NS_BEGIN { void MemoryStorage::DeleteRecords(const std::map & whereFilter) { + // An empty filter matches every record. Never silently wipe the whole + // in-memory queue from a no-op predicate; callers must use + // DeleteAllRecords() for an intentional full clear. This mirrors the + // fail-closed behavior of OfflineStorage_SQLite::DeleteRecords. + if (whereFilter.empty()) + { + LOG_WARN("DeleteRecords called with an empty filter; ignoring to avoid deleting all records."); + return; + } + auto matcher = [&](const StorageRecord &r, const std::map & whereFilter) { bool matched = true; diff --git a/lib/offline/OfflineStorageFactory.cpp b/lib/offline/OfflineStorageFactory.cpp index 221d2997b..fff62c823 100644 --- a/lib/offline/OfflineStorageFactory.cpp +++ b/lib/offline/OfflineStorageFactory.cpp @@ -8,6 +8,7 @@ #include "OfflineStorageFactory.hpp" +#include "offline/MemoryStorage.hpp" #ifdef USE_ROOM #include "offline/OfflineStorage_Room.hpp" #else @@ -18,6 +19,25 @@ namespace MAT_NS_BEGIN { + namespace + { + class DefaultOfflineStorageProvider final : public IOfflineStorageProvider + { + public: + std::shared_ptr CreateDiskStorage( + ILogManager& logManager, IRuntimeConfig& runtimeConfig) override + { + return OfflineStorageFactory::Create(logManager, runtimeConfig); + } + + std::shared_ptr CreateMemoryStorage( + ILogManager& logManager, IRuntimeConfig& runtimeConfig) override + { + return std::make_shared(logManager, runtimeConfig); + } + }; + } + std::shared_ptr OfflineStorageFactory::Create(ILogManager& logManager, IRuntimeConfig& runtimeConfig) { #ifdef HAVE_MAT_STORAGE @@ -40,6 +60,14 @@ namespace MAT_NS_BEGIN return nullptr; #endif //HAVE_MAT_STORAGE } + + std::shared_ptr OfflineStorageFactory::GetDefaultProvider() + { + // The default provider is stateless; sharing it avoids per-handler + // allocation while preserving a stable provider lifetime. + static std::shared_ptr provider = + std::make_shared(); + return provider; + } } MAT_NS_END - diff --git a/lib/offline/OfflineStorageFactory.hpp b/lib/offline/OfflineStorageFactory.hpp index 103bb078a..3a8f38d13 100644 --- a/lib/offline/OfflineStorageFactory.hpp +++ b/lib/offline/OfflineStorageFactory.hpp @@ -6,6 +6,7 @@ #define OFFLINESTORAGEFACTORY_HPP #include "IOfflineStorage.hpp" +#include "IOfflineStorageProvider.hpp" #include "api/IRuntimeConfig.hpp" namespace MAT_NS_BEGIN @@ -14,9 +15,9 @@ namespace MAT_NS_BEGIN { public: static std::shared_ptr Create(ILogManager& logManager, IRuntimeConfig& runtimeConfig); + static std::shared_ptr GetDefaultProvider(); }; } MAT_NS_END #endif // HTTPCLIENTFACTORY_HPP - diff --git a/lib/offline/OfflineStorageHandler.cpp b/lib/offline/OfflineStorageHandler.cpp index 52ce15515..08a0a89f5 100644 --- a/lib/offline/OfflineStorageHandler.cpp +++ b/lib/offline/OfflineStorageHandler.cpp @@ -7,22 +7,42 @@ #include "OfflineStorageFactory.hpp" #include "offline/MemoryStorage.hpp" +#include "offline/StorageRecordValidation.hpp" #include "ILogManager.hpp" +#include "utils/Utils.hpp" #include +#include +#include +#include #include #include +#include namespace MAT_NS_BEGIN { + namespace + { + // Keep each persistence transaction bounded so a large in-memory backlog + // cannot monopolize memory or database locks. + constexpr unsigned MAX_RECORDS_PER_STORAGE_BATCH = 2000; + } + MATSDK_LOG_INST_COMPONENT_CLASS(OfflineStorageHandler, "EventsSDK.StorageHandler", "Events telemetry client - OfflineStorageHandler class") OfflineStorageHandler::OfflineStorageHandler(ILogManager& logManager, IRuntimeConfig& runtimeConfig, ITaskDispatcher& taskDispatcher) : + OfflineStorageHandler(logManager, runtimeConfig, taskDispatcher, OfflineStorageFactory::GetDefaultProvider()) + { + } + + OfflineStorageHandler::OfflineStorageHandler(ILogManager& logManager, IRuntimeConfig& runtimeConfig, + ITaskDispatcher& taskDispatcher, std::shared_ptr storageProvider) : m_observer(nullptr), m_logManager(logManager), m_config(runtimeConfig), m_taskDispatcher(taskDispatcher), + m_storageProvider(std::move(storageProvider)), m_killSwitchManager(), m_clockSkewManager(), m_flushPending(false), @@ -36,6 +56,11 @@ namespace MAT_NS_BEGIN { m_cacheMemorySizeLimitInBytes(0), m_isStorageFullNotificationSend(false) { + if (!m_storageProvider) + { + throw std::invalid_argument("OfflineStorageHandler requires a storage provider"); + } + // TODO: [MG] - OfflineStorage_SQLite.cpp is performing similar checks uint32_t percentage = m_config[CFG_INT_RAMCACHE_FULL_PCT]; uint32_t cacheMemorySizeLimitInBytes = m_config[CFG_INT_RAM_QUEUE_SIZE]; @@ -50,6 +75,64 @@ namespace MAT_NS_BEGIN { } } + /// + /// RAII guard around ILogManager::StartActivity()/EndActivity(). Flush() + /// used to pair these manually (StartActivity() at the top, EndActivity() + /// on the last line), so an exception thrown by disk I/O or by + /// IOfflineStorageObserver::OnStorageRecordsSaved() partway through would + /// skip EndActivity() and permanently leak the pause-activity count -- + /// deadlocking every later FlushAndTeardown()'s WaitPause(). This guard + /// guarantees EndActivity() runs on every exit path, matching the existing + /// safe pattern used by PauseGuard (TransmissionPolicyManager.cpp) and + /// ActiveLoggerCall (Logger.cpp). + /// + class ActivityGuard + { + public: + explicit ActivityGuard(ILogManager& logManager) : + m_logManager(logManager), + m_active(logManager.StartActivity()), + m_allowInactive(false) + { + } + + ActivityGuard(ILogManager& logManager, bool allowInactive) : + m_logManager(logManager), + m_active(logManager.StartActivity()), + m_allowInactive(allowInactive) + { + } + + ~ActivityGuard() noexcept + { + if (m_active) + { + try + { + m_logManager.EndActivity(); + } + catch (const std::exception& e) + { + std::fprintf(stderr, "Failed to end telemetry activity: %s\n", e.what()); + } + catch (...) + { + std::fputs("Failed to end telemetry activity\n", stderr); + } + } + } + + ActivityGuard(ActivityGuard const&) = delete; + ActivityGuard& operator=(ActivityGuard const&) = delete; + + bool IsActive() const noexcept { return m_active || m_allowInactive; } + + private: + ILogManager& m_logManager; + bool m_active; + bool m_allowInactive; + }; + bool OfflineStorageHandler::isKilled(StorageRecord const& record) { return ( @@ -64,7 +147,8 @@ namespace MAT_NS_BEGIN { if (!m_flushPending) return; } - LOG_INFO("Waiting for pending Flush (%p) to complete...", m_flushHandle.m_task); + LOG_INFO("Waiting for pending Flush (%p) to complete...", + static_cast(m_flushHandle.GetTask())); m_flushComplete.wait(); } @@ -86,7 +170,7 @@ namespace MAT_NS_BEGIN { m_observer = &observer; m_cacheMemorySizeLimitInBytes = m_config[CFG_INT_RAM_QUEUE_SIZE]; - m_offlineStorageDisk = OfflineStorageFactory::Create(m_logManager, m_config); + m_offlineStorageDisk = m_storageProvider->CreateDiskStorage(m_logManager, m_config); if (m_offlineStorageDisk) { m_offlineStorageDisk->Initialize(*this); @@ -97,7 +181,7 @@ namespace MAT_NS_BEGIN { // disk. if (m_cacheMemorySizeLimitInBytes > 0) { - m_offlineStorageMemory.reset(new MemoryStorage(m_logManager, m_config)); + m_offlineStorageMemory = m_storageProvider->CreateMemoryStorage(m_logManager, m_config); m_offlineStorageMemory->Initialize(*this); } @@ -163,65 +247,124 @@ namespace MAT_NS_BEGIN { void OfflineStorageHandler::Flush() { - if (!m_logManager.StartActivity()) { + // Shutdown has already paused normal logging, but its synchronous final + // flush must still persist the in-memory records before storage closes. + ActivityGuard activityGuard(m_logManager, m_shutdownStarted); + if (!activityGuard.IsActive()) { + // The LogManager is shutting down, so the flush cannot run. Still + // signal completion and clear the pending flag so a concurrent + // WaitForFlush() (e.g. during teardown) does not block forever + // waiting for m_flushComplete. + LOCKGUARD(m_flushLock); + m_flushHandle.Cancel(); + m_flushComplete.post(); + m_flushPending = false; return; } - // Flush could be executed from context of worker thread, as well as from TPM and - // after HTTP callback. Make sure it is atomic / thread-safe. - LOCKGUARD(m_flushLock); - - // If item isn't scheduled yet, it gets canceled, so that we don't do two flushes. - // If we are running that item right now (our thread), then nothing happens other - // than the handle gets replaced by nullptr in this DeferredCallbackHandle obj. - m_flushHandle.Cancel(); - - size_t dbSizeBeforeFlush = (m_offlineStorageMemory != nullptr) ? m_offlineStorageMemory->GetSize() : 0; - if ((m_offlineStorageMemory) && (dbSizeBeforeFlush > 0) && (m_offlineStorageDisk)) + std::vector recordsToRecover; + try { - // This will block on and then take a lock for the duration of this move, and - // StoreRecord() will then block until the move completes. - auto records = m_offlineStorageMemory->GetRecords(false, EventLatency_Unspecified); - std::vector ids; - - // TODO: [MG] - consider running the batch in transaction - // if (sqlite) - // sqlite->Execute("BEGIN"); + // Flush could be executed from context of worker thread, as well as from TPM and + // after HTTP callback. Make sure it is atomic / thread-safe. + LOCKGUARD(m_flushLock); - size_t totalSaved = m_offlineStorageDisk->StoreRecords(records); + // If item isn't scheduled yet, it gets canceled, so that we don't do two flushes. + // If we are running that item right now (our thread), then nothing happens other + // than the handle reporting nullptr once that task finishes. + m_flushHandle.Cancel(); - // TODO: [MG] - consider running the batch in transaction - // if (sqlite) - // sqlite->Execute("END"); + size_t dbSizeBeforeFlush = (m_offlineStorageMemory != nullptr) ? m_offlineStorageMemory->GetSize() : 0; + if ((m_offlineStorageMemory) && (dbSizeBeforeFlush > 0) && (m_offlineStorageDisk)) + { + size_t totalSaved = 0; + if (IsBatchedStorageFlushEnabled()) + { + // Drain only the records present when this flush started so + // producers cannot keep the flush alive indefinitely. + size_t recordsRemaining = m_offlineStorageMemory->GetRecordCount(); + while (recordsRemaining > 0) + { + recordsToRecover = m_offlineStorageMemory->GetRecords( + false, EventLatency_Unspecified, MAX_RECORDS_PER_STORAGE_BATCH); + if (recordsToRecover.empty()) + { + break; + } + + const size_t drainedBatchSize = recordsToRecover.size(); + recordsRemaining -= std::min(recordsRemaining, drainedBatchSize); + const size_t batchSaved = m_offlineStorageDisk->StoreRecords(recordsToRecover); + // StoreRecords() removes permanently-invalid records before + // returning, so compare against the remaining valid records. + const size_t validBatchSize = recordsToRecover.size(); + if (batchSaved != validBatchSize) + { + LOG_WARN("Flush: disk store failed for the batch of %zu records; returning it to the queue for retry", + validBatchSize); + ReturnRecordsToMemory(recordsToRecover); + recordsToRecover.clear(); + break; + } + + totalSaved += batchSaved; + recordsToRecover.clear(); + } + } + else + { + // Preserve the legacy per-record path and its unlimited drain. + recordsToRecover = m_offlineStorageMemory->GetRecords( + false, EventLatency_Unspecified); + totalSaved = StoreRecordsIndividually(recordsToRecover); + } - // Delete records from reserved on flush - HttpHeaders dummy; - bool fromMemory = true; - m_offlineStorageMemory->DeleteRecords(ids, dummy, fromMemory); + // Persistence and retry handling are complete; a later exception + // must not requeue records that were already committed. + recordsToRecover.clear(); - // Notify event listener about the records cached - OnStorageRecordsSaved(totalSaved); + if (m_offlineStorageMemory->GetSize() > dbSizeBeforeFlush) + { + // We managed to accumulate as much data as we had before the flush, + // means we cannot keep up flushing at the same speed as incoming + // obviously because the disk is slower than ram. + LOG_WARN("Data is arriving too fast!"); + } + OnStorageRecordsSaved(totalSaved); + } - if (m_offlineStorageMemory->GetSize() > dbSizeBeforeFlush) + // Checkpoint DB + if (m_offlineStorageDisk && m_config.HasConfig(CFG_BOOL_CHECKPOINT_DB_ON_FLUSH) && m_config[CFG_BOOL_CHECKPOINT_DB_ON_FLUSH]) { - // We managed to accumulate as much data as we had before the flush, - // means we cannot keep up flushing at the same speed as incoming - // obviously because the disk is slower than ram. - LOG_WARN("Data is arriving too fast!"); + m_offlineStorageDisk->Flush(); } - } - // Checkpoint DB - if (m_config.HasConfig(CFG_BOOL_CHECKPOINT_DB_ON_FLUSH) && m_config[CFG_BOOL_CHECKPOINT_DB_ON_FLUSH]) + m_isStorageFullNotificationSend = false; + m_flushComplete.post(); + m_flushPending = false; + } + catch (...) { - m_offlineStorageDisk->Flush(); + std::exception_ptr failure = std::current_exception(); + try + { + if (m_offlineStorageMemory && !recordsToRecover.empty()) + { + ReturnRecordsToMemory(recordsToRecover); + } + } + catch (const std::exception& e) + { + std::fprintf(stderr, "Failed to recover records after flush failure: %s\n", e.what()); + } + catch (...) + { + std::fputs("Failed to recover records after flush failure\n", stderr); + } + LOCKGUARD(m_flushLock); + m_flushComplete.post(); + m_flushPending = false; + std::rethrow_exception(failure); } - - m_isStorageFullNotificationSend = false; - - // Flush is done, notify the waiters - m_flushComplete.post(); - m_flushPending = false; - m_logManager.EndActivity(); } bool OfflineStorageHandler::StoreRecord(StorageRecord const& record) @@ -247,7 +390,21 @@ namespace MAT_NS_BEGIN { // are selected and removed from the cache (but will // not block for the subsequent handoff to persistent // storage) - m_offlineStorageMemory->StoreRecord(record); + if (!m_offlineStorageMemory->StoreRecord(record)) + { + if (record.latency == EventLatency_Off) + { + // MemoryStorage intentionally returns false for latency-off + // records to mean "drop without storing", not "storage + // failed". Keep the handler's false return reserved for + // genuine storage failures so StorageObserver does not + // misclassify this normal drop as a persistence error. + return true; + } + LOG_ERROR("Failed to store event %s:%s in memory queue", + tenantTokenToId(record.tenantToken).c_str(), record.id.c_str()); + return false; + } } // Perform periodic flush to disk @@ -260,7 +417,15 @@ namespace MAT_NS_BEGIN { m_flushPending = true; m_flushComplete.Reset(); m_flushHandle = PAL::scheduleTask(&m_taskDispatcher, 0, this, &OfflineStorageHandler::Flush); - LOG_INFO("Requested Flush (%p)", m_flushHandle.m_task); + if (m_flushHandle.GetTask() == nullptr) + { + // The dispatcher may drop a task synchronously during + // shutdown. Do not leave WaitForFlush blocked forever. + m_flushPending = false; + m_flushComplete.post(); + } + LOG_INFO("Requested Flush (%p)", + static_cast(m_flushHandle.GetTask())); } m_flushLock.unlock(); } @@ -272,7 +437,9 @@ namespace MAT_NS_BEGIN { { if (record.persistence != EventPersistence::EventPersistence_DoNotStoreOnDisk) { - m_offlineStorageDisk->StoreRecord(record); + // Propagate a synchronous disk write failure to the caller so a + // failed store is not counted as successfully persisted. + return m_offlineStorageDisk->StoreRecord(record); } } } @@ -280,6 +447,134 @@ namespace MAT_NS_BEGIN { return true; } + bool OfflineStorageHandler::IsBatchedStorageFlushEnabled() + { + const bool batchingConfigured = + !m_config.HasConfig(CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH) || + m_config[CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH]; + const bool usingCustomStorage = + m_logManager.GetLogConfiguration().GetModule(CFG_MODULE_OFFLINE_STORAGE) != nullptr; + return batchingConfigured && !usingCustomStorage; + } + + void OfflineStorageHandler::ReportInvalidDiskRecord(StorageRecord const& record) + { + (void)record; + LOG_ERROR("Flush: dropping event %s:%s: Invalid parameters", + tenantTokenToId(record.tenantToken).c_str(), record.id.c_str()); + OnStorageFailed("Invalid parameters"); + } + + size_t OfflineStorageHandler::StoreRecordsIndividually(std::vector& records) + { + size_t totalSaved = 0; + std::vector recordsToRetry; + size_t nextRecord = 0; + + try + { + for (; nextRecord < records.size(); ++nextRecord) + { + auto const& record = records[nextRecord]; + if (!IsValidDiskStorageRecord(record)) + { + ReportInvalidDiskRecord(record); + continue; + } + + if (m_offlineStorageDisk->StoreRecord(record)) + { + ++totalSaved; + continue; + } + + for (size_t retryIndex = nextRecord; retryIndex < records.size(); ++retryIndex) + { + auto const& retryRecord = records[retryIndex]; + if (IsValidDiskStorageRecord(retryRecord)) + { + recordsToRetry.push_back(retryRecord); + } + else + { + ReportInvalidDiskRecord(retryRecord); + } + } + break; + } + } + catch (...) + { + recordsToRetry.clear(); + for (size_t retryIndex = nextRecord; retryIndex < records.size(); ++retryIndex) + { + if (IsValidDiskStorageRecord(records[retryIndex])) + { + recordsToRetry.push_back(records[retryIndex]); + } + } + records.clear(); + ReturnRecordsToMemory(recordsToRetry); + throw; + } + + if (!recordsToRetry.empty()) + { + LOG_WARN("Flush: per-record disk store failed after saving %zu of %zu records; returning %zu records to the queue for retry", + totalSaved, records.size(), recordsToRetry.size()); + ReturnRecordsToMemory(recordsToRetry); + } + + return totalSaved; + } + + size_t OfflineStorageHandler::ReturnRecordsToMemory(std::vector const& records) + { + size_t returned = 0; + DroppedMap dropped; + + for (auto const& record : records) + { + try + { + if (m_offlineStorageMemory && m_offlineStorageMemory->StoreRecord(record)) + { + ++returned; + continue; + } + LOG_ERROR("Flush: failed to return event %s:%s to memory queue after disk store failure; dropping record", + tenantTokenToId(record.tenantToken).c_str(), record.id.c_str()); + dropped[record.tenantToken]++; + } + catch (const std::exception& e) + { + std::fprintf(stderr, "Failed to recover a record after flush failure: %s\n", e.what()); + } + catch (...) + { + std::fputs("Failed to recover a record after flush failure\n", stderr); + } + } + + if (!dropped.empty()) + { + try + { + OnStorageRecordsDropped(dropped); + } + catch (const std::exception& e) + { + std::fprintf(stderr, "Failed to report dropped records after flush failure: %s\n", e.what()); + } + catch (...) + { + std::fputs("Failed to report dropped records after flush failure\n", stderr); + } + } + + return returned; + } + size_t OfflineStorageHandler::StoreRecords(std::vector& records) { size_t stored = 0; diff --git a/lib/offline/OfflineStorageHandler.hpp b/lib/offline/OfflineStorageHandler.hpp index 9a1131aff..0eae7510b 100644 --- a/lib/offline/OfflineStorageHandler.hpp +++ b/lib/offline/OfflineStorageHandler.hpp @@ -8,6 +8,7 @@ #include "pal/PAL.hpp" #include "IOfflineStorage.hpp" +#include "IOfflineStorageProvider.hpp" #include "api/IRuntimeConfig.hpp" #include "ILogManager.hpp" @@ -27,6 +28,8 @@ namespace MAT_NS_BEGIN { { public: OfflineStorageHandler(ILogManager& logManager, IRuntimeConfig& runtimeConfig, ITaskDispatcher& taskDispatcher); + OfflineStorageHandler(ILogManager& logManager, IRuntimeConfig& runtimeConfig, + ITaskDispatcher& taskDispatcher, std::shared_ptr storageProvider); virtual ~OfflineStorageHandler() override; virtual void Initialize(IOfflineStorageObserver& observer) override; virtual void Shutdown() override; @@ -71,6 +74,7 @@ namespace MAT_NS_BEGIN { std::string m_databasePath; IRuntimeConfig& m_config; ITaskDispatcher& m_taskDispatcher; + std::shared_ptr m_storageProvider; KillSwitchManager m_killSwitchManager; ClockSkewManager m_clockSkewManager; @@ -82,11 +86,11 @@ namespace MAT_NS_BEGIN { PAL::DeferredCallbackHandle m_flushHandle; PAL::Event m_flushComplete; - std::unique_ptr m_offlineStorageMemory; + std::shared_ptr m_offlineStorageMemory; std::shared_ptr m_offlineStorageDisk; - bool m_readFromMemory; - unsigned m_lastReadCount; + std::atomic m_readFromMemory; + std::atomic m_lastReadCount; bool m_shutdownStarted; unsigned m_memoryDbSize; @@ -100,6 +104,10 @@ namespace MAT_NS_BEGIN { private: void WaitForFlush(); + bool IsBatchedStorageFlushEnabled(); + void ReportInvalidDiskRecord(StorageRecord const& record); + size_t StoreRecordsIndividually(std::vector& records); + size_t ReturnRecordsToMemory(std::vector const& records); }; diff --git a/lib/offline/OfflineStorage_SQLite.cpp b/lib/offline/OfflineStorage_SQLite.cpp index b9b2ed83d..93f60b01d 100644 --- a/lib/offline/OfflineStorage_SQLite.cpp +++ b/lib/offline/OfflineStorage_SQLite.cpp @@ -8,6 +8,7 @@ #include "OfflineStorage_SQLite.hpp" #include "ILogManager.hpp" #include "SQLiteWrapper.hpp" +#include "StorageRecordValidation.hpp" #include "utils/StringUtils.hpp" #include #include @@ -18,11 +19,32 @@ namespace MAT_NS_BEGIN { constexpr static size_t kBlockSize = 8192; + EventLatency NormalizePersistedLatency(int latency) + { + if (latency < EventLatency_Off || latency > EventLatency_Max) + { + return EventLatency_Normal; + } + return static_cast(latency); + } + std::mutex OfflineStorage_SQLite::m_initAndShutdownLock; int OfflineStorage_SQLite::m_instanceCount = 0; + bool OfflineStorage_SQLite::m_ownsTempDirectory = false; + + static std::string GetRequiredSqliteTempDirectory() + { +#if defined(ANDROID) || defined(_WINRT_DLL) + return GetTempDirectory(); +#else + return {}; +#endif + } class DbTransaction { SqliteDB* m_db; + bool m_rollback = false; + bool m_finished = false; public: bool locked; @@ -34,11 +56,43 @@ namespace MAT_NS_BEGIN { } } + // Discard the transaction (ROLLBACK) instead of committing it on destruction. + void markForRollback() + { + m_rollback = true; + } + + // Commit the transaction now and report whether COMMIT succeeded. On a + // COMMIT failure the transaction is rolled back so it is never left open, + // and false is returned so the caller does not treat undurable writes as + // stored. After this call the destructor performs no further COMMIT/ROLLBACK. + bool commit() + { + if (!locked || m_finished) + { + return false; + } + m_finished = true; + if (m_db->unlock()) + { + return true; + } + m_db->rollback(); + return false; + } + ~DbTransaction() { - if (locked) + if (locked && !m_finished) { - m_db->unlock(); + if (m_rollback) + { + m_db->rollback(); + } + else + { + m_db->unlock(); + } } } }; @@ -95,15 +149,18 @@ namespace MAT_NS_BEGIN { void OfflineStorage_SQLite::Initialize(IOfflineStorageObserver& observer) { + LOCKGUARD(m_lock); m_observer = &observer; assert(!m_db); m_db.reset(new SqliteDB(m_skipInitAndShutdown, &m_initAndShutdownLock, - &m_instanceCount)); + &m_instanceCount, &m_ownsTempDirectory)); LOG_TRACE("Initializing offline storage: %s", m_offlineStorageFileName.c_str()); auto sqlStartTime = GetUptimeMs(); - if (m_db->initialize(m_offlineStorageFileName, false, m_DbSizeHeapLimit) && initializeDatabase()) { + if (m_db->initialize(m_offlineStorageFileName, false, m_DbSizeHeapLimit, + GetRequiredSqliteTempDirectory()) && + initializeDatabase()) { LOG_INFO("Using configured on-disk database"); m_observer->OnStorageOpened("SQLite/Default"); sqlStartTime = GetUptimeMs() - sqlStartTime; @@ -127,60 +184,51 @@ namespace MAT_NS_BEGIN { LOG_TRACE("Shutting down offline storage %s", m_offlineStorageFileName.c_str()); LOCKGUARD(m_lock); if (m_db) { - if (m_isOpened) { - m_db->shutdown(); - m_db.reset(); - } + m_db->shutdown(); + m_db.reset(); m_isOpened = false; } } void OfflineStorage_SQLite::Flush() { + LOCKGUARD(m_lock); if (m_db) m_db->flush(); } void OfflineStorage_SQLite::Execute(std::string command) { + LOCKGUARD(m_lock); if (m_db) m_db->execute(command.c_str()); } - bool OfflineStorage_SQLite::StoreRecord(StorageRecord const& record) + bool OfflineStorage_SQLite::isValidRecord(StorageRecord const& record) const { - // TODO: [MG] - this works, but may not play nicely with several LogManager instances - // static SqliteStatement sql_insert(*m_db, m_stmtInsertEvent_id_tenant_prio_ts_data); - - if (record.id.empty() || record.tenantToken.empty() || static_cast(record.latency) < 0 || record.timestamp <= 0) { + if (!IsValidDiskStorageRecord(record)) { LOG_ERROR("Failed to store event %s:%s: Invalid parameters", tenantTokenToId(record.tenantToken).c_str(), record.id.c_str()); m_observer->OnStorageFailed("Invalid parameters"); return false; } + return true; + } - if (!m_db) { - LOG_ERROR("Failed to store event %s:%s: Database is not open", + bool OfflineStorage_SQLite::insertRecordUnsafe(StorageRecord const& record) + { + if (!SqliteStatement(*m_db, m_stmtInsertEvent_id_tenant_prio_ts_data).execute(record.id, record.tenantToken, static_cast(record.latency), static_cast(record.persistence), record.timestamp, record.blob)) + { + LOG_ERROR("Failed to store event %s:%s: database write failed", tenantTokenToId(record.tenantToken).c_str(), record.id.c_str()); - m_observer->OnStorageOpenFailed("Database is not open"); return false; } + m_DbSizeEstimate += record.id.size() + record.tenantToken.size() + record.blob.size(); + return true; + } - { -#ifdef ENABLE_LOCKING - LOCKGUARD(m_lock); - DbTransaction transaction(m_db.get()); - if (!transaction.locked) - { - LOG_ERROR("Failed to store event %s:%s: Database error", tenantTokenToId(record.tenantToken).c_str(), record.id.c_str()); - m_observer->OnStorageFailed("Database error"); - return false; - } -#endif - SqliteStatement(*m_db, m_stmtInsertEvent_id_tenant_prio_ts_data).execute(record.id, record.tenantToken, static_cast(record.latency), static_cast(record.persistence), record.timestamp, record.blob); - m_DbSizeEstimate += record.id.size() + record.tenantToken.size() + record.blob.size(); - } - + void OfflineStorage_SQLite::checkStorageSizeLimits() + { if ((m_DbSizeNotificationLimit != 0) && (m_DbSizeEstimate>m_DbSizeNotificationLimit)) { auto now = PAL::getMonotonicTimeMs(); @@ -210,20 +258,173 @@ namespace MAT_NS_BEGIN { m_resizing = false; } } + } - return true; + bool OfflineStorage_SQLite::StoreRecord(StorageRecord const& record) + { + // TODO: [MG] - this works, but may not play nicely with several LogManager instances + // static SqliteStatement sql_insert(*m_db, m_stmtInsertEvent_id_tenant_prio_ts_data); + + if (!isValidRecord(record)) { + return false; + } + + bool stored = false; + { + LOCKGUARD(m_lock); + if (!m_db) { + LOG_ERROR("Failed to store event %s:%s: Database is not open", + tenantTokenToId(record.tenantToken).c_str(), record.id.c_str()); + m_observer->OnStorageOpenFailed("Database is not open"); + return false; + } +#ifdef ENABLE_LOCKING + DbTransaction transaction(m_db.get()); + if (!transaction.locked) + { + LOG_ERROR("Failed to store event %s:%s: Database error", tenantTokenToId(record.tenantToken).c_str(), record.id.c_str()); + m_observer->OnStorageFailed("Database error"); + return false; + } + if (insertRecordUnsafe(record)) + { + // Verify the COMMIT: a COMMIT that fails must not be reported as a + // successful store, or the caller treats an undurable write as saved. + stored = transaction.commit(); + if (!stored) + { + m_DbSizeEstimate -= std::min(m_DbSizeEstimate.load(), + record.id.size() + record.tenantToken.size() + record.blob.size()); + } + } + else + { + transaction.markForRollback(); + } +#else + stored = insertRecordUnsafe(record); +#endif + } + + if (!stored) { + // Report the write failure after the transaction has closed, so the + // observer callback never runs while BEGIN EXCLUSIVE is held. + m_observer->OnStorageFailed("Database write failed"); + } + + // Run the size-limit check after the transaction, matching the original + // per-record path (which ran it on every StoreRecord call). + checkStorageSizeLimits(); + + return stored; } size_t OfflineStorage_SQLite::StoreRecords(std::vector & records) { - size_t stored = 0; - for (auto & i : records) { - if (StoreRecord(i)) { - ++stored; + if (records.empty()) { + return 0; + } + + // Drop invalid records up front (each is reported by isValidRecord) so a + // permanently-invalid record is discarded rather than failing the whole + // batch. Removing them from the vector means a caller that re-queues on a + // short return (e.g. Flush) never re-queues a poison record -- which would + // be re-drained and re-rejected on every flush, blocking every valid record + // behind it -- while the valid remainder stays all-or-nothing. + records.erase( + std::remove_if(records.begin(), records.end(), + [this](StorageRecord const& record) { return !isValidRecord(record); }), + records.end()); + + if (records.empty()) { + // Every record was invalid (already reported). + return 0; + } + + size_t addedSize = 0; + bool committed = false; + { + LOCKGUARD(m_lock); + if (!m_db) { + LOG_ERROR("Failed to store %zu events: Database is not open", records.size()); + m_observer->OnStorageOpenFailed("Database is not open"); + return 0; + } + // Batch all inserts into a single transaction: one BEGIN EXCLUSIVE / + // COMMIT (one fsync) for the whole flush instead of one per record. + // All-or-nothing: if any insert OR the COMMIT fails the transaction is + // rolled back, so callers (e.g. Flush) can re-queue the whole batch + // without risking duplicate rows (the events table has no unique + // record_id constraint). + bool allInserted = true; +#ifdef ENABLE_LOCKING + DbTransaction transaction(m_db.get()); + if (!transaction.locked) + { + LOG_ERROR("Failed to store %zu events: Database error", records.size()); + m_observer->OnStorageFailed("Database error"); + return 0; + } +#endif + try + { + for (auto const& r : records) { + if (insertRecordUnsafe(r)) { + addedSize += r.id.size() + r.tenantToken.size() + r.blob.size(); + } + else { + allInserted = false; + break; + } + } + } + catch (...) + { +#ifdef ENABLE_LOCKING + // DbTransaction commits on destruction by default for legacy + // callers. An exception during a batch must explicitly roll + // back so Flush can safely requeue the entire batch. + transaction.markForRollback(); +#endif + // insertRecordUnsafe updates the estimate before the + // transaction commits; undo inserts that will be rolled back. + m_DbSizeEstimate -= std::min(m_DbSizeEstimate.load(), addedSize); + throw; + } + +#ifdef ENABLE_LOCKING + if (allInserted) { + // Verify the COMMIT: a COMMIT that fails (e.g. SQLITE_FULL/IOERR) + // must not be reported as success, or Flush would drop the records + // it already drained from memory. + committed = transaction.commit(); + } + else { + transaction.markForRollback(); + } +#else + committed = allInserted; +#endif + + if (!committed) { + // Nothing durably stored; undo the size estimate added by the + // (rolled-back) inserts. + m_DbSizeEstimate -= std::min(m_DbSizeEstimate.load(), addedSize); } } - return stored; + + if (!committed) { + // The whole batch was rolled back after an insert or COMMIT failure; + // report once. + m_observer->OnStorageFailed("Database write failed"); + } + + // Run the size-full notification / resize check once after the batch, + // matching the original per-record path (which ran it on every insert). + checkStorageSizeLimits(); + + return committed ? records.size() : 0; } // Debug routine to print record count in the DB @@ -249,6 +450,7 @@ namespace MAT_NS_BEGIN { /// bool OfflineStorage_SQLite::GetAndReserveRecords(std::function const& consumer, unsigned leaseTimeMs, EventLatency minLatency, unsigned maxCount) { + LOCKGUARD(m_lock); m_lastReadCount = 0; if (!m_db) { @@ -260,7 +462,6 @@ namespace MAT_NS_BEGIN { maxCount, (maxCount > 0) ? "" : " (unlimited)", minLatency, latencyToStr(static_cast(minLatency))); /* ============================================================================================================= */ - LOCKGUARD(m_lock); { #ifdef ENABLE_LOCKING DbTransaction transaction(m_db.get()); @@ -295,12 +496,7 @@ namespace MAT_NS_BEGIN { while (selectStmt.getRow(record.id, record.tenantToken, latency, record.timestamp, record.retryCount, record.reservedUntil, record.blob)) { - if (latency < EventLatency_Off || latency > EventLatency_Max) { - record.latency = EventLatency_Normal; - } - else { - record.latency = static_cast(latency); - } + record.latency = NormalizePersistedLatency(latency); consumedIds.push_back(record.id); if (!consumer(std::move(record))) { @@ -347,6 +543,7 @@ namespace MAT_NS_BEGIN { unsigned OfflineStorage_SQLite::LastReadRecordCount() { + LOCKGUARD(m_lock); return m_lastReadCount; } @@ -355,6 +552,7 @@ namespace MAT_NS_BEGIN { std::vector records; StorageRecord record; + LOCKGUARD(m_lock); if (!isOpen()) { return records; } @@ -367,7 +565,7 @@ namespace MAT_NS_BEGIN { int latency; while (selectStmt.getRow(record.id, record.tenantToken, latency, record.timestamp, record.retryCount, record.reservedUntil, record.blob)) { - record.latency = static_cast(latency); + record.latency = NormalizePersistedLatency(latency); records.push_back(record); } selectStmt.reset(); @@ -381,7 +579,7 @@ namespace MAT_NS_BEGIN { int latency; while (selectStmt.getRow(record.id, record.tenantToken, latency, record.timestamp, record.retryCount, record.reservedUntil, record.blob)) { - record.latency = static_cast(latency); + record.latency = NormalizePersistedLatency(latency); records.push_back(record); } selectStmt.reset(); @@ -399,11 +597,11 @@ namespace MAT_NS_BEGIN { void OfflineStorage_SQLite::DeleteRecords(const std::map & whereFilter) { + LOCKGUARD(m_lock); if (!isOpen()) { return; } - LOCKGUARD(m_lock); { #ifdef ENABLE_LOCKING DbTransaction transaction(m_db.get()); @@ -519,6 +717,7 @@ namespace MAT_NS_BEGIN { return; } + LOCKGUARD(m_lock); if (!m_db) { LOG_ERROR("Failed to delete %u sent event(s) {%s%s}: Database is not open", static_cast(ids.size()), ids.front().c_str(), (ids.size() > 1) ? ", ..." : ""); @@ -526,7 +725,6 @@ namespace MAT_NS_BEGIN { } /* ============================================================================================================= */ - LOCKGUARD(m_lock); { #ifdef ENABLE_LOCKING DbTransaction transaction(m_db.get()); @@ -562,13 +760,13 @@ namespace MAT_NS_BEGIN { if (ids.empty()) { return; } + LOCKGUARD(m_lock); if (!m_db) { LOG_ERROR("Failed to release %u event(s) {%s%s}, retry count %s: Database is not open", static_cast(ids.size()), ids.front().c_str(), (ids.size() > 1) ? ", ..." : "", incrementRetryCount ? "+1" : "not changed"); return; } - LOCKGUARD(m_lock); { #ifdef ENABLE_LOCKING DbTransaction transaction(m_db.get()); @@ -644,6 +842,7 @@ namespace MAT_NS_BEGIN { return false; } + LOCKGUARD(m_lock); if (!m_db) { LOG_ERROR("Failed to set setting \"%s\": Database is not open", name.c_str()); return false; @@ -676,6 +875,7 @@ namespace MAT_NS_BEGIN { return result; } + LOCKGUARD(m_lock); if (!isOpen()) { LOG_ERROR("Oddly closed"); return result; @@ -706,6 +906,7 @@ namespace MAT_NS_BEGIN { LOG_ERROR("Failed to delete setting \"%s\": Name cannot be empty", name.c_str()); return false; } + LOCKGUARD(m_lock); if (!isOpen()) { LOG_ERROR("Oddly closed"); return false; @@ -734,7 +935,8 @@ namespace MAT_NS_BEGIN { { m_db->shutdown(); // Try again with deletePrevious = true - if (m_db->initialize(m_offlineStorageFileName, true)) { + if (m_db->initialize(m_offlineStorageFileName, true, 0, + GetRequiredSqliteTempDirectory())) { if (initializeDatabase()) { m_observer->OnStorageOpened("SQLite/Clean"); LOG_INFO("Using configured on-disk database after deleting the existing one"); @@ -756,12 +958,6 @@ namespace MAT_NS_BEGIN { SqliteStatement(*m_db, "PRAGMA auto_vacuum=FULL").select(); SqliteStatement(*m_db, "PRAGMA journal_mode=WAL").select(); SqliteStatement(*m_db, "PRAGMA synchronous=NORMAL").select(); - { - std::ostringstream tempPragma; - tempPragma << "PRAGMA temp_store_directory = '" << GetTempDirectory() << "'"; - SqliteStatement(*m_db, tempPragma.str().c_str()).select(); - LOG_INFO("Set sqlite3 temp_store_directory to '%s'", sqlite3_temp_directory); - } int openedDbVersion; { @@ -825,19 +1021,8 @@ namespace MAT_NS_BEGIN { if (!stmt.select() || !stmt.getRow(m_pageSize)) { return false; } } -#if defined(_MSC_VER) -#pragma warning(push) -#pragma warning(disable:4296) // expression always false. -#elif defined( __clang__) -#pragma clang diagnostic push -#pragma clang diagnostic ignored "-Wtype-limits" // error: comparison of unsigned expression < 0 is always false [-Werror=type-limits] -#elif defined(__GNUC__) -#pragma GCC diagnostic push -#pragma GCC diagnostic ignored "-Wtype-limits" // error: comparison of unsigned expression < 0 is always false [-Werror=type-limits] -#endif - #define PREPARE_SQL(var_, stmt_) \ - if ((var_ = m_db->prepare(stmt_)) < 0) { return false; } + if ((var_ = m_db->prepare(stmt_)) == 0) { return false; } #ifdef ENABLE_LOCKING PREPARE_SQL(m_stmtBeginTransaction, @@ -923,26 +1108,18 @@ namespace MAT_NS_BEGIN { #undef PREPARE_SQL -#if defined(_MSC_VER) -#pragma warning(pop) -#elif defined(__clang__) -#pragma clang diagnostic pop -#elif defined(__GNUC__) -#pragma GCC diagnostic pop -#endif - ResizeDb(); return true; } size_t OfflineStorage_SQLite::GetSize() { + LOCKGUARD(m_lock); if (!m_db) { LOG_ERROR("Failed to get DB size: database is not open"); return 0; } - LOCKGUARD(m_lock); unsigned pageCount = 0; SqliteStatement pageCountStmt(*m_db, m_stmtGetPageCount); if (!pageCountStmt.select()) @@ -977,28 +1154,29 @@ namespace MAT_NS_BEGIN { size_t OfflineStorage_SQLite::GetRecordCount(EventLatency latency = EventLatency_Unspecified) const { + LOCKGUARD(m_lock); if (!m_db) { LOG_ERROR("Failed to get DB size: database is not open"); return 0; } - LOCKGUARD(m_lock); return OfflineStorage_SQLite::GetRecordCountUnsafe(latency); } bool OfflineStorage_SQLite::ResizeDb() { + LOCKGUARD(m_lock); if (!m_db) { LOG_ERROR("Failed to resize DB: database is not open"); return false; } size_t eventsDropped = 0; + bool compactDatabase = false; m_DbSizeEstimate = GetSize(); if (m_DbSizeEstimate <= m_DbSizeLimit) return false; - LOCKGUARD(m_lock); { #ifdef ENABLE_LOCKING DbTransaction transaction(m_db.get()); @@ -1012,9 +1190,17 @@ namespace MAT_NS_BEGIN { if (m_DbSizeEstimate > 2 * m_DbSizeLimit) { LOG_TRACE("DB is too big, deleting..."); - Execute("DELETE FROM " TABLE_NAME_EVENTS); - Execute("VACUUM"); + if (!SqliteStatement(*m_db, "DELETE FROM " TABLE_NAME_EVENTS).execute()) + { +#ifdef ENABLE_LOCKING + transaction.markForRollback(); +#endif + LOG_ERROR("Failed to delete events while resizing database"); + m_observer->OnStorageFailed("Database resize failed"); + return false; + } eventsDropped = count; + compactDatabase = true; } else { @@ -1029,6 +1215,26 @@ namespace MAT_NS_BEGIN { LOG_TRACE("Db resized, events dropped: %zu", eventsDropped); trimStmt.reset(); } + +#ifdef ENABLE_LOCKING + if (!transaction.commit()) + { + LOG_ERROR("Failed to commit database resize"); + m_observer->OnStorageFailed("Database resize failed"); + return false; + } +#endif + } + + // VACUUM cannot run inside a transaction. Reserve the full rewrite for + // the emergency delete-all path; routine 25% trims use auto_vacuum=FULL. + if (compactDatabase && + !SqliteStatement(*m_db, "VACUUM").execute()) + { + LOG_ERROR("Failed to compact database after resize"); + m_observer->OnStorageFailed("Database resize failed"); + m_DbSizeEstimate = GetSize(); + return false; } m_DbSizeEstimate = GetSize(); @@ -1064,4 +1270,3 @@ namespace MAT_NS_BEGIN { } MAT_NS_END #endif - diff --git a/lib/offline/OfflineStorage_SQLite.hpp b/lib/offline/OfflineStorage_SQLite.hpp index 18643cde5..2053a0246 100644 --- a/lib/offline/OfflineStorage_SQLite.hpp +++ b/lib/offline/OfflineStorage_SQLite.hpp @@ -85,6 +85,7 @@ namespace MAT_NS_BEGIN { // of this class still using SQLite. static std::mutex m_initAndShutdownLock; static int m_instanceCount; + static bool m_ownsTempDirectory; size_t m_stmtBeginTransaction {}; size_t m_stmtCommitTransaction {}; @@ -122,9 +123,17 @@ namespace MAT_NS_BEGIN { private: size_t GetRecordCountUnsafe(EventLatency latency) const; + + // Validate a record's required fields; reports OnStorageFailed on rejection. + bool isValidRecord(StorageRecord const& record) const; + // Insert one already-validated record. Caller must hold m_lock and have an + // active DbTransaction (when ENABLE_LOCKING). Updates m_DbSizeEstimate. + // Returns false (without updating the size estimate) if the insert fails. + bool insertRecordUnsafe(StorageRecord const& record); + // Run the DB-size-full notification and resize checks (after inserts). + void checkStorageSizeLimits(); }; } MAT_NS_END #endif - diff --git a/lib/offline/SQLiteWrapper.hpp b/lib/offline/SQLiteWrapper.hpp index 2a5f0d108..895be3309 100644 --- a/lib/offline/SQLiteWrapper.hpp +++ b/lib/offline/SQLiteWrapper.hpp @@ -216,15 +216,30 @@ namespace MAT_NS_BEGIN { public: SqliteDB(bool skipInitAndShutdown, std::mutex* initAndShutdownLock = nullptr, - int* instanceCount = nullptr) + int* instanceCount = nullptr, + bool* ownsTempDirectory = nullptr) : m_db(nullptr), m_skipInitAndShutdown(skipInitAndShutdown), m_initAndShutdownLock(initAndShutdownLock), - m_instanceCount(instanceCount) + m_instanceCount(instanceCount), + m_ownsTempDirectory(ownsTempDirectory) { } - bool initialize(std::string const& filename, bool deletePrevious, size_t maxHeapLimit = 0) + ~SqliteDB() + { + // Finalize prepared statements and close the database even if + // shutdown() was not called explicitly (e.g. the owning storage was + // destroyed without Shutdown()). shutdown() is idempotent -- it + // returns immediately once m_db is null -- so an earlier explicit + // shutdown() makes this a no-op. + shutdown(); + } + + bool initialize(std::string const& filename, + bool deletePrevious, + size_t maxHeapLimit = 0, + std::string const& tempDirectory = {}) { int result = SQLITE_OK; @@ -235,11 +250,34 @@ namespace MAT_NS_BEGIN { if (*m_instanceCount > 0) { *m_instanceCount += 1; } else { + // Android and WinRT may require an explicit temp directory. + // Configure SQLite's process-global value once, before the + // first SQLite initialization, and release it with the last + // connection. Other platforms pass an empty directory and + // use SQLite's native temp-directory selection. + if (!tempDirectory.empty() && sqlite3_temp_directory == nullptr) { + sqlite3_temp_directory = ::sqlite3_mprintf("%s", tempDirectory.c_str()); + if (sqlite3_temp_directory == nullptr) { + result = SQLITE_NOMEM; + } else if (m_ownsTempDirectory != nullptr) { + *m_ownsTempDirectory = true; + } + } + } + if (result == SQLITE_OK && *m_instanceCount == 0) { result = g_sqlite3Proxy->sqlite3_initialize(); if (result == SQLITE_OK) { *m_instanceCount = 1; } } + if (result != SQLITE_OK && + m_ownsTempDirectory != nullptr && + *m_ownsTempDirectory) { + ::sqlite3_free(sqlite3_temp_directory); + sqlite3_temp_directory = nullptr; + *m_ownsTempDirectory = false; + g_sqlite3Proxy->sqlite3_shutdown(); + } } else { result = g_sqlite3Proxy->sqlite3_initialize(); } @@ -354,6 +392,11 @@ namespace MAT_NS_BEGIN { *m_instanceCount -= 1; } else if (*m_instanceCount == 1) { *m_instanceCount = 0; + if (m_ownsTempDirectory != nullptr && *m_ownsTempDirectory) { + ::sqlite3_free(sqlite3_temp_directory); + sqlite3_temp_directory = nullptr; + *m_ownsTempDirectory = false; + } g_sqlite3Proxy->sqlite3_shutdown(); } } else @@ -490,6 +533,13 @@ namespace MAT_NS_BEGIN { return isOK(sqlite3_exec("COMMIT;")); } + /** + * @brief Roll back (discard) the current DB transaction. + */ + bool rollback() { + return isOK(sqlite3_exec("ROLLBACK;")); + } + bool lock() { #ifndef NDEBUG unsigned count = 0; @@ -564,6 +614,7 @@ namespace MAT_NS_BEGIN { bool m_skipInitAndShutdown; std::mutex* m_initAndShutdownLock; int* m_instanceCount; + bool* m_ownsTempDirectory; private: MATSDK_LOG_DECL_COMPONENT_CLASS(); @@ -865,4 +916,3 @@ namespace MAT_NS_BEGIN { } MAT_NS_END #endif - diff --git a/lib/offline/StorageRecordValidation.hpp b/lib/offline/StorageRecordValidation.hpp new file mode 100644 index 000000000..23447a11f --- /dev/null +++ b/lib/offline/StorageRecordValidation.hpp @@ -0,0 +1,21 @@ +// +// Copyright (c) Microsoft Corporation. All rights reserved. +// SPDX-License-Identifier: Apache-2.0 +// + +#ifndef STORAGERECORDVALIDATION_HPP +#define STORAGERECORDVALIDATION_HPP + +#include "IOfflineStorage.hpp" + +namespace MAT_NS_BEGIN { + + inline bool IsValidDiskStorageRecord(StorageRecord const& record) + { + return !(record.id.empty() || record.tenantToken.empty() || + static_cast(record.latency) < 0 || record.timestamp <= 0); + } + +} MAT_NS_END + +#endif diff --git a/lib/pal/PAL.cpp b/lib/pal/PAL.cpp index 0fc28abfb..d55026af6 100644 --- a/lib/pal/PAL.cpp +++ b/lib/pal/PAL.cpp @@ -13,6 +13,7 @@ #include #include #include +#include #include #include @@ -58,9 +59,54 @@ namespace PAL_NS_BEGIN { +#if defined(_WIN32) || defined(_WIN64) + namespace + { + using GetSystemTimeAsFileTimeProc = VOID (WINAPI*)(LPFILETIME); + + GetSystemTimeAsFileTimeProc getPreciseSystemTimeAsFileTime() noexcept + { + static std::once_flag once; + static GetSystemTimeAsFileTimeProc proc = nullptr; + std::call_once(once, [] { + HMODULE kernel32 = ::GetModuleHandleW(L"kernel32.dll"); + if (kernel32 != nullptr) + { + proc = reinterpret_cast( + ::GetProcAddress(kernel32, "GetSystemTimePreciseAsFileTime")); + } + }); + return proc; + } + + void getSystemTimeAsFileTime(FILETIME& fileTime) noexcept + { + if (auto preciseProc = getPreciseSystemTimeAsFileTime()) + { + preciseProc(&fileTime); + } + else + { + ::GetSystemTimeAsFileTime(&fileTime); + } + } + } +#endif + PlatformAbstractionLayer& GetPAL() noexcept { - static PlatformAbstractionLayer pal; + // Deliberately never destroyed. PAL::shutdown() (called from + // LogManagerImpl::FlushAndTeardown()) must find this object's members + // still alive, but PAL is constructed lazily on first use, so whether + // this function-local static is destroyed before or after that + // teardown call depends on runtime timing, not source order -- if it + // is destroyed first, shutdown() releases shared_ptr members of an + // already-destroyed object (a downstream consumer observed this as + // intermittent EXC_BAD_ACCESS in ~shared_ptr at + // process exit). Leaking one fixed-size object avoids the ordering + // hazard entirely: shutdown() already performs the real resource + // teardown explicitly, and the OS reclaims the object at process exit. + static PlatformAbstractionLayer& pal = *new PlatformAbstractionLayer(); return pal; } @@ -196,10 +242,6 @@ namespace PAL_NS_BEGIN { #define gettid() std::this_thread::get_id() #endif -#ifdef _MSC_VER -#pragma warning(push) -#pragma warning(disable:4996) -#endif void log(LogLevel level, char const* component, char const* fmt, ...) { #if defined(ANDROID) && !defined(ANDROID_SUPPRESS_LOGCAT) @@ -313,9 +355,6 @@ namespace PAL_NS_BEGIN { (void)(fmt); #endif /* of #ifdef HAVE_MAT_LOGGING */ } -#ifdef _MSC_VER -#pragma warning(pop) -#endif } // namespace detail @@ -330,17 +369,16 @@ namespace PAL_NS_BEGIN { return m_taskDispatcher; } -#ifdef _MSC_VER -#pragma warning(push) -#pragma warning(disable:6031) -#endif std::string PlatformAbstractionLayer::generateUuidString() const { #ifdef _WIN32 GUID uuid = { 0, 0, 0, { 0, 0, 0, 0, 0, 0, 0, 0 } }; - auto hr = CoCreateGuid(&uuid); - /* CoCreateGuid` will possiblity never fail, so ignoring the result */ - UNREFERENCED_PARAMETER(hr); + const HRESULT hr = CoCreateGuid(&uuid); + if (FAILED(hr)) + { + LOG_ERROR("CoCreateGuid failed: 0x%08lx", static_cast(hr)); + return {}; + } return MAT::to_string(uuid); #elif defined(__APPLE__) auto uuid {CFUUIDCreate(kCFAllocatorDefault)}; @@ -406,15 +444,15 @@ namespace PAL_NS_BEGIN { return buf; #endif } -#ifdef _MSC_VER -#pragma warning(pop) -#endif int64_t PlatformAbstractionLayer::getUtcSystemTimeMs() const { #ifdef _WIN32 + FILETIME fileTime; + getSystemTimeAsFileTime(fileTime); ULARGE_INTEGER now; - ::GetSystemTimeAsFileTime(reinterpret_cast(&now)); + now.LowPart = fileTime.dwLowDateTime; + now.HighPart = fileTime.dwHighDateTime; return (now.QuadPart - 116444736000000000ull) / 10000; #else return std::chrono::system_clock::now().time_since_epoch() / std::chrono::milliseconds(1); @@ -430,26 +468,7 @@ namespace PAL_NS_BEGIN { { #ifdef _WIN32 FILETIME tocks; - // Resolve the precise API dynamically so the SDK retains its Windows 7 - // runtime compatibility and falls back when the API is unavailable. - using GetSystemTimePreciseAsFileTimeProc = VOID (WINAPI*)(LPFILETIME); - static const GetSystemTimePreciseAsFileTimeProc getSystemTimePreciseAsFileTime = - []() -> GetSystemTimePreciseAsFileTimeProc - { - HMODULE kernel32 = ::GetModuleHandleW(L"kernel32.dll"); - return kernel32 - ? reinterpret_cast( - ::GetProcAddress(kernel32, "GetSystemTimePreciseAsFileTime")) - : nullptr; - }(); - if (getSystemTimePreciseAsFileTime) - { - getSystemTimePreciseAsFileTime(&tocks); - } - else - { - ::GetSystemTimeAsFileTime(&tocks); - } + getSystemTimeAsFileTime(tocks); ULONGLONG ticks = (ULONGLONG(tocks.dwHighDateTime) << 32) | tocks.dwLowDateTime; // number of days from beginning to 1601 multiplied by ticks per day return ticks + 0x701ce1722770000ULL; @@ -470,49 +489,39 @@ namespace PAL_NS_BEGIN { { #ifdef _WIN32 __time64_t seconds = static_cast<__time64_t>(timestampMs / 1000); - int milliseconds = static_cast(timestampMs % 1000); - - tm tm; - if (::_gmtime64_s(&tm, &seconds) != 0) + tm timeParts; + if (::_gmtime64_s(&timeParts, &seconds) != 0) { - memset(&tm, 0, sizeof(tm)); + return {}; } - - char buf[sizeof("YYYY-MM-DDTHH:MM:SS.sssZ") + 1] = { 0 }; - ::_snprintf_s(buf, _TRUNCATE, "%04d-%02d-%02dT%02d:%02d:%02d.%03dZ", - 1900 + tm.tm_year, 1 + tm.tm_mon, tm.tm_mday, - tm.tm_hour, tm.tm_min, tm.tm_sec, milliseconds); #else time_t seconds = static_cast(timestampMs / 1000); - int milliseconds = static_cast(timestampMs % 1000); - - tm tm; - bool valid = (gmtime_r(&seconds, &tm) != NULL); - - if (!valid) + tm timeParts; + if (gmtime_r(&seconds, &timeParts) == nullptr) { - memset(&tm, 0, sizeof(tm)); + return {}; } - - char buf[sizeof("YYYY-MM-DDTHH:MM:SS.sssZ") + 1] = { 0 }; - -#if defined(__GNUC__) && !defined(__clang__) -#include -#if __GNUC_PREREQ(7,0) // If gcc_version >= 7.0 https://gcc.gnu.org/gcc-7/changes.html -#pragma GCC diagnostic push -#pragma GCC diagnostic ignored "-Wformat-truncation" // error: 'T' directive output may be truncated writing 1 byte into a region of size between 0 and 16 [-Werror=format-truncation=] -#endif -#endif - (void)snprintf(buf, sizeof(buf), "%04d-%02d-%02dT%02d:%02d:%02d.%03dZ", - 1900 + tm.tm_year, 1 + tm.tm_mon, tm.tm_mday, - tm.tm_hour, tm.tm_min, tm.tm_sec, milliseconds); -#if defined(__GNUC__) && !defined(__clang__) -#if __GNUC_PREREQ(7,0) // If gcc_version >= 7.0 https://gcc.gnu.org/gcc-7/changes.html -#pragma GCC diagnostic pop #endif -#endif -#endif - return buf; + + const int milliseconds = static_cast(timestampMs % 1000); + char buf[128] = { 0 }; + const int length = snprintf( + buf, + sizeof(buf), + "%04d-%02d-%02dT%02d:%02d:%02d.%03dZ", + 1900 + timeParts.tm_year, + 1 + timeParts.tm_mon, + timeParts.tm_mday, + timeParts.tm_hour, + timeParts.tm_min, + timeParts.tm_sec, + milliseconds); + if (length < 0 || static_cast(length) >= sizeof(buf)) + { + LOG_ERROR("Failed to format UTC timestamp"); + return {}; + } + return std::string(buf, static_cast(length)); } /** @@ -527,20 +536,27 @@ namespace PAL_NS_BEGIN { { #ifdef USE_WIN32_PERFCOUNTER /* Win32 API implementation */ - static bool frequencyQueried = false; - static int64_t ticksPerMillisecond; - if (!frequencyQueried) - { - // There is no harm in querying twice in case of a race condition. + static std::once_flag frequencyOnce; + static int64_t frequency = 0; + std::call_once(frequencyOnce, [] { LARGE_INTEGER ticksInOneSecond; - ::QueryPerformanceFrequency(&ticksInOneSecond); - ticksPerMillisecond = ticksInOneSecond.QuadPart / 1000; - frequencyQueried = true; - } + if (::QueryPerformanceFrequency(&ticksInOneSecond)) + { + frequency = ticksInOneSecond.QuadPart; + } + }); LARGE_INTEGER now; ::QueryPerformanceCounter(&now); - return static_cast(now.QuadPart / ticksPerMillisecond); + if (frequency <= 0) + { + return std::chrono::steady_clock::now().time_since_epoch() / std::chrono::milliseconds(1); + } + + const int64_t wholeSeconds = now.QuadPart / frequency; + const int64_t remainder = now.QuadPart % frequency; + return static_cast(wholeSeconds) * 1000u + + static_cast((remainder * 1000) / frequency); #else /* Cross-platform C++11 implementation */ return std::chrono::steady_clock::now().time_since_epoch() / std::chrono::milliseconds(1); diff --git a/lib/pal/TaskDispatcher.hpp b/lib/pal/TaskDispatcher.hpp index ec6f2f690..c2e6bbd42 100644 --- a/lib/pal/TaskDispatcher.hpp +++ b/lib/pal/TaskDispatcher.hpp @@ -16,6 +16,7 @@ #include #include #include +#include #include #include "ITaskDispatcher.hpp" @@ -25,6 +26,15 @@ namespace PAL_NS_BEGIN { namespace detail { + struct TaskLifetimeState + { + TaskLifetimeState() : + task(nullptr) + {} + + std::atomic task; + }; + template class TaskCall : public Task { @@ -48,14 +58,35 @@ namespace PAL_NS_BEGIN { this->TargetTime = targetTime; } + TaskCall(TCall& call, int64_t targetTime, std::shared_ptr lifetimeState) : + Task(), + m_call(call), + m_lifetimeState(std::move(lifetimeState)) + { + this->TypeName = TYPENAME(call); + this->Type = Task::TimedCall; + this->TargetTime = targetTime; + if (m_lifetimeState) { + m_lifetimeState->task.store(this, std::memory_order_release); + } + } + virtual void operator()() override { m_call(); } - virtual ~TaskCall() noexcept = default; + virtual ~TaskCall() noexcept + { + if (m_lifetimeState) { + m_lifetimeState->task.store(nullptr, std::memory_order_release); + } + } const TCall m_call; + + private: + std::shared_ptr m_lifetimeState; }; } // namespace detail @@ -63,14 +94,11 @@ namespace PAL_NS_BEGIN { class DeferredCallbackHandle { public: - std::mutex m_mutex; - MAT::Task* m_task = nullptr; - MAT::ITaskDispatcher* m_taskDispatcher = nullptr; - - DeferredCallbackHandle(MAT::Task* task, MAT::ITaskDispatcher* taskDispatcher) : - m_task(task), + DeferredCallbackHandle(std::shared_ptr taskLifetimeState, MAT::ITaskDispatcher* taskDispatcher) : + m_taskLifetimeState(std::move(taskLifetimeState)), m_taskDispatcher(taskDispatcher) { } - DeferredCallbackHandle() {} + + DeferredCallbackHandle() = default; DeferredCallbackHandle(DeferredCallbackHandle&& h) { *this = std::move(h); @@ -78,30 +106,64 @@ namespace PAL_NS_BEGIN { DeferredCallbackHandle& operator=(DeferredCallbackHandle&& other) { + if (this == &other) { + return *this; + } + std::lock_guard lock(m_mutex); std::lock_guard otherLock(other.m_mutex); - m_task = other.m_task; - other.m_task = nullptr; + m_taskLifetimeState = std::move(other.m_taskLifetimeState); m_taskDispatcher = other.m_taskDispatcher; + other.m_taskDispatcher = nullptr; return *this; } + MAT::Task* GetTask() const + { + std::lock_guard lock(m_mutex); + return (m_taskLifetimeState != nullptr) ? m_taskLifetimeState->task.load(std::memory_order_acquire) : nullptr; + } + bool Cancel(uint64_t waitTime = 0) { std::lock_guard lock(m_mutex); - if (m_task) + MAT::Task* task = (m_taskLifetimeState != nullptr) ? m_taskLifetimeState->task.load(std::memory_order_acquire) : nullptr; + if (task) { - bool result = (m_taskDispatcher != nullptr) && (m_taskDispatcher->Cancel(m_task, waitTime)); - return result; + bool result = (m_taskDispatcher != nullptr) && (m_taskDispatcher->Cancel(task, waitTime)); + return result || ((m_taskLifetimeState != nullptr) && (m_taskLifetimeState->task.load(std::memory_order_acquire) == nullptr)); } else { // Canceled nothing successfully return true; } } + + private: + mutable std::mutex m_mutex; + std::shared_ptr m_taskLifetimeState; + MAT::ITaskDispatcher* m_taskDispatcher = nullptr; }; + inline DeferredCallbackHandle scheduleTask( + MAT::ITaskDispatcher* taskDispatcher, + unsigned delayMs, + std::function call) + { + auto taskLifetime = std::make_shared(); + auto task = new detail::TaskCall>( + call, + getMonotonicTimeMs() + static_cast(delayMs), + taskLifetime); + taskDispatcher->Queue(task); + if (taskLifetime->task.load(std::memory_order_acquire) == nullptr) + { + return DeferredCallbackHandle(); + } + return DeferredCallbackHandle(taskLifetime, taskDispatcher); + } + template void dispatchTask(MAT::ITaskDispatcher* taskDispatcher, TObject* obj, void (TObject::*func)(TFuncArgs...), TPassedArgs&&... args) { @@ -121,9 +183,19 @@ namespace PAL_NS_BEGIN { DeferredCallbackHandle scheduleTask(MAT::ITaskDispatcher* taskDispatcher, unsigned delayMs, TObject* obj, void (TObject::*func)(TFuncArgs...), TPassedArgs&&... args) { auto bound = std::bind(std::mem_fn(func), obj, std::forward(args)...); - auto task = new detail::TaskCall(bound, getMonotonicTimeMs() + (int64_t)delayMs); + auto taskLifetime = std::make_shared(); + auto task = new detail::TaskCall(bound, getMonotonicTimeMs() + (int64_t)delayMs, taskLifetime); taskDispatcher->Queue(task); - return DeferredCallbackHandle(task, taskDispatcher); + // Queue() is void; an SDK dispatcher that rejects by deleting the task + // synchronously clears this state before Queue() returns, and the task + // destructor publishes completion after normal asynchronous execution. + // Cancel() treats the pointer only as an opaque dispatcher identity + // because completion may race the handle's atomic load. + if (taskLifetime->task.load(std::memory_order_acquire) == nullptr) + { + return DeferredCallbackHandle(); + } + return DeferredCallbackHandle(taskLifetime, taskDispatcher); } template @@ -135,4 +207,3 @@ namespace PAL_NS_BEGIN { } PAL_NS_END #endif - diff --git a/lib/pal/TaskDispatcher_CAPI.cpp b/lib/pal/TaskDispatcher_CAPI.cpp index e75ee1924..5fd28ba48 100644 --- a/lib/pal/TaskDispatcher_CAPI.cpp +++ b/lib/pal/TaskDispatcher_CAPI.cpp @@ -6,11 +6,14 @@ #include #include +#include #include +#include #include #include #include #include +#include #include "ctmacros.hpp" #include "pal/PAL.hpp" @@ -32,11 +35,28 @@ namespace PAL_NS_BEGIN { Task* GetTask() { + std::lock_guard lock(m_stateLock); return m_task.get(); } + bool BeginCallback() + { + std::lock_guard lock(m_stateLock); + if (m_done || m_cancelled) + { + return false; + } + m_running = true; + m_callbackThread = std::this_thread::get_id(); + return true; + } + void OnCallback() { + if (!BeginCallback()) + { + return; + } if (m_task) { // The task is host/user code running on the external dispatcher's // thread; an exception escaping here would terminate the process. @@ -45,13 +65,54 @@ namespace PAL_NS_BEGIN { (*m_task)(); } catch (const std::exception& ex) { + (void)ex; LOG_ERROR("Unhandled exception in CAPI task: %s", ex.what()); } catch (...) { LOG_ERROR("Unhandled non-standard exception in CAPI task"); } } - ReleaseItem(); + { + std::lock_guard lock(m_stateLock); + ReleaseItem(); + m_running = false; + m_done = true; + } + m_doneCv.notify_all(); + } + + bool RequestCancel() + { + std::lock_guard lock(m_stateLock); + if (m_done) + { + return false; + } + m_cancelled = true; + if (!m_running) + { + m_done = true; + m_doneCv.notify_all(); + } + return m_running; + } + + bool WaitForCompletion(uint64_t waitTime) + { + std::unique_lock lock(m_stateLock); + if (m_done || m_callbackThread == std::this_thread::get_id()) + { + return true; + } + if (waitTime == std::numeric_limits::max()) + { + m_doneCv.wait(lock, [this] { return m_done; }); + } + else if (waitTime > 0) + { + m_doneCv.wait_for(lock, std::chrono::milliseconds(waitTime), [this] { return m_done; }); + } + return m_done; } private: @@ -64,6 +125,12 @@ namespace PAL_NS_BEGIN { } std::unique_ptr m_task; + std::mutex m_stateLock; + std::condition_variable m_doneCv; + std::thread::id m_callbackThread; + bool m_running = false; + bool m_done = false; + bool m_cancelled = false; }; @@ -85,18 +152,26 @@ namespace PAL_NS_BEGIN { { std::shared_ptr task; - // Find and remove pending task + // Keep the task discoverable while its callback is running so a + // concurrent cancellation can wait for completion. { LOCKGUARD(s_tasksLock); auto itTask = GetPendingTasks().find(taskId); if (itTask != GetPendingTasks().end()) { task = itTask->second; - GetPendingTasks().erase(itTask); } } if (task) + { task->OnCallback(); + LOCKGUARD(s_tasksLock); + auto itTask = GetPendingTasks().find(taskId); + if (itTask != GetPendingTasks().end() && itTask->second == task) + { + GetPendingTasks().erase(itTask); + } + } } TaskDispatcher_CAPI::TaskDispatcher_CAPI(task_dispatcher_queue_fn_t queueFn, task_dispatcher_cancel_fn_t cancelFn, task_dispatcher_join_fn_t joinFn) @@ -141,10 +216,10 @@ namespace PAL_NS_BEGIN { m_queueFn(&capiTask, &OnAsyncTaskCallback); } - // TODO: currently shutdown wait on task cancellation is not implemented for C API Task Dispatcher - bool TaskDispatcher_CAPI::Cancel(Task* task, uint64_t) + bool TaskDispatcher_CAPI::Cancel(Task* task, uint64_t waitTime) { std::string taskId; + std::shared_ptr capiTask; // Find and erase pending task { @@ -156,12 +231,32 @@ namespace PAL_NS_BEGIN { if (itTask != GetPendingTasks().end()) { taskId = itTask->first; - GetPendingTasks().erase(itTask); + capiTask = itTask->second; } } - return (!taskId.empty()) ? m_cancelFn(taskId.c_str()) : false; + if (taskId.empty()) + { + return false; + } + + const bool wasRunning = capiTask->RequestCancel(); + m_cancelFn(taskId.c_str()); + if (!wasRunning) + { + LOCKGUARD(s_tasksLock); + GetPendingTasks().erase(taskId); + return true; + } + + if (capiTask->WaitForCompletion(waitTime)) + { + LOCKGUARD(s_tasksLock); + GetPendingTasks().erase(taskId); + return true; + } + + return false; } } PAL_NS_END - diff --git a/lib/pal/WorkerThread.cpp b/lib/pal/WorkerThread.cpp index 3adfb9e61..97f35aa36 100644 --- a/lib/pal/WorkerThread.cpp +++ b/lib/pal/WorkerThread.cpp @@ -7,6 +7,9 @@ #include "pal/PAL.hpp" #include +#include +#include +#include #if defined(MATSDK_PAL_CPP11) || defined(MATSDK_PAL_WIN32) @@ -29,6 +32,14 @@ namespace PAL_NS_BEGIN { { protected: std::thread m_hThread; + // The worker thread's own id, captured under m_lock once threadFunc starts. + // onLastReferenceReleased() reads it (under m_lock) rather than m_hThread.get_id() + // to detect "am I running on my own worker thread?", because m_hThread.get_id() + // returns the default not-a-thread id after a detach() -- so this keeps + // self-dispose detection correct even if the thread was detached first. A plain + // std::thread::id guarded by m_lock is used rather than std::atomic, + // which is not portable (std::thread::id is not guaranteed trivially copyable). + std::thread::id m_workerId; std::recursive_mutex m_lock; std::timed_mutex m_execution_mutex; @@ -36,16 +47,21 @@ namespace PAL_NS_BEGIN { std::list m_queue; std::list m_timerQueue; Event m_event; - MAT::Task* m_itemInProgress; - int count = 0; + std::atomic m_itemInProgress; + bool m_shuttingDown = false; + std::mutex m_joinLock; + // Set when the last reference is released by a task running on this worker + // thread, so threadFunc performs the final delete after its loop breaks + // (see onLastReferenceReleased() and WorkerThreadFactory::Create()). + std::atomic m_disposeFromThread { false }; public: WorkerThread() { - m_itemInProgress = nullptr; + m_itemInProgress.store(nullptr, std::memory_order_relaxed); m_hThread = std::thread(WorkerThread::threadFunc, static_cast(this)); - LOG_INFO("Started new thread %u", m_hThread.get_id()); + LOG_INFO("Started new thread %zu", std::hash{}(m_hThread.get_id())); } ~WorkerThread() @@ -53,34 +69,116 @@ namespace PAL_NS_BEGIN { Join(); } + private: + void enqueueShutdownItemLocked() + { + if (!m_shuttingDown) { + m_shuttingDown = true; + m_queue.push_back(new WorkerThreadShutdownItem()); + m_event.post(); + } + } + + void drainPendingTasksLocked() + { + if (!m_queue.empty()) { + LOG_WARN("Shutdown with %zu queued task(s) pending", m_queue.size()); + } + if (!m_timerQueue.empty()) { + LOG_WARN("Shutdown with %zu timer(s) pending", m_timerQueue.size()); + } + for (auto task : m_queue) { delete task; } + m_queue.clear(); + for (auto task : m_timerQueue) { delete task; } + m_timerQueue.clear(); + } + + public: void Join() final { - auto item = new WorkerThreadShutdownItem(); - Queue(item); + LOCKGUARD(m_joinLock); std::thread::id this_id = std::this_thread::get_id(); - try { - if (m_hThread.joinable() && (m_hThread.get_id() != this_id)) - m_hThread.join(); - else + std::thread threadToJoin; + bool joined = false; + { + LOCKGUARD(m_lock); + enqueueShutdownItemLocked(); + if (!m_hThread.joinable()) { + return; + } + if (m_hThread.get_id() == this_id) { m_hThread.detach(); + } else { + threadToJoin = std::move(m_hThread); + } + } + try { + if (threadToJoin.joinable()) { + threadToJoin.join(); + joined = true; + } + } + catch (const std::system_error& e) { + (void)e; + LOG_ERROR("Thread join/detach failed: [%d] %s", e.code().value(), e.what()); + std::terminate(); + } + catch (const std::exception& e) { + (void)e; + LOG_ERROR("Thread join/detach failed: %s", e.what()); + std::terminate(); } - catch (...) {}; - // TODO: [MG] - investigate if we ever drop work items on shutdown. - if (!m_queue.empty()) - { - LOG_WARN("m_queue is not empty!"); + LOCKGUARD(m_lock); + // Clean up any tasks remaining in the queues after shutdown. + // Only safe after join() — the thread has fully exited. + // After detach(), the thread still needs the shutdown item + // and may still be accessing the queues. + if (joined) { + drainPendingTasksLocked(); } - if (!m_timerQueue.empty()) + } + + // Invoked by the shared_ptr deleter when the last reference is released. + // Returns true if the caller should delete the object, false if deletion was + // deferred to the worker thread. The worker is shared process-wide, so the + // last reference can be dropped by a task running on the worker thread itself + // (e.g. a task that tears down its LogManager/PAL). In that case threadFunc is + // still on the stack below the task and keeps touching members after the task + // returns, so freeing the object here would be a use-after-free: instead + // detach, signal shutdown, mark the thread to delete itself once its loop + // breaks, and leave the object alive. On any other thread it is safe to delete + // immediately (~WorkerThread joins the worker first). + bool onLastReferenceReleased() + { + LOCKGUARD(m_lock); + if (m_workerId == std::this_thread::get_id()) { - LOG_WARN("m_timerQueue is not empty!"); + enqueueShutdownItemLocked(); + m_disposeFromThread.store(true, std::memory_order_release); + try { + if (m_hThread.joinable()) { + m_hThread.detach(); + } + } + catch (const std::exception& e) { + (void)e; + LOG_ERROR("Worker self-detach failed: %s", e.what()); + } + return false; } + return true; } void Queue(MAT::Task* item) final { - LOG_INFO("queue item=%p", &item); + LOG_INFO("queue item=%p", static_cast(item)); LOCKGUARD(m_lock); + if (m_shuttingDown) { + LOG_WARN("Dropping queued task %p during shutdown", static_cast(item)); + delete item; + return; + } if (item->Type == MAT::Task::TimedCall) { auto it = m_timerQueue.begin(); while (it != m_timerQueue.end() && (*it)->TargetTime < item->TargetTime) { @@ -91,16 +189,14 @@ namespace PAL_NS_BEGIN { else { m_queue.push_back(item); } - count++; m_event.post(); } // Cancel a task or wait for task completion for up to waitTime ms: // - // - acquire the m_lock to prevent a new task from getting scheduled. - // This may block the scheduling of a new task in queue for up to - // waitTime in case if the task being canceled - // is the one being executed right now. + // - acquire m_lock to inspect the current task or remove a queued task. + // Do not hold it while waiting for an active task to finish, because + // the active task may need to queue follow-up work. // // - if currently executing task is the one we are trying to cancel, // then verify for recursion: if the current thread is the same @@ -122,20 +218,42 @@ namespace PAL_NS_BEGIN { // bool Cancel(MAT::Task* item, uint64_t waitTime) override { - LOCKGUARD(m_lock); + std::unique_lock lock(m_lock); if (item == nullptr) { return false; } - if (m_itemInProgress == item) + if (m_itemInProgress.load(std::memory_order_acquire) == item) { /* Can't recursively wait on completion of our own thread */ - if (m_hThread.get_id() != std::this_thread::get_id()) + if (m_workerId != std::this_thread::get_id()) { - if (waitTime > 0 && m_execution_mutex.try_lock_for(std::chrono::milliseconds(waitTime))) + // Do not hold m_lock while waiting for the worker. A task + // may queue follow-up work before it finishes, which needs + // the same lock. + lock.unlock(); + bool locked = false; + if (waitTime == std::numeric_limits::max()) + { + m_execution_mutex.lock(); + locked = true; + } + else if (waitTime > 0) { - m_itemInProgress = nullptr; + locked = m_execution_mutex.try_lock_for(std::chrono::milliseconds(waitTime)); + } + if (locked) + { + // Prevent a dequeued but not-yet-started task from running. + // Only clear the requested task: after releasing m_lock, + // the worker may already have published its successor. + MAT::Task* expected = item; + m_itemInProgress.compare_exchange_strong( + expected, + nullptr, + std::memory_order_acq_rel, + std::memory_order_acquire); m_execution_mutex.unlock(); } } @@ -150,7 +268,7 @@ namespace PAL_NS_BEGIN { * true - if item in progress is different than item (other task) * false - if item in progress is still the same (didn't wait long enough) */ - return (m_itemInProgress != item); + return (m_itemInProgress.load(std::memory_order_acquire) != item); } { @@ -161,17 +279,6 @@ namespace PAL_NS_BEGIN { delete item; } } -#if 0 - for (;;) { - { - LOCKGUARD(m_lock); - if (item->Type == MAT::Task::Done) { - return; - } - } - Sleep(10); - } -#endif return true; } @@ -181,7 +288,11 @@ namespace PAL_NS_BEGIN { uint64_t wakeupCount = 0; WorkerThread* self = reinterpret_cast(lpThreadParameter); - LOG_INFO("Running thread %u", std::this_thread::get_id()); + { + LOCKGUARD(self->m_lock); + self->m_workerId = std::this_thread::get_id(); + } + LOG_INFO("Running thread %zu", std::hash{}(std::this_thread::get_id())); for (;;) { std::unique_ptr item = nullptr; @@ -218,7 +329,7 @@ namespace PAL_NS_BEGIN { } if (item) { - self->m_itemInProgress = item.get(); + self->m_itemInProgress.store(item.get(), std::memory_order_release); } } @@ -230,7 +341,17 @@ namespace PAL_NS_BEGIN { if (item->Type == MAT::Task::Shutdown) { item.reset(); - self->m_itemInProgress = nullptr; + self->m_itemInProgress.store(nullptr, std::memory_order_release); + // Drop any tasks still queued behind the shutdown sentinel + // (e.g. future-dated timers) before exiting. The owning thread + // deletes these in Join() only after a successful join(); on the + // self-Join path it detaches and skips that cleanup, so draining + // here prevents leaking those tasks. This matches the join()-path + // behavior of dropping un-run work at shutdown. + { + LOCKGUARD(self->m_lock); + self->drainPendingTasksLocked(); + } break; } @@ -238,7 +359,7 @@ namespace PAL_NS_BEGIN { std::lock_guard lock(self->m_execution_mutex); // Item wasn't cancelled before it could be executed - if (self->m_itemInProgress != nullptr) { + if (self->m_itemInProgress.load(std::memory_order_acquire) == item.get()) { LOG_TRACE("%10llu Execute item=%p type=%s\n", wakeupCount, item.get(), item.get()->TypeName.c_str() ); // A task can run arbitrary work (storage I/O, HTTP encode, and // user DebugEventListener callbacks). An exception escaping here @@ -248,12 +369,13 @@ namespace PAL_NS_BEGIN { (*item)(); } catch (const std::exception& ex) { + (void)ex; LOG_ERROR("Unhandled exception in worker task: %s", ex.what()); } catch (...) { LOG_ERROR("Unhandled non-standard exception in worker task"); } - self->m_itemInProgress = nullptr; + self->m_itemInProgress.store(nullptr, std::memory_order_release); } if (item) { @@ -262,17 +384,31 @@ namespace PAL_NS_BEGIN { } } } + + // The loop has broken on a Shutdown item. If the last reference was + // released by a task on this worker thread, onLastReferenceReleased() + // detached and deferred deletion to us; perform it now, after all member + // access is done, so the object outlives threadFunc rather than being + // freed underneath it. + if (self->m_disposeFromThread.load(std::memory_order_acquire)) { + delete self; + } } }; namespace WorkerThreadFactory { std::shared_ptr Create() { - return std::make_shared(); + // Custom deleter so that a last-reference release happening on the worker + // thread itself defers destruction to the thread (see + // onLastReferenceReleased) instead of freeing the object underneath a + // still-running threadFunc. + return std::shared_ptr( + new WorkerThread(), + [](WorkerThread* self) { if (self->onLastReferenceReleased()) delete self; }); } } } PAL_NS_END #endif - diff --git a/lib/tpm/TransmissionPolicyManager.cpp b/lib/tpm/TransmissionPolicyManager.cpp index 83b82cf2a..bd3420dce 100644 --- a/lib/tpm/TransmissionPolicyManager.cpp +++ b/lib/tpm/TransmissionPolicyManager.cpp @@ -47,7 +47,8 @@ namespace MAT_NS_BEGIN { m_system(system), m_taskDispatcher(taskDispatcher), m_config(m_system.getConfig()), - m_bandwidthController(bandwidthController) + m_bandwidthController(bandwidthController), + m_scheduledUploadCallbackState(std::make_shared(this)) { m_backoff = IBackoff::createFromConfig(m_backoffConfig); assert(m_backoff); @@ -56,6 +57,7 @@ namespace MAT_NS_BEGIN { TransmissionPolicyManager::~TransmissionPolicyManager() { + m_scheduledUploadCallbackState->Invalidate(); m_deviceStateHandler.Stop(); } @@ -111,26 +113,36 @@ namespace MAT_NS_BEGIN { LOG_TRACE("Collector URL is not set, no upload."); return; } - LOCKGUARD(m_scheduledUploadMutex); - if (delay.count() < 0 || m_timerdelay.count() < 0) - { - LOG_TRACE("Negative delay(%d) or m_timerdelay(%d), no upload", delay.count(), m_timerdelay.count()); - return; - } - if (m_scheduledUploadAborted) - { - LOG_TRACE("Scheduled upload aborted, no upload."); - return; - } - if (uploadCount() >= static_cast(m_config[CFG_INT_MAX_PENDING_REQ]) ) + auto shouldSkipScheduling = [&delay, this]() -> bool { - LOG_TRACE("Maximum number of HTTP requests reached"); - return; - } + if (delay.count() < 0 || m_timerdelay.count() < 0) + { + LOG_TRACE("Negative delay(%lld) or m_timerdelay(%lld), no upload", + static_cast(delay.count()), static_cast(m_timerdelay.count())); + return true; + } + if (m_scheduledUploadAborted) + { + LOG_TRACE("Scheduled upload aborted, no upload."); + return true; + } + if (uploadCount() >= static_cast(m_config[CFG_INT_MAX_PENDING_REQ])) + { + LOG_TRACE("Maximum number of HTTP requests reached"); + return true; + } + if (m_isPaused) + { + LOG_TRACE("Paused, not uploading anything until resumed"); + return true; + } + + return false; + }; - if (m_isPaused) + LOCKGUARD(m_scheduledUploadMutex); + if (shouldSkipScheduling()) { - LOG_TRACE("Paused, not uploading anything until resumed"); return; } @@ -151,10 +163,9 @@ namespace MAT_NS_BEGIN { if (delta <= static_cast(delay.count())) { // Don't need to cancel and reschedule if it's about to happen now anyways. - // m_isUploadScheduled check does not have to be strictly atomic because // the completion of upload will schedule more uploads as-needed, we only // want to avoid the unnecessary wasteful rescheduling. - LOG_TRACE("WAIT upload %d ms for lat=%d", delta, m_runningLatency); + LOG_TRACE("WAIT upload %llu ms for lat=%d", static_cast(delta), m_runningLatency); return; } } @@ -162,19 +173,47 @@ namespace MAT_NS_BEGIN { // Cancel upload if already scheduled. if (force || delay.count() == 0) { - if (!cancelUploadTask()) + if (!cancelUploadTaskNoWaitLocked()) { LOG_TRACE("Upload either hasn't been scheduled or already done."); + // Cancel can return false when the previous upload task is + // currently executing on the worker. If uploadAsync hasn't + // yet entered its own LOCKGUARD (m_isUploadScheduled is + // still set under the mutex we hold), propagate the + // requested latency so the running task picks it up when + // it acquires m_scheduledUploadMutex. Otherwise the + // running task has already cleared the flag and the + // schedule below will queue a fresh task. + if (m_isUploadScheduled) + { + m_runningLatency = latency; + } + } + if (shouldSkipScheduling()) + { + return; } } // Schedule new upload - if (!m_isUploadScheduled.exchange(true)) + if (!m_isUploadScheduled) { + m_isUploadScheduled = true; m_scheduledUploadTime = PAL::getMonotonicTimeMs() + delay.count(); m_runningLatency = latency; - LOG_TRACE("SCHED upload %d ms for lat=%d", delay.count(), m_runningLatency); - m_scheduledUpload = PAL::scheduleTask(&m_taskDispatcher, static_cast(delay.count()), this, &TransmissionPolicyManager::uploadAsync, latency); + LOG_TRACE("SCHED upload %lld ms for lat=%d", static_cast(delay.count()), m_runningLatency); + auto callbackState = m_scheduledUploadCallbackState; + m_scheduledUpload = PAL::scheduleTask( + &m_taskDispatcher, + static_cast(delay.count()), + [callbackState, latency]() { + callbackState->Invoke(latency); + }); + if (m_scheduledUpload.GetTask() == nullptr) + { + m_isUploadScheduled = false; + m_scheduledUploadTime = std::numeric_limits::max(); + } } } @@ -184,16 +223,15 @@ namespace MAT_NS_BEGIN { if (guard.isPaused()) { return; } - m_runningLatency = latency; - m_scheduledUploadTime = std::numeric_limits::max(); - + EventLatency requestedLatency = latency; { LOCKGUARD(m_scheduledUploadMutex); + requestedLatency = m_runningLatency; + m_scheduledUploadTime = std::numeric_limits::max(); m_isUploadScheduled = false; // Allow to schedule another uploadAsync if ((m_isPaused) || (m_scheduledUploadAborted)) { - LOG_TRACE("Paused or upload aborted: cancel pending upload task."); - cancelUploadTask(); // If there is a pending upload task, kill it + LOG_TRACE("Paused or upload aborted: skip upload."); return; } } @@ -210,14 +248,14 @@ namespace MAT_NS_BEGIN { unsigned delayMs = 1000; LOG_INFO("Bandwidth controller proposed bandwidth %u bytes/sec but minimum accepted is %u, will retry %u ms later", proposedBandwidthBps, minimumBandwidthBps, delayMs); - scheduleUpload(delayMs, latency); // reschedule uploadAsync to run again 1000 ms later + scheduleUpload(std::chrono::milliseconds{delayMs}, requestedLatency); // reschedule uploadAsync to run again 1000 ms later return; } } #endif auto ctx = m_system.createEventsUploadContext(); - ctx->requestedMinLatency = m_runningLatency; + ctx->requestedMinLatency = requestedLatency; addUpload(ctx); initiateUpload(ctx); } @@ -238,7 +276,7 @@ namespace MAT_NS_BEGIN { // Rescheduling upload if (nextUpload.count() >= 0) { - LOG_TRACE("Scheduling upload in %d ms", nextUpload.count()); + LOG_TRACE("Scheduling upload in %lld ms", static_cast(nextUpload.count())); EventLatency proposed = calculateNewPriority(); scheduleUpload(nextUpload, proposed); // reschedule uploadAsync again } @@ -284,8 +322,16 @@ namespace MAT_NS_BEGIN { LOCKGUARD(m_scheduledUploadMutex); // Prevent execution of all upload tasks m_scheduledUploadAborted = true; - // Make sure we wait for completion of the upload scheduling task that may be running - cancelUploadTask(); + } + // A queued task retains only the callback state. Invalidate it first so + // an uncooperative custom dispatcher cannot run the manager callback + // after teardown; Invalidate waits for an already-running callback. + m_scheduledUploadCallbackState->Invalidate(); + cancelUploadTask(true); + { + LOCKGUARD(m_scheduledUploadMutex); + m_isUploadScheduled = false; + m_scheduledUploadTime = std::numeric_limits::max(); } // Make sure we wait for all active upload callbacks to finish @@ -342,7 +388,12 @@ namespace MAT_NS_BEGIN { } // Schedule async upload if not scheduled yet - if (!m_isUploadScheduled || TransmitProfiles::isTimerUpdateRequired()) + bool isUploadScheduled = false; + { + LOCKGUARD(m_scheduledUploadMutex); + isUploadScheduled = m_isUploadScheduled; + } + if (!isUploadScheduled || TransmitProfiles::isTimerUpdateRequired()) { if (updateTimersIfNecessary()) { @@ -374,7 +425,13 @@ namespace MAT_NS_BEGIN { return EventLatency_RealTime; } - if (m_runningLatency == EventLatency_RealTime) + EventLatency runningLatency = EventLatency_RealTime; + { + LOCKGUARD(m_scheduledUploadMutex); + runningLatency = m_runningLatency; + } + + if (runningLatency == EventLatency_RealTime) { return EventLatency_Normal; } @@ -453,16 +510,51 @@ namespace MAT_NS_BEGIN { return (m_scheduledUploadAborted) ? DefaultTaskCancelTime : std::chrono::milliseconds {}; } - bool TransmissionPolicyManager::cancelUploadTask() + bool TransmissionPolicyManager::cancelUploadTaskNoWaitLocked() { - bool result = m_scheduledUpload.Cancel(getCancelWaitTime().count()); + bool result = m_scheduledUpload.Cancel(std::chrono::milliseconds {}.count()); + + if (result) + { + m_isUploadScheduled = false; + m_scheduledUploadTime = std::numeric_limits::max(); + } + return result; + } + + bool TransmissionPolicyManager::cancelUploadTask(bool waitForCompletion) + { + uint64_t waitTime = 0; + { + LOCKGUARD(m_scheduledUploadMutex); + if (waitForCompletion) + { + // Poll with a representable finite duration so custom + // ITaskDispatcher implementations do not have to interpret an + // unsigned sentinel as an infinite signed chrono duration. + waitTime = std::max( + 1, + static_cast(DefaultTaskCancelTime.count())); + } + else + { + waitTime = static_cast(getCancelWaitTime().count()); + } + if (waitTime == 0) + { + return cancelUploadTaskNoWaitLocked(); + } + } + bool result = m_scheduledUpload.Cancel(waitTime); // TODO: There is a potential for upload tasks to not be canceled, especially if they aren't waited for. // We either need a stronger guarantee here (could impact SDK performance), or a mechanism to // ensure those tasks are canceled when the log manager is destroyed. Issue 388 if (result) { - m_isUploadScheduled.exchange(false); + LOCKGUARD(m_scheduledUploadMutex); + m_isUploadScheduled = false; + m_scheduledUploadTime = std::numeric_limits::max(); } return result; } @@ -473,9 +565,10 @@ namespace MAT_NS_BEGIN { return m_activeUploads.size(); } - bool TransmissionPolicyManager::isUploadInProgress() const noexcept + bool TransmissionPolicyManager::isUploadInProgress() const { // unfinished uploads that haven't processed callbacks or pending upload task + LOCKGUARD(m_scheduledUploadMutex); return (uploadCount() > 0) || m_isUploadScheduled; } diff --git a/lib/tpm/TransmissionPolicyManager.hpp b/lib/tpm/TransmissionPolicyManager.hpp index e1a91ad10..840dac107 100644 --- a/lib/tpm/TransmissionPolicyManager.hpp +++ b/lib/tpm/TransmissionPolicyManager.hpp @@ -24,14 +24,14 @@ #include #include #include +#include +#include #include namespace MAT_NS_BEGIN { -// This macro allows to specify max upload task cancellation wait time at compile-time, -// addressing the case when a task that we are trying to cancel is currently running. -// Default value: 500ms - sufficient for upload scheduler/batcher task to finish. -// Alternate value: UINT64_MAX - for infinite wait until the task is completed. +// This macro specifies the maximum duration of one upload-task cancellation +// attempt when the task may already be running. The default is 500 ms. #ifdef UPLOAD_TASK_CANCEL_TIME_MS static_assert(std::numeric_limits::max() >= UPLOAD_TASK_CANCEL_TIME_MS, "std::numeric_limits::max() >= UPLOAD_TASK_CANCEL_TIME_MS"); static_assert(UPLOAD_TASK_CANCEL_TIME_MS >= 0, "UPLOAD_TASK_CANCEL_TIME_MS >= 0"); @@ -51,6 +51,32 @@ constexpr const char* const DefaultBackoffConfig = "E,3000,300000,2,1"; virtual void scheduleUpload(const std::chrono::milliseconds& delay, EventLatency latency, bool force = false); protected: + struct ScheduledUploadCallbackState + { + explicit ScheduledUploadCallbackState(TransmissionPolicyManager* owner) + : manager(owner) + { + } + + void Invoke(EventLatency latency) + { + std::lock_guard lock(mutex); + if (manager != nullptr) + { + manager->uploadAsync(latency); + } + } + + void Invalidate() + { + std::lock_guard lock(mutex); + manager = nullptr; + } + + std::mutex mutex; + TransmissionPolicyManager* manager; + }; + MATSDK_LOG_DECL_COMPONENT_CLASS(); void checkBackoffConfigUpdate(); void resetBackoff(); @@ -88,11 +114,12 @@ constexpr const char* const DefaultBackoffConfig = "E,3000,300000,2,1"; std::string m_backoffConfig { DefaultBackoffConfig }; std::unique_ptr m_backoff; DeviceStateHandler m_deviceStateHandler; + std::shared_ptr m_scheduledUploadCallbackState; std::atomic m_isPaused { true }; - std::atomic m_isUploadScheduled { false }; + bool m_isUploadScheduled { false }; uint64_t m_scheduledUploadTime { std::numeric_limits::max() }; - std::mutex m_scheduledUploadMutex; + mutable std::mutex m_scheduledUploadMutex; PAL::DeferredCallbackHandle m_scheduledUpload; bool m_scheduledUploadAborted { false }; @@ -120,9 +147,16 @@ constexpr const char* const DefaultBackoffConfig = "E,3000,300000,2,1"; std::chrono::milliseconds getCancelWaitTime() const noexcept; /// - /// Cancels pending upload task. + /// Cancels a pending upload task without waiting for a running task to finish. + /// The caller must already hold m_scheduledUploadMutex. /// - bool cancelUploadTask(); + bool cancelUploadTaskNoWaitLocked(); + + /// + /// Cancels a pending upload task, optionally asking the dispatcher to + /// wait for at most DefaultTaskCancelTime. + /// + bool cancelUploadTask(bool waitForCompletion = false); /// /// Calculate the number of pending upload contexts. @@ -152,7 +186,7 @@ constexpr const char* const DefaultBackoffConfig = "E,3000,300000,2,1"; RouteSink eventsUploadFailed{ this, &TransmissionPolicyManager::handleEventsUploadFailed }; RouteSink eventsUploadAborted{ this, &TransmissionPolicyManager::handleEventsUploadAborted }; - virtual bool isUploadInProgress() const noexcept; + virtual bool isUploadInProgress() const; virtual bool isPaused() const noexcept; }; @@ -160,4 +194,3 @@ constexpr const char* const DefaultBackoffConfig = "E,3000,300000,2,1"; } MAT_NS_END #endif // TRANSMISSIONPOLICYMANAGER_HPP - diff --git a/lib/tpm/TransmitProfiles.cpp b/lib/tpm/TransmitProfiles.cpp index 5daec5f8b..b26766f6f 100644 --- a/lib/tpm/TransmitProfiles.cpp +++ b/lib/tpm/TransmitProfiles.cpp @@ -58,6 +58,7 @@ static void initTransmitProfileFields() transmitProfilePowerState["unknown"] = (PowerSource_Unknown); transmitProfilePowerState["battery"] = (PowerSource_Battery); transmitProfilePowerState["charging"] = (PowerSource_Charging); + transmitProfilePowerState["low_battery"] = (PowerSource_LowBattery); }; #endif @@ -103,11 +104,14 @@ namespace MAT_NS_BEGIN { LOG_TRACE("name=%s", profile.name.c_str()); size_t i = 0; for (auto &rule : profile.rules) { - LOG_TRACE("[%d] netCost=%2d, powState=%2d, timers=[%3d,%3d,%3d]", + // Custom profiles may supply fewer than three timers, so read + // out-of-range slots as 0 instead of indexing past the vector. + auto timerOrZero = [&rule](size_t idx) { return idx < rule.timers.size() ? rule.timers[idx] : 0; }; + LOG_TRACE("[%zu] netCost=%2d, powState=%2d, timers=[%3d,%3d,%3d]", i, rule.netCost, rule.powerState, - rule.timers[0], - rule.timers[1], - rule.timers[2]); + timerOrZero(0), + timerOrZero(1), + timerOrZero(2)); i++; } } @@ -512,14 +516,17 @@ namespace MAT_NS_BEGIN { isTimerUpdated = true; #ifdef HAVE_MAT_LOGGING auto it = profiles.find(currProfileName); - if (it != profiles.end()) { + if (it != profiles.end() && currRule < it->second.rules.size()) { /* Debug routine to print the list of currently selected timers */ TransmitProfileRule &rule = (it->second).rules[currRule]; + // The rule may carry fewer than three timers, so read out-of-range + // slots as 0 instead of indexing past the vector. + auto timerOrZero = [&rule](size_t idx) { return idx < rule.timers.size() ? rule.timers[idx] : 0; }; // Print just 3 timers for now because we support only 3 LOG_INFO("timers=[%3d,%3d,%3d]", - rule.timers[0], - rule.timers[1], - rule.timers[2]); + timerOrZero(0), + timerOrZero(1), + timerOrZero(2)); } #endif } diff --git a/lib/utils/Utils.cpp b/lib/utils/Utils.cpp index 22a48d87f..a1cf48ee7 100644 --- a/lib/utils/Utils.cpp +++ b/lib/utils/Utils.cpp @@ -103,15 +103,30 @@ namespace MAT_NS_BEGIN { if (IsRunningInApp()) { auto hr = RoInitialize(RO_INIT_MULTITHREADED); - /* Ignoring result from call to `RoInitialize` as either initialzation is successful, or else already - * initialized and it should be ok to proceed in both the scenarios */ - UNREFERENCED_PARAMETER(hr); - - ::Windows::Storage::StorageFolder ^ temp = ::Windows::Storage::ApplicationData::Current->TemporaryFolder; - // TODO: [MG] - // - verify that the path ends with a slash - // -- add exception handler in case if AppData temp folder is not accessible - return from_platform_string(temp->Path->ToString()); + // RoInitialize returns S_OK when it initializes the apartment and + // S_FALSE when it was already initialized on this thread; both add a + // reference that must be balanced with RoUninitialize. The RAII guard + // balances a successful init on every exit path, including if a WinRT + // call below throws. RPC_E_CHANGED_MODE and other failures did not + // initialize and are left unbalanced. + struct ApartmentGuard + { + HRESULT hr; + ~ApartmentGuard() { if (SUCCEEDED(hr)) { RoUninitialize(); } } + } apartmentGuard{hr}; + + std::string tempPath; + { + // Release the WinRT StorageFolder before the guard runs (at the + // end of the enclosing scope) so the object is not destroyed in an + // uninitialized apartment. + ::Windows::Storage::StorageFolder ^ temp = ::Windows::Storage::ApplicationData::Current->TemporaryFolder; + // TODO: [MG] + // - verify that the path ends with a slash + // -- add exception handler in case if AppData temp folder is not accessible + tempPath = from_platform_string(temp->Path->ToString()); + } + return tempPath; } else { @@ -177,9 +192,6 @@ namespace MAT_NS_BEGIN { EventRejectedReason validateEventName(std::string const& name) { - // Data collector uses this regex (avoided here for code size reasons): - // ^[a-zA-Z0-9]([a-zA-Z0-9]|_){2,98}[a-zA-Z0-9]$ - if (name.length() < 1 + 2 + 1 || name.length() > 1 + 98 + 1) { LOG_ERROR("Invalid event name - \"%s\": must be between 4 and 100 characters long", name.c_str()); return REJECTED_REASON_VALIDATION_FAILED; @@ -191,13 +203,6 @@ namespace MAT_NS_BEGIN { return REJECTED_REASON_VALIDATION_FAILED; } -#if 0 - if (name.front() == '_' || name.back() == '_') { - LOG_ERROR("Invalid event name - \"%s\": must not start or end with an underscore", name.c_str()); - return REJECTED_REASON_VALIDATION_FAILED; - } -#endif - return REJECTED_REASON_OK; } @@ -247,4 +252,3 @@ namespace MAT_NS_BEGIN { } } MAT_NS_END - diff --git a/lib/utils/annex_k.hpp b/lib/utils/annex_k.hpp index 5aa4b73af..3d7d1f915 100644 --- a/lib/utils/annex_k.hpp +++ b/lib/utils/annex_k.hpp @@ -150,9 +150,6 @@ static errno_t oneds_strncpy_s(char * restrict dest, rsize_t destsz, const char static errno_t oneds_memcpy_s( void *restrict dest, rsize_t destsz, const void *restrict src, rsize_t count ) noexcept { -#if (defined __STDC_LIB_EXT1__) || ( defined _MSC_VER) - return memcpy_s(dest, destsz, src, count); -#else if (dest == NULL) { return EINVAL; @@ -176,6 +173,9 @@ static errno_t oneds_memcpy_s( void *restrict dest, rsize_t destsz, memset(dest, 0, destsz); return EINVAL; } +#if (defined __STDC_LIB_EXT1__) || ( defined _MSC_VER) + return memcpy_s(dest, destsz, src, count); +#else void *result = memcpy(dest, src, count); if (result == (void *)NULL) { diff --git a/tests/common/MockIOfflineStorage.hpp b/tests/common/MockIOfflineStorage.hpp index d0bae4118..4c37df7d4 100644 --- a/tests/common/MockIOfflineStorage.hpp +++ b/tests/common/MockIOfflineStorage.hpp @@ -14,7 +14,7 @@ namespace testing { #pragma clang diagnostic ignored "-Winconsistent-missing-override" // GMock MOCK_METHOD* macros don't use override. #endif -class MockIOfflineStorage : public MAT::IOfflineStorage { +class MockIOfflineStorage : public MAT::IOfflineStorageModule { public: MockIOfflineStorage(); virtual ~MockIOfflineStorage(); @@ -46,4 +46,3 @@ class MockIOfflineStorage : public MAT::IOfflineStorage { #endif } // namespace testing - diff --git a/tests/common/MockIRuntimeConfig.hpp b/tests/common/MockIRuntimeConfig.hpp index a52ef8e8d..04a720732 100644 --- a/tests/common/MockIRuntimeConfig.hpp +++ b/tests/common/MockIRuntimeConfig.hpp @@ -19,13 +19,13 @@ namespace testing { class MockIRuntimeConfig : public MAT::RuntimeConfig_Default /* MAT::IRuntimeConfig */ { protected: - std::unique_ptr& GetStaticConfig() noexcept + static std::unique_ptr& GetStaticConfig() noexcept { static std::unique_ptr staticConfig; return staticConfig; } - MAT::ILogConfiguration& GetDefaultConfig() + static MAT::ILogConfiguration& GetDefaultConfig() { std::unique_ptr& staticConfig = GetStaticConfig(); if (!staticConfig) @@ -72,4 +72,3 @@ namespace testing { #endif } // namespace testing - diff --git a/tests/common/SocketTools.hpp b/tests/common/SocketTools.hpp index 0bfe350d3..17122b2f6 100644 --- a/tests/common/SocketTools.hpp +++ b/tests/common/SocketTools.hpp @@ -288,6 +288,33 @@ class Socket return (::setsockopt(m_sock, SOL_SOCKET, SO_REUSEADDR, reinterpret_cast(&value), sizeof(value)) == 0); } + /** + * Suppress SIGPIPE when writing to a socket whose peer has already gone away. + * + * The test HTTP server writes responses on the reactor thread. When a client + * (e.g. NSURLSession on Apple) cancels an in-flight upload during teardown, the + * connection can be reset before the response is flushed, so ::send() fails with + * EPIPE and raises SIGPIPE. The test process installs no SIGPIPE handler, so the + * default disposition terminates it - which surfaces as a silent, backtrace-less + * test-runner exit/restart rather than a normal test failure. + * + * Apple/BSD only supports this per-socket via SO_NOSIGPIPE; Linux uses the + * MSG_NOSIGNAL send() flag instead (see send() below). + */ + bool setNoSigPipe() + { +#ifdef SO_NOSIGPIPE + if (m_sock == Invalid) + { + return false; + } + int value = 1; + return (::setsockopt(m_sock, SOL_SOCKET, SO_NOSIGPIPE, &value, sizeof(value)) == 0); +#else + return true; +#endif + } + bool setNoDelay() { assert(m_sock != Invalid); @@ -326,7 +353,14 @@ class Socket int send(void const* buffer, unsigned size) { assert(m_sock != Invalid); - return static_cast(::send(m_sock, reinterpret_cast(buffer), size, 0)); +#if defined(MSG_NOSIGNAL) + // Linux: ask the kernel to return EPIPE instead of raising SIGPIPE. + int flags = MSG_NOSIGNAL; +#else + // Apple/Windows: handled by SO_NOSIGPIPE / not applicable. + int flags = 0; +#endif + return static_cast(::send(m_sock, reinterpret_cast(buffer), size, flags)); } bool bind(SocketAddr const& addr) @@ -361,6 +395,12 @@ class Socket socklen_t addrlen = sizeof(caddr); #endif csock = ::accept(m_sock, caddr, &addrlen); + if (!csock.invalid()) + { + // Accepted connections are written to from the reactor thread; a peer + // that resets mid-response must not kill the test process via SIGPIPE. + csock.setNoSigPipe(); + } return !csock.invalid(); } diff --git a/tests/functests/BasicFuncTests.cpp b/tests/functests/BasicFuncTests.cpp index bc879d3e6..3e203c6db 100644 --- a/tests/functests/BasicFuncTests.cpp +++ b/tests/functests/BasicFuncTests.cpp @@ -128,6 +128,7 @@ class BasicFuncTests : public ::testing::Test, protected: std::mutex mtx_requests; std::vector receivedRequests; + std::string serverBaseAddress; std::string serverAddress; HttpServer server; @@ -139,6 +140,9 @@ class BasicFuncTests : public ::testing::Test, std::condition_variable cv_gotEvents; std::mutex cv_m; + std::condition_variable cv_slowRequest; + std::mutex mtx_slowRequest; + bool slowRequestStarted = false; public: BasicFuncTests() : @@ -155,7 +159,8 @@ class BasicFuncTests : public ::testing::Test, int port = server.addListeningPort(HTTP_PORT); std::ostringstream os; os << "127.0.0.1:" << port; - serverAddress = "http://" + os.str() + "/simple/"; + serverBaseAddress = "http://" + os.str(); + serverAddress = serverBaseAddress + "/simple/"; server.setServerName(os.str()); server.addHandler("/simple/", *this); server.addHandler("/slow/", *this); @@ -186,9 +191,14 @@ class BasicFuncTests : public ::testing::Test, std::remove((fileName + "-journal").c_str()); } - virtual void Initialize() + virtual void Initialize( + int64_t maxTeardownUploadTimeInSec = 2, + int64_t cacheFileSize = 4096 * 1024) { - receivedRequests.clear(); + { + LOCKGUARD(mtx_requests); + receivedRequests.clear(); + } auto configuration = LogManager::GetLogConfiguration(); configuration[CFG_INT_TRACE_LEVEL_MASK] = 0xFFFFFFFF; @@ -201,15 +211,15 @@ class BasicFuncTests : public ::testing::Test, configuration[CFG_INT_RAM_QUEUE_SIZE] = 4096 * 20; configuration[CFG_STR_CACHE_FILE_PATH] = TEST_STORAGE_FILENAME; - configuration[CFG_INT_CACHE_FILE_SIZE] = 4096 * 1024; // 4MB default - configuration[CFG_INT_MAX_TEARDOWN_TIME] = 2; // 2 seconds wait on shutdown + configuration[CFG_INT_CACHE_FILE_SIZE] = cacheFileSize; + configuration[CFG_INT_MAX_TEARDOWN_TIME] = maxTeardownUploadTimeInSec; configuration[CFG_INT_STORAGE_FULL_PCT] = 75; // default configuration[CFG_INT_STORAGE_FULL_CHECK_TIME] = 5000; // default 5s configuration[CFG_STR_COLLECTOR_URL] = serverAddress.c_str(); configuration[CFG_MAP_HTTP][CFG_BOOL_HTTP_COMPRESSION] = false; // disable compression for now configuration[CFG_MAP_TPM][CFG_STR_TPM_BACKOFF] = "E,500,5000,2,1"; // faster retry for localhost tests configuration[CFG_MAP_METASTATS_CONFIG][CFG_INT_METASTATS_INTERVAL] = 30 * 60; // 30 mins - configuration[CFG_MAP_METASTATS_CONFIG]["enabled"] = true; // opt in to stats (disabled by default since #1420) + configuration[CFG_MAP_METASTATS_CONFIG]["enabled"] = true; // opt in to stats (disabled by default) configuration["name"] = __FILE__; configuration["version"] = "1.0.0"; @@ -237,6 +247,11 @@ class BasicFuncTests : public ::testing::Test, } if (request.uri.compare(0, 6, "/slow/") == 0) { + { + std::lock_guard lock(mtx_slowRequest); + slowRequestStarted = true; + } + cv_slowRequest.notify_all(); PAL::sleep(static_cast(request.content.size() / DELAY_FACTOR_FOR_SERVER)); } @@ -251,6 +266,15 @@ class BasicFuncTests : public ::testing::Test, return 200; } + bool waitForSlowRequest(unsigned timeoutSec) + { + std::unique_lock lock(mtx_slowRequest); + return cv_slowRequest.wait_for( + lock, + std::chrono::seconds(timeoutSec), + [this] { return slowRequestStarted; }); + } + bool waitForRequests(unsigned timeOutSec, unsigned expected_count = 1) { std::unique_lock lk(cv_m); @@ -502,6 +526,7 @@ class BasicFuncTests : public ::testing::Test, std::vector records() { + LOCKGUARD(mtx_requests); std::vector result; if (receivedRequests.size()) { @@ -521,6 +546,7 @@ class BasicFuncTests : public ::testing::Test, // Find first matching event CsProtocol::Record find(const std::string& name) { + LOCKGUARD(mtx_requests); CsProtocol::Record result; result.name = ""; if (receivedRequests.size()) @@ -594,6 +620,37 @@ TEST_F(BasicFuncTests, sendOneEvent_immediatelyStop) EXPECT_GE(receivedRequests.size(), (size_t)1); // at least 1 HTTP request with customer payload and stats } +TEST_F(BasicFuncTests, teardownDuringInFlightUpload_ShutsDownCleanly) +{ + // Smoke test for teardown while an upload is in flight. + // Uploads target the /slow/ endpoint with large payloads and MAX_TEARDOWN_TIME + // is 0, so FlushAndTeardown() returns while an upload is still outstanding. + // Teardown must complete cleanly without touching freed SDK state; run under a + // sanitizer (ASan/TSan) this guards the teardown-vs-upload path. + CleanStorage(); + static int64_t const ONE_EVENT_SIZE = 256 * 1024; + + // Point Initialize() at the (slow) endpoint so uploads stay in flight. + std::string savedAddress = serverAddress; + serverAddress = serverBaseAddress + "/slow/"; + Initialize(0); + serverAddress = savedAddress; + + for (int i = 0; i < 20; ++i) + { + EventProperties event("teardown_event"); + event.SetPriority(EventPriority_Normal); + event.SetProperty("big_data", std::string(static_cast(ONE_EVENT_SIZE), 'x')); + logger->LogEvent(event); + } + LogManager::UploadNow(); + ASSERT_TRUE(waitForSlowRequest(5)) + << "Upload did not reach the /slow/ endpoint"; + // Teardown with timeout 0 returns while the upload is still outstanding. + LogManager::FlushAndTeardown(); + SUCCEED(); +} + TEST_F(BasicFuncTests, sendNoPriorityEvents) { CleanStorage(); @@ -806,19 +863,20 @@ TEST_F(BasicFuncTests, configDecorations) TEST_F(BasicFuncTests, restartRecoversEventsFromStorage) { + EventProperties event1("first_event"); + EventProperties event2("second_event"); + event1.SetProperty("property1", "value1"); + event2.SetProperty("property2", "value2"); + event1.SetLatency(MAT::EventLatency::EventLatency_RealTime); + event1.SetPersistence(MAT::EventPersistence::EventPersistence_Critical); + event2.SetLatency(MAT::EventLatency::EventLatency_RealTime); + event2.SetPersistence(MAT::EventPersistence::EventPersistence_Critical); + { CleanStorage(); Initialize(); // This code is a bit racy because ResumeTransmission is done in Initialize LogManager::PauseTransmission(); - EventProperties event1("first_event"); - EventProperties event2("second_event"); - event1.SetProperty("property1", "value1"); - event2.SetProperty("property2", "value2"); - event1.SetLatency(MAT::EventLatency::EventLatency_RealTime); - event1.SetPersistence(MAT::EventPersistence::EventPersistence_Critical); - event2.SetLatency(MAT::EventLatency::EventLatency_RealTime); - event2.SetPersistence(MAT::EventPersistence::EventPersistence_Critical); logger->LogEvent(event1); logger->LogEvent(event2); FlushAndTeardown(); @@ -833,30 +891,16 @@ TEST_F(BasicFuncTests, restartRecoversEventsFromStorage) LogManager::SetTransmitProfile(TransmitProfile_RealTime); LogManager::UploadNow(); - // 1st request for realtime event - waitForEvents(10, 5); // start, first_event, second_event, ongoing, stop, start, fooEvent - // we drop two of the events during pause, though. - EXPECT_GE(receivedRequests.size(), (size_t)1); - if (receivedRequests.size() != 0) - { - auto payload = decodeRequest(receivedRequests[receivedRequests.size() - 1], false); - } + // The first manager persists both paused customer events and its lifecycle + // metastats; the second manager then uploads those plus its own start event. + waitForEvents(10, 7); + verifyEvent(event1, find(event1.GetName())); + verifyEvent(event2, find(event2.GetName())); + verifyEvent(fooEvent, find(fooEvent.GetName())); FlushAndTeardown(); } - - /* - ASSERT_THAT(receivedRequests, SizeIs(1)); - auto payload = decodeRequest(receivedRequests[0], false); - ASSERT_THAT(payload.TokenToDataPackagesMap, Contains(Key("functests-tenant-token"))); - ASSERT_THAT(payload.TokenToDataPackagesMap["functests-tenant-token"], SizeIs(1)); - auto const& dp = payload.TokenToDataPackagesMap["functests-tenant-token"][0]; - ASSERT_THAT(payload, SizeIs(2)); - verifyEvent(event1, payload[0]); - verifyEvent(event2, payload[1]); - */ } -#if 0 // FIXME: 1445871 [v3][1DS] Offline storage size may exceed configured limit TEST_F(BasicFuncTests, storageFileSizeDoesntExceedConfiguredSize) { CleanStorage(); @@ -865,15 +909,13 @@ TEST_F(BasicFuncTests, storageFileSizeDoesntExceedConfiguredSize) static int64_t const MAX_FILE_SIZE = 8 * 1024 * 1024; static int64_t const ALLOWED_OVERFLOW = 10 * MAX_FILE_SIZE / 100; - auto &configuration = LogManager::GetLogConfiguration(); - configuration[CFG_INT_MAX_TEARDOWN_TIME] = 0; - configuration[CFG_INT_CACHE_FILE_SIZE] = MAX_FILE_SIZE; - - std::string slowServiceUrl; - slowServiceUrl.insert(slowServiceUrl.find('/', sizeof("http://")) + 1, "slow/"); - configuration[CFG_STR_COLLECTOR_URL] = slowServiceUrl.c_str(); + auto& configuration = LogManager::GetLogConfiguration(); + configuration[CFG_BOOL_ENABLE_DB_DROP_IF_FULL] = true; + std::string savedAddress = serverAddress; + serverAddress = serverBaseAddress + "/slow/"; { - Initialize(); + Initialize(0, MAX_FILE_SIZE); + serverAddress = savedAddress; LogManager::PauseTransmission(); for (int i = 0; i < 50; i++) { EventProperties event("event" + toString(i)); @@ -887,38 +929,13 @@ TEST_F(BasicFuncTests, storageFileSizeDoesntExceedConfiguredSize) FlushAndTeardown(); std::string fileName = MAT::GetTempDirectory(); - fileName += "\\"; + fileName += PATH_SEPARATOR_CHAR; fileName += TEST_STORAGE_FILENAME; size_t fileSize = getFileSize(fileName); EXPECT_LE(fileSize, (size_t)(MAX_FILE_SIZE + ALLOWED_OVERFLOW)); } - - // Restore fast URL - configuration[CFG_STR_COLLECTOR_URL] = serverAddress.c_str(); - - { - Initialize(); - waitForEvents(5, 8); - if (receivedRequests.size()) - { - auto payload = decodeRequest(receivedRequests[0], false); - /* auto payload = decodeRequest(receivedRequests[0], false); - ASSERT_THAT(payload.TokenToDataPackagesMap["metastats-tenant-token"], SizeIs(1)); - auto const& dp = payload.TokenToDataPackagesMap["metastats-tenant-token"][0]; - ASSERT_THAT(payload, SizeIs(2)); - EXPECT_THAT(payload[0].Id, Not(IsEmpty())); - EXPECT_THAT(payload[0].Type, Eq("client_telemetry")); - EXPECT_THAT(payload[0].Extension, Contains(Pair("stats_rollup_kind", "stop"))); - // The expected number of dropped events is hard to estimate because of database overhead, - // varying timing, some events have been sent etc. Just check that it's at least a quarter. - EXPECT_THAT(payload[0].Extension, Contains(Pair("records_dropped_offline_storage_overflow", StrAsIntGt(50 / 4)))); - */ - } - FlushAndTeardown(); - } - + configuration[CFG_BOOL_ENABLE_DB_DROP_IF_FULL] = false; } -#endif TEST_F(BasicFuncTests, sendMetaStatsOnStart) { @@ -945,10 +962,10 @@ TEST_F(BasicFuncTests, sendMetaStatsOnStart) LogManager::ResumeTransmission(); // ? LogManager::SetTransmitProfile(TransmitProfile_RealTime); LogManager::UploadNow(); - waitForEvents(5, 4); // (start + stop) + (2 events + start) + waitForEvents(5, 6); // Four lifecycle metastats plus the two persisted customer events. auto r2 = records(); - ASSERT_GE(r2.size(), (size_t)4); // (start + stop) + (2 events + start) + ASSERT_EQ(r2.size(), (size_t)6); for (const auto &evt : { event1, event2 }) { @@ -1200,7 +1217,7 @@ TEST_F(BasicFuncTests, killSwitchWorks) configuration[CFG_STR_COLLECTOR_URL] = serverAddress.c_str(); configuration[CFG_MAP_HTTP][CFG_BOOL_HTTP_COMPRESSION] = false; // disable compression for now configuration[CFG_MAP_METASTATS_CONFIG]["interval"] = 30 * 60; // 30 mins - configuration[CFG_MAP_METASTATS_CONFIG]["enabled"] = true; // opt in to stats (disabled by default since #1420) + configuration[CFG_MAP_METASTATS_CONFIG]["enabled"] = true; // opt in to stats (disabled by default) configuration["name"] = __FILE__; configuration["version"] = "1.0.0"; @@ -1280,9 +1297,9 @@ TEST_F(BasicFuncTests, killIsTemporary) configuration[CFG_STR_CACHE_FILE_PATH] = TEST_STORAGE_FILENAME; configuration[CFG_INT_MAX_TEARDOWN_TIME] = 2; configuration[CFG_STR_COLLECTOR_URL] = serverAddress.c_str(); - configuration[CFG_MAP_HTTP][CFG_BOOL_HTTP_COMPRESSION] = false; - configuration[CFG_MAP_METASTATS_CONFIG]["interval"] = 30 * 60; - configuration[CFG_MAP_METASTATS_CONFIG]["enabled"] = true; + configuration[CFG_MAP_HTTP][CFG_BOOL_HTTP_COMPRESSION] = false; // disable compression for now + configuration[CFG_MAP_METASTATS_CONFIG]["interval"] = 30 * 60; // 30 mins + configuration[CFG_MAP_METASTATS_CONFIG]["enabled"] = true; // opt in to stats (disabled by default) configuration["name"] = __FILE__; configuration["version"] = "1.0.0"; configuration["config"] = { { "host", __FILE__ } }; @@ -1569,56 +1586,4 @@ TEST_F(BasicFuncTests, deleteEvents) } #endif -#if 0 // TODO: [MG] - re-enable this long-haul test -TEST_F(BasicFuncTests, serverProblemsDropEventsAfterMaxRetryCount) -{ - CleanStorage(); - - auto &configuration = LogManager::GetLogConfiguration(); - - std::string badServiceUrl; - badServiceUrl.insert(badServiceUrl.find('/', sizeof("http://")) + 1, "503/"); - - configuration[CFG_STR_COLLECTOR_URL] = badServiceUrl.c_str(); - - { - Initialize(); - - EventProperties event("event"); - event.SetProperty("property", "value"); - - logger->LogEvent(event); - - // After initial delay of 2 seconds, the library will send a request, wait 3 seconds, send 1st retry and stop. - // 2nd retry after another 3 seconds (using the good URL again) should not come - wait 1 more second to be sure. - PAL::sleep(2000 + 2 * 3000 + 1000); - // EXPECT_THAT(receivedRequests, SizeIs(0)); - - // Check meta stats on restart (will be first request) - FlushAndTeardown(); - } - - // Restore fast URL - configuration[CFG_STR_COLLECTOR_URL] = serverAddress.c_str(); - - { - configuration[CFG_INT_RAM_QUEUE_SIZE] = 4096 * 20; - configuration[CFG_STR_CACHE_FILE_PATH] = TEST_STORAGE_FILENAME; - Initialize(); - waitForEvents(5, 2); - if (receivedRequests.size()) - { - auto payload = decodeRequest(receivedRequests[receivedRequests.size() - 1], false); - /* auto const& dp = payload.TokenToDataPackagesMap["metastats-tenant-token"][0]; - ASSERT_THAT(payload, SizeIs(1)); - EXPECT_THAT(payload[0].Id, Not(IsEmpty())); - EXPECT_THAT(payload[0].Type, Eq("client_telemetry")); - EXPECT_THAT(payload[0].Extension, Contains(Pair("stats_rollup_kind", "stop"))); - EXPECT_THAT(payload[0].Extension, Contains(Pair("records_dropped_retry_exceeded", "2"))); - */ - } - FlushAndTeardown(); - } -} -#endif #endif // HAVE_MAT_DEFAULT_HTTP_CLIENT diff --git a/tests/functests/MultipleLogManagersTests.cpp b/tests/functests/MultipleLogManagersTests.cpp index 7a9027b9b..420377442 100644 --- a/tests/functests/MultipleLogManagersTests.cpp +++ b/tests/functests/MultipleLogManagersTests.cpp @@ -97,12 +97,6 @@ class MultipleLogManagersTests : public ::testing::Test server.start(); -#if 0 - sqlite3_initialize(); - config1["skipSqliteInitAndShutdown"] = "true"; - config2["skipSqliteInitAndShutdown"] = "true"; -#endif - // Config for instance #1 config1["cacheFilePath"] = "lm1.db"; ::remove(config1["cacheFilePath"]); @@ -308,4 +302,3 @@ TEST_F(MultipleLogManagersTests, PrivacyGuardSharedWithTwoInstancesCoexist) #endif // !TARGET_OS_IPHONE (suite excluded on iOS; see note above) #endif // HAVE_MAT_DEFAULT_HTTP_CLIENT - diff --git a/tests/unittests/HttpClientCAPITests.cpp b/tests/unittests/HttpClientCAPITests.cpp index 0f0e56a7e..0a5403044 100644 --- a/tests/unittests/HttpClientCAPITests.cpp +++ b/tests/unittests/HttpClientCAPITests.cpp @@ -20,8 +20,9 @@ namespace virtual void OnHttpResponse(IHttpResponse* response) override { + std::unique_ptr ownedResponse(response); if (m_validateFn) - m_validateFn(response); + m_validateFn(ownedResponse.get()); } private: @@ -35,8 +36,10 @@ namespace void SetSendValidation(std::function fn) { m_validateSendFn = fn; } void SetCancelValidation(std::function fn) { m_validateCancelFn = fn; } - void OnSend(http_request_t* request) + void OnSend(http_request_t* request, http_complete_fn_t completeFn) { + m_requestId = request->id; + m_completeFn = completeFn; if (m_validateSendFn) m_validateSendFn(request); } @@ -45,11 +48,22 @@ namespace { if (m_validateCancelFn) m_validateCancelFn(requestId); + Complete(HTTP_RESULT_CANCELLED, nullptr); + } + + void Complete(http_result_t result, http_response_t* response) + { + auto completeFn = m_completeFn; + m_completeFn = nullptr; + if (completeFn != nullptr) + completeFn(m_requestId.c_str(), result, response); } private: std::function m_validateSendFn; std::function m_validateCancelFn; + std::string m_requestId; + http_complete_fn_t m_completeFn = nullptr; bool m_shouldSend = false; }; @@ -77,7 +91,7 @@ namespace void EVTSDK_LIBABI_CDECL OnHttpSend(http_request_t* request, http_complete_fn_t callback) { - s_testHelper->OnSend(request); + s_testHelper->OnSend(request, callback); if (s_testHelper->ShouldSend()) { @@ -93,7 +107,7 @@ void EVTSDK_LIBABI_CDECL OnHttpSend(http_request_t* request, http_complete_fn_t response.headers = &header; response.headersCount = 1; - callback(request->id, HTTP_RESULT_OK, &response); + s_testHelper->Complete(HTTP_RESULT_OK, &response); } } @@ -108,7 +122,7 @@ TEST(HttpClientCAPITests, SendAsync) // Build request std::vector body = {'a', 'b', 'c'}; - auto request = httpClient.CreateRequest(); + std::unique_ptr request(httpClient.CreateRequest()); request->SetUrl("https://www.microsoft.com"); request->SetBody(body); request->SetMethod("POST"); @@ -150,7 +164,7 @@ TEST(HttpClientCAPITests, SendAsync) EXPECT_EQ(response->GetHeaders().get("response_key1"), string("response_value1")); }); - httpClient.SendRequestAsync(request, &responseCallback); + httpClient.SendRequestAsync(request.get(), &responseCallback); EXPECT_EQ(wasSent, true); EXPECT_EQ(wasReceived, true); @@ -161,9 +175,10 @@ TEST(HttpClientCAPITests, Cancel) HttpClient_CAPI httpClient(&OnHttpSend, &OnHttpCancel); // Build request - auto request = httpClient.CreateRequest(); + std::unique_ptr request(httpClient.CreateRequest()); request->SetUrl("https://www.microsoft.com"); request->SetMethod("GET"); + const auto requestId = request->GetId(); AutoTestHelper testHelper; testHelper->SetShouldSend(false); @@ -174,14 +189,17 @@ TEST(HttpClientCAPITests, Cancel) }); TestHttpResponseCallback responseCallback; - responseCallback.SetResponseValidation([](IHttpResponse* /*response*/) { - FAIL() << "No response should have been received"; + bool wasReceived = false; + responseCallback.SetResponseValidation([&wasReceived](IHttpResponse* response) { + wasReceived = true; + EXPECT_EQ(response->GetResult(), HttpResult_Aborted); }); - httpClient.SendRequestAsync(request, &responseCallback); - httpClient.CancelRequestAsync(request->GetId()); + httpClient.SendRequestAsync(request.get(), &responseCallback); + httpClient.CancelRequestAsync(requestId); - EXPECT_EQ(cancelledId, request->GetId()); + EXPECT_EQ(cancelledId, requestId); + EXPECT_TRUE(wasReceived); } TEST(HttpClientCAPITests, CancelAllThenSend) @@ -195,7 +213,7 @@ TEST(HttpClientCAPITests, CancelAllThenSend) httpClient.CancelAllRequests(); // Build request - auto request = httpClient.CreateRequest(); + std::unique_ptr request(httpClient.CreateRequest()); request->SetUrl("https://www.microsoft.com"); request->SetMethod("GET"); request->GetHeaders().add("key1", "value1"); @@ -227,7 +245,7 @@ TEST(HttpClientCAPITests, CancelAllThenSend) EXPECT_EQ(response->GetHeaders().get("response_key1"), string("response_value1")); }); - httpClient.SendRequestAsync(request, &responseCallback); + httpClient.SendRequestAsync(request.get(), &responseCallback); EXPECT_EQ(wasSent, true); EXPECT_EQ(wasReceived, true); diff --git a/tests/unittests/HttpResponseDecoderTests.cpp b/tests/unittests/HttpResponseDecoderTests.cpp index 314cdb513..7d11ae4b8 100644 --- a/tests/unittests/HttpResponseDecoderTests.cpp +++ b/tests/unittests/HttpResponseDecoderTests.cpp @@ -88,20 +88,29 @@ TEST_F(HttpResponseDecoderTests, UnderstandsTemporaryServerFailures) TEST_F(HttpResponseDecoderTests, UnderstandsTemporaryNetworkFailures) { auto ctx = createContextWith(HttpResult_LocalFailure, -1, ""); - EXPECT_CALL(*this, resultTemporaryNetworkFailure(ctx)) - .WillOnce(Return()); + EXPECT_CALL(*this, resultTemporaryNetworkFailure(ctx)).WillOnce(Invoke([](EventsUploadContextPtr const& routedCtx) { + ASSERT_THAT(routedCtx->httpResponse, NotNull()); + EXPECT_THAT(routedCtx->httpResponse->GetResult(), HttpResult_LocalFailure); + EXPECT_THAT(routedCtx->httpResponse->GetStatusCode(), static_cast(-1)); + })); decoder.decode(ctx); ctx = createContextWith(HttpResult_NetworkFailure, -1, ""); - EXPECT_CALL(*this, resultTemporaryNetworkFailure(ctx)) - .WillOnce(Return()); + EXPECT_CALL(*this, resultTemporaryNetworkFailure(ctx)).WillOnce(Invoke([](EventsUploadContextPtr const& routedCtx) { + ASSERT_THAT(routedCtx->httpResponse, NotNull()); + EXPECT_THAT(routedCtx->httpResponse->GetResult(), HttpResult_NetworkFailure); + EXPECT_THAT(routedCtx->httpResponse->GetStatusCode(), static_cast(-1)); + })); decoder.decode(ctx); } TEST_F(HttpResponseDecoderTests, SkipsAbortedRequests) { auto ctx = createContextWith(HttpResult_Aborted, -1, ""); - EXPECT_CALL(*this, resultRequestAborted(ctx)) - .WillOnce(Return()); + EXPECT_CALL(*this, resultRequestAborted(ctx)).WillOnce(Invoke([](EventsUploadContextPtr const& routedCtx) { + ASSERT_THAT(routedCtx->httpResponse, NotNull()); + EXPECT_THAT(routedCtx->httpResponse->GetResult(), HttpResult_Aborted); + EXPECT_THAT(routedCtx->httpResponse->GetStatusCode(), static_cast(-1)); + })); decoder.decode(ctx); } diff --git a/tests/unittests/LogSessionDataDBTests.cpp b/tests/unittests/LogSessionDataDBTests.cpp index 4788c5302..dbda5fd27 100644 --- a/tests/unittests/LogSessionDataDBTests.cpp +++ b/tests/unittests/LogSessionDataDBTests.cpp @@ -50,7 +50,8 @@ class LogSessionDataDBTests : public ::testing::Test StrictMock configMock; LogSessionDataProvider *logSessionDataProvider; std::ostringstream name; - unsigned long long now = PAL::getUtcSystemTimeMs(); + uint64_t sessionCreationStart = 0; + uint64_t sessionCreationEnd = 0; virtual void SetUp() override { @@ -67,7 +68,9 @@ class LogSessionDataDBTests : public ::testing::Test logSessionDataProvider = new LogSessionDataProvider(offlineStorage.get()); logSessionDataProvider->CreateLogSessionData(); offlineStorage->Initialize(observerMock); + sessionCreationStart = PAL::getUtcSystemTimeMs(); logSessionDataProvider->CreateLogSessionData(); + sessionCreationEnd = PAL::getUtcSystemTimeMs(); } virtual void TearDown() override @@ -83,7 +86,7 @@ TEST_F(LogSessionDataDBTests, subTest) { #ifndef USE_ROOM logSessionData = logSessionDataProvider->GetLogSessionData(); auto sessionFirstTime= logSessionData->getSessionFirstTime(); - EXPECT_IN_RANGE(sessionFirstTime, now , now + 1000); + EXPECT_IN_RANGE(sessionFirstTime, sessionCreationStart, sessionCreationEnd); auto sdkUid = logSessionData->getSessionSDKUid(); EXPECT_TRUE(sdkUid.size()); @@ -97,4 +100,3 @@ TEST_F(LogSessionDataDBTests, subTest) { ASSERT_EQ(1, 1); #endif } - diff --git a/tests/unittests/Main.cpp b/tests/unittests/Main.cpp index 303174749..4bb7b3c7a 100644 --- a/tests/unittests/Main.cpp +++ b/tests/unittests/Main.cpp @@ -52,4 +52,3 @@ int MAIN_CDECL main(int argc, char** argv) return result; } - diff --git a/tests/unittests/MemoryStorageTests.cpp b/tests/unittests/MemoryStorageTests.cpp index a736d125f..d33d152ce 100644 --- a/tests/unittests/MemoryStorageTests.cpp +++ b/tests/unittests/MemoryStorageTests.cpp @@ -213,6 +213,24 @@ TEST_F(MemoryStorageTests, DeleteAllRecords) EXPECT_THAT(storage.GetReservedCount(), 0); } +TEST_F(MemoryStorageTests, DeleteRecordsWithEmptyFilterDoesNotDeleteAll) +{ + MemoryStorage storage(testLogManager, *testConfig); + + // Add some events to storage + auto total_db_size = addEvents(storage); + EXPECT_THAT(storage.GetSize(), total_db_size); + auto count_before = storage.GetRecordCount(); + EXPECT_GT(count_before, static_cast(0)); + + // An empty where-filter matches every record; it must NOT wipe the queue. + // Intentional full clears go through DeleteAllRecords(). + storage.DeleteRecords(std::map{}); + + EXPECT_THAT(storage.GetRecordCount(), count_before); + EXPECT_THAT(storage.GetSize(), total_db_size); +} + TEST_F(MemoryStorageTests, ReleaseRecords) { @@ -262,18 +280,11 @@ TEST_F(MemoryStorageTests, GetAndReserveSome) storage.Initialize(testObserver); addEvents(storage); auto totalCount = storage.GetRecordCount(); - constexpr size_t howMany = 32; + static constexpr size_t howMany = 32; std::vector someRecords; -#if defined(__clang__) -#pragma clang diagnostic push // This appears to be a detection bug with constexpr variables in Clang9 -#pragma clang diagnostic ignored "-Wunused-lambda-capture" // error : lambda capture 'howMany' is not required to be captured for this use[-Werror, -Wunused - lambda - capture] -#elif defined(_MSC_VER) -#pragma warning(push) -#pragma warning(disable : 5258) // warning C5258: explicit capture of 'howMany' is not required for this use -#endif storage.GetAndReserveRecords( - [&someRecords, howMany] (StorageRecord && record)->bool + [&someRecords] (StorageRecord && record)->bool { if (someRecords.size() >= howMany) { return false; @@ -283,11 +294,6 @@ TEST_F(MemoryStorageTests, GetAndReserveSome) }, EventLatency_Normal ); -#if defined(__clang__) -#pragma clang diagnostic pop -#elif defined(_MSC_VER) -#pragma warning(pop) -#endif EXPECT_EQ(howMany, someRecords.size()); EXPECT_EQ(howMany, storage.LastReadRecordCount()); @@ -377,4 +383,3 @@ TEST_F(MemoryStorageTests, MultiThreadPerfTest) EXPECT_THAT(storage.GetSize(), 0); } - diff --git a/tests/unittests/OfflineStorageTests.cpp b/tests/unittests/OfflineStorageTests.cpp index bbb8da8e0..6f552fad1 100644 --- a/tests/unittests/OfflineStorageTests.cpp +++ b/tests/unittests/OfflineStorageTests.cpp @@ -2,7 +2,18 @@ #include "common/Common.hpp" #include "common/MockIOfflineStorage.hpp" +#include "common/MockIOfflineStorageObserver.hpp" +#include "common/MockIRuntimeConfig.hpp" +#include "offline/OfflineStorageHandler.hpp" +#include "offline/IOfflineStorageProvider.hpp" #include "offline/StorageObserver.hpp" +#include "NullObjects.hpp" + +#include +#include +#include +#include +#include using namespace testing; using namespace MAT; @@ -65,18 +76,18 @@ TEST_F(OfflineStorageTests, StopShutsDown) TEST_F(OfflineStorageTests, StoreRecordIsForwarded) { - auto ctx = new IncomingEventContext(); + IncomingEventContext ctx; - EXPECT_CALL(offlineStorageMock, StoreRecord(Ref(ctx->record))) + EXPECT_CALL(offlineStorageMock, StoreRecord(Ref(ctx.record))) .WillOnce(Return(true)); - EXPECT_THAT(offlineStorage.storeRecord(ctx), true); - EXPECT_THAT(ctx->record.timestamp, Near(PAL::getUtcSystemTimeMs(), 1000)); + EXPECT_THAT(offlineStorage.storeRecord(&ctx), true); + EXPECT_THAT(ctx.record.timestamp, Near(PAL::getUtcSystemTimeMs(), 1000)); - EXPECT_CALL(offlineStorageMock, StoreRecord(Ref(ctx->record))) + EXPECT_CALL(offlineStorageMock, StoreRecord(Ref(ctx.record))) .WillOnce(Return(false)); - EXPECT_CALL(*this, resultStoreRecordFailed(ctx)) + EXPECT_CALL(*this, resultStoreRecordFailed(&ctx)) .WillOnce(Return()); - EXPECT_THAT(offlineStorage.storeRecord(ctx), false); + EXPECT_THAT(offlineStorage.storeRecord(&ctx), false); } TEST_F(OfflineStorageTests, RetrieveEventsPassesRecordsThrough) @@ -162,3 +173,479 @@ TEST_F(OfflineStorageTests, ReleaseRecordsIsForwarded) .WillOnce(Return()); EXPECT_THAT(offlineStorage.releaseRecordsIncRetryCount(ctx), true); } + +namespace +{ + class ConfigurableLogManager : public NullLogManager + { + public: + ILogConfiguration config; + ILogConfiguration& GetLogConfiguration() override { return config; } + }; + + // Remove a SQLite db file along with its WAL-mode companion files + // (-wal/-shm/-journal), which would otherwise accumulate in the temp dir. + void RemoveDbFiles(const std::string& path) + { + std::remove(path.c_str()); + std::remove((path + "-wal").c_str()); + std::remove((path + "-shm").c_str()); + std::remove((path + "-journal").c_str()); + } + + // No-op dispatcher that owns queued tasks and frees them, so flushes only + // run when invoked directly and scheduled tasks (if any) are not leaked. + class NoopTaskDispatcher : public ITaskDispatcher + { + public: + void Join() override { clear(); } + void Queue(Task* task) override { m_tasks.push_back(task); } + bool Cancel(Task* task, uint64_t waitTime = 0) override + { + UNREFERENCED_PARAMETER(waitTime); + auto it = std::find(m_tasks.begin(), m_tasks.end(), task); + if (it != m_tasks.end()) + { + delete *it; + m_tasks.erase(it); + return true; + } + return false; + } + ~NoopTaskDispatcher() override { clear(); } + + private: + void clear() + { + for (auto* t : m_tasks) + delete t; + m_tasks.clear(); + } + std::vector m_tasks; + }; +} + +namespace MAT_NS_BEGIN { + + class MockOfflineStorageProvider : public IOfflineStorageProvider + { + public: + MockOfflineStorageProvider( + std::shared_ptr memory, + std::shared_ptr disk) + : memory(std::move(memory)), disk(std::move(disk)) + { + } + + std::shared_ptr CreateDiskStorage( + ILogManager&, IRuntimeConfig&) override + { + return disk; + } + + std::shared_ptr CreateMemoryStorage( + ILogManager&, IRuntimeConfig&) override + { + return memory; + } + + private: + std::shared_ptr memory; + std::shared_ptr disk; + }; + +} MAT_NS_END + +TEST(OfflineStorageHandlerFlushTests, FailedMemoryRequeueIsReportedAndDropped) +{ + NullLogManager logManager; + NiceMock config; + NoopTaskDispatcher dispatcher; + StrictMock observer; + + auto memory = std::make_shared>(); + auto disk = std::make_shared>(); + auto provider = std::make_shared(memory, disk); + OfflineStorageHandler handler(logManager, config, dispatcher, provider); + config[CFG_INT_RAM_QUEUE_SIZE] = 4096 * 20; + config[CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH] = true; + EXPECT_CALL(*memory, Initialize(Ref(handler))).WillOnce(Return()); + EXPECT_CALL(*disk, Initialize(Ref(handler))).WillOnce(Return()); + handler.Initialize(observer); + + std::vector records; + records.push_back(StorageRecord("retry-ok", "tenant-one-token", + EventLatency_Normal, EventPersistence_Normal, /*timestamp*/ 1, + std::vector{ 'x' })); + records.push_back(StorageRecord("retry-drop", "tenant-two-token", + EventLatency_Normal, EventPersistence_Normal, /*timestamp*/ 1, + std::vector{ 'y' })); + + EXPECT_CALL(*memory, GetSize()) + .WillOnce(Return(records.size())) + .WillOnce(Return(records.size())); + EXPECT_CALL(*memory, GetRecordCount(EventLatency_Unspecified)) + .WillOnce(Return(records.size())); + EXPECT_CALL(*memory, GetRecords(false, EventLatency_Unspecified, 2000)) + .WillOnce(Return(records)); + EXPECT_CALL(*disk, StoreRecords(_)).WillOnce(Return(0)); + EXPECT_CALL(*memory, StoreRecord(_)) + .WillOnce(Return(true)) + .WillOnce(Return(false)); + EXPECT_CALL(observer, OnStorageRecordsSaved(0)); + EXPECT_CALL(observer, OnStorageRecordsDropped(_)) + .WillOnce(Invoke([](std::map const& dropped) { + auto found = dropped.find("tenant-two-token"); + ASSERT_NE(found, dropped.end()); + EXPECT_EQ(found->second, static_cast(1)); + })); + + handler.Flush(); +} + +TEST(OfflineStorageHandlerFlushTests, BatchingOptOutUsesPerRecordDiskStores) +{ + NullLogManager logManager; + NiceMock config; + NoopTaskDispatcher dispatcher; + StrictMock observer; + + config[CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH] = false; + config[CFG_INT_RAM_QUEUE_SIZE] = 4096 * 20; + + auto memory = std::make_shared>(); + auto disk = std::make_shared>(); + auto provider = std::make_shared(memory, disk); + OfflineStorageHandler handler(logManager, config, dispatcher, provider); + EXPECT_CALL(*memory, Initialize(Ref(handler))).WillOnce(Return()); + EXPECT_CALL(*disk, Initialize(Ref(handler))).WillOnce(Return()); + handler.Initialize(observer); + + std::vector records; + records.push_back(StorageRecord("per-record-1", "tenant-one-token", + EventLatency_Normal, EventPersistence_Normal, /*timestamp*/ 1, + std::vector{ 'x' })); + records.push_back(StorageRecord("per-record-2", "tenant-two-token", + EventLatency_Normal, EventPersistence_Normal, /*timestamp*/ 1, + std::vector{ 'y' })); + + EXPECT_CALL(*memory, GetSize()) + .WillOnce(Return(static_cast(records.size()))) + .WillOnce(Return(static_cast(0))); + EXPECT_CALL(*memory, GetRecords(false, EventLatency_Unspecified, 0)) + .WillOnce(Return(records)); + EXPECT_CALL(*disk, StoreRecords(_)).Times(0); + EXPECT_CALL(*disk, StoreRecord(_)) + .Times(static_cast(records.size())) + .WillRepeatedly(Return(true)); + EXPECT_CALL(observer, OnStorageRecordsSaved(records.size())); + + handler.Flush(); +} + +TEST(OfflineStorageHandlerFlushTests, BatchedFlushLimitsEachDiskWrite) +{ + NullLogManager logManager; + NiceMock config; + NoopTaskDispatcher dispatcher; + StrictMock observer; + + config[CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH] = true; + config[CFG_INT_RAM_QUEUE_SIZE] = 4096 * 20; + + auto memory = std::make_shared>(); + auto disk = std::make_shared>(); + auto provider = std::make_shared(memory, disk); + OfflineStorageHandler handler(logManager, config, dispatcher, provider); + EXPECT_CALL(*memory, Initialize(Ref(handler))).WillOnce(Return()); + EXPECT_CALL(*disk, Initialize(Ref(handler))).WillOnce(Return()); + handler.Initialize(observer); + + std::vector firstBatch; + std::vector secondBatch; + std::vector finalBatch; + for (size_t i = 0; i < 4005; ++i) + { + StorageRecord record("batch-" + std::to_string(i), "tenant-token", + EventLatency_Normal, EventPersistence_Normal, /*timestamp*/ 1, + std::vector{ 'x' }); + if (i < 2000) + { + firstBatch.push_back(record); + } + else if (i < 4000) + { + secondBatch.push_back(record); + } + else + { + finalBatch.push_back(record); + } + } + + EXPECT_CALL(*memory, GetSize()) + .WillOnce(Return(static_cast(4005))) + .WillOnce(Return(static_cast(0))); + EXPECT_CALL(*memory, GetRecordCount(EventLatency_Unspecified)) + .WillOnce(Return(static_cast(4005))); + EXPECT_CALL(*memory, GetRecords(false, EventLatency_Unspecified, 2000)) + .WillOnce(Return(firstBatch)) + .WillOnce(Return(secondBatch)) + .WillOnce(Return(finalBatch)); + EXPECT_CALL(*disk, StoreRecords(_)) + .WillOnce(Invoke([](std::vector& records) { + EXPECT_EQ(records.size(), static_cast(2000)); + return records.size(); + })) + .WillOnce(Invoke([](std::vector& records) { + EXPECT_EQ(records.size(), static_cast(2000)); + return records.size(); + })) + .WillOnce(Invoke([](std::vector& records) { + EXPECT_EQ(records.size(), static_cast(5)); + return records.size(); + })); + EXPECT_CALL(observer, OnStorageRecordsSaved(4005)); + + handler.Flush(); +} + +TEST(OfflineStorageHandlerFlushTests, FailedBatchRequeuesOnlyThatBatch) +{ + NullLogManager logManager; + NiceMock config; + NoopTaskDispatcher dispatcher; + StrictMock observer; + + config[CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH] = true; + config[CFG_INT_RAM_QUEUE_SIZE] = 4096 * 20; + + auto memory = std::make_shared>(); + auto disk = std::make_shared>(); + auto provider = std::make_shared(memory, disk); + OfflineStorageHandler handler(logManager, config, dispatcher, provider); + EXPECT_CALL(*memory, Initialize(Ref(handler))).WillOnce(Return()); + EXPECT_CALL(*disk, Initialize(Ref(handler))).WillOnce(Return()); + handler.Initialize(observer); + + std::vector firstBatch; + std::vector failedBatch; + for (size_t i = 0; i < 4000; ++i) + { + StorageRecord record("failed-batch-" + std::to_string(i), "tenant-token", + EventLatency_Normal, EventPersistence_Normal, /*timestamp*/ 1, + std::vector{ 'x' }); + (i < 2000 ? firstBatch : failedBatch).push_back(record); + } + + EXPECT_CALL(*memory, GetSize()) + .WillOnce(Return(static_cast(4000))) + .WillOnce(Return(static_cast(4000))); + EXPECT_CALL(*memory, GetRecordCount(EventLatency_Unspecified)) + .WillOnce(Return(static_cast(4000))); + EXPECT_CALL(*memory, GetRecords(false, EventLatency_Unspecified, 2000)) + .WillOnce(Return(firstBatch)) + .WillOnce(Return(failedBatch)); + EXPECT_CALL(*memory, StoreRecord(_)) + .Times(2000) + .WillRepeatedly(Return(true)); + EXPECT_CALL(*disk, StoreRecords(_)) + .WillOnce(Return(static_cast(2000))) + .WillOnce(Return(static_cast(0))); + EXPECT_CALL(observer, OnStorageRecordsSaved(2000)); + + handler.Flush(); +} + +TEST(OfflineStorageHandlerFlushTests, CustomStorageUsesPerRecordWrites) +{ + ConfigurableLogManager logManager; + NiceMock config; + NoopTaskDispatcher dispatcher; + StrictMock observer; + config[CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH] = true; + config[CFG_INT_RAM_QUEUE_SIZE] = 4096 * 20; + + auto disk = std::make_shared>(); + logManager.config.AddModule(CFG_MODULE_OFFLINE_STORAGE, disk); + + auto memory = std::make_shared>(); + auto provider = std::make_shared(memory, disk); + OfflineStorageHandler handler(logManager, config, dispatcher, provider); + EXPECT_CALL(*memory, Initialize(Ref(handler))).WillOnce(Return()); + EXPECT_CALL(*disk, Initialize(Ref(handler))).WillOnce(Return()); + handler.Initialize(observer); + + std::vector records; + records.push_back(StorageRecord("custom-1", "tenant-token", + EventLatency_Normal, EventPersistence_Normal, 1, std::vector{ 'x' })); + records.push_back(StorageRecord("custom-2", "tenant-token", + EventLatency_Normal, EventPersistence_Normal, 1, std::vector{ 'y' })); + + EXPECT_CALL(*memory, GetSize()) + .WillOnce(Return(records.size())) + .WillOnce(Return(static_cast(0))); + EXPECT_CALL(*memory, GetRecords(false, EventLatency_Unspecified, 0)) + .WillOnce(Return(records)); + EXPECT_CALL(*disk, StoreRecords(_)).Times(0); + EXPECT_CALL(*disk, StoreRecord(_)).Times(2).WillRepeatedly(Return(true)); + EXPECT_CALL(observer, OnStorageRecordsSaved(records.size())); + + handler.Flush(); +} + +// Regression test: when valid records drained from the in-memory queue fail to +// be persisted by the disk backend during Flush() (a transient failure -- here +// an unopenable database), they must be returned to the queue rather than lost. +TEST(OfflineStorageHandlerFlushTests, FailedDiskStoreDuringFlushReturnsRecordsToMemory) +{ + NullLogManager logManager; + NiceMock config; + NoopTaskDispatcher dispatcher; + NiceMock observer; + + ON_CALL(config, GetOfflineStorageMaximumSizeBytes()).WillByDefault(Return(32 * 4096)); + ON_CALL(config, GetMaximumRetryCount()).WillByDefault(Return(5)); + + // A path inside a non-existent directory cannot be opened by SQLite (it does + // not create parent directories), so every disk StoreRecords() returns 0 -- + // a transient failure with otherwise-valid records. + std::ostringstream dbPath; + dbPath << GetTempDirectory() << "no_such_dir_" << PAL::getUtcSystemTimeMs() + << "/FlushReserveTest.db"; + config[CFG_STR_CACHE_FILE_PATH] = dbPath.str(); + config[CFG_INT_RAM_QUEUE_SIZE] = 1024 * 1024; // enable the in-memory queue + + OfflineStorageHandler handler(logManager, config, dispatcher); + handler.Initialize(observer); + + const size_t kCount = 5; + for (size_t i = 0; i < kCount; i++) + { + StorageRecord r("flush-id-" + std::to_string(i), "tenant-token", + EventLatency_Normal, EventPersistence_Normal, /*timestamp*/ 1, + std::vector{ 'x' }); + handler.StoreRecord(r); + } + EXPECT_EQ(handler.GetRecordCount(), kCount); + + handler.Flush(); + + // The disk could not persist the batch; with the fix the valid records are + // returned to the in-memory queue rather than silently dropped. + EXPECT_EQ(handler.GetRecordCount(), kCount); + + handler.Shutdown(); +} + +TEST(OfflineStorageHandlerFlushTests, EventLatencyOffIsDroppedWithoutReportingStoreFailure) +{ + NullLogManager logManager; + NiceMock config; + NoopTaskDispatcher dispatcher; + NiceMock observer; + + ON_CALL(config, GetOfflineStorageMaximumSizeBytes()).WillByDefault(Return(32 * 4096)); + + std::ostringstream dbPath; + dbPath << GetTempDirectory() << "LatencyOff-" << PAL::getUtcSystemTimeMs() << ".db"; + RemoveDbFiles(dbPath.str()); + config[CFG_STR_CACHE_FILE_PATH] = dbPath.str(); + config[CFG_INT_RAM_QUEUE_SIZE] = 1024 * 1024; // enable the in-memory queue + + OfflineStorageHandler handler(logManager, config, dispatcher); + handler.Initialize(observer); + + StorageRecord record("latency-off", "tenant-token", + EventLatency_Off, EventPersistence_Normal, /*timestamp*/ 1, + std::vector{ 'x' }); + + EXPECT_TRUE(handler.StoreRecord(record)); + EXPECT_EQ(handler.GetRecordCount(), static_cast(0)); + + handler.Shutdown(); + RemoveDbFiles(dbPath.str()); +} + +// Regression test: a permanently-invalid record (rejected by the disk backend's +// validation) must be dropped on Flush(), not returned to the queue -- otherwise +// one poison record would be re-drained and re-rejected on every flush, wedging +// the queue and blocking every valid record behind it. +TEST(OfflineStorageHandlerFlushTests, FlushDropsInvalidRecordsInsteadOfWedging) +{ + NullLogManager logManager; + NiceMock config; + NoopTaskDispatcher dispatcher; + NiceMock observer; + + ON_CALL(config, GetOfflineStorageMaximumSizeBytes()).WillByDefault(Return(32 * 4096)); + ON_CALL(config, GetMaximumRetryCount()).WillByDefault(Return(5)); + + std::ostringstream dbPath; + dbPath << GetTempDirectory() << "FlushDropInvalid-" << PAL::getUtcSystemTimeMs() << ".db"; + RemoveDbFiles(dbPath.str()); + config[CFG_STR_CACHE_FILE_PATH] = dbPath.str(); + config[CFG_INT_RAM_QUEUE_SIZE] = 1024 * 1024; // enable the in-memory queue + + OfflineStorageHandler handler(logManager, config, dispatcher); + handler.Initialize(observer); + + // A timestamp <= 0 is accepted by the in-memory queue but permanently rejected + // by the SQLite disk store's validation, so it can never be persisted. + const size_t kCount = 5; + for (size_t i = 0; i < kCount; i++) + { + StorageRecord r("bad-id-" + std::to_string(i), "tenant-token", + EventLatency_Normal, EventPersistence_Normal, /*timestamp*/ 0, + std::vector{ 'x' }); + handler.StoreRecord(r); + } + EXPECT_EQ(handler.GetRecordCount(), kCount); + + handler.Flush(); + + // The invalid records are dropped, not returned to the queue, so the queue + // drains and is not wedged. + EXPECT_EQ(handler.GetRecordCount(), static_cast(0)); + + handler.Shutdown(); + RemoveDbFiles(dbPath.str()); +} + +TEST(OfflineStorageHandlerFlushTests, FlushOptOutDropsInvalidRecordsInsteadOfWedging) +{ + NullLogManager logManager; + NiceMock config; + NoopTaskDispatcher dispatcher; + NiceMock observer; + + ON_CALL(config, GetOfflineStorageMaximumSizeBytes()).WillByDefault(Return(32 * 4096)); + ON_CALL(config, GetMaximumRetryCount()).WillByDefault(Return(5)); + + std::ostringstream dbPath; + dbPath << GetTempDirectory() << "FlushOptOutDropInvalid-" << PAL::getUtcSystemTimeMs() << ".db"; + RemoveDbFiles(dbPath.str()); + config[CFG_STR_CACHE_FILE_PATH] = dbPath.str(); + config[CFG_INT_RAM_QUEUE_SIZE] = 1024 * 1024; + config[CFG_BOOL_ENABLE_BATCHED_STORAGE_FLUSH] = false; + + OfflineStorageHandler handler(logManager, config, dispatcher); + handler.Initialize(observer); + + const size_t kCount = 3; + for (size_t i = 0; i < kCount; i++) + { + StorageRecord r("bad-opt-out-id-" + std::to_string(i), "tenant-token", + EventLatency_Normal, EventPersistence_Normal, /*timestamp*/ 0, + std::vector{ 'x' }); + handler.StoreRecord(r); + } + EXPECT_EQ(handler.GetRecordCount(), kCount); + + handler.Flush(); + + EXPECT_EQ(handler.GetRecordCount(), static_cast(0)); + + handler.Shutdown(); + RemoveDbFiles(dbPath.str()); +} diff --git a/tests/unittests/OfflineStorageTests_SQLite.cpp b/tests/unittests/OfflineStorageTests_SQLite.cpp index 015e197d7..c7e17fbdc 100644 --- a/tests/unittests/OfflineStorageTests_SQLite.cpp +++ b/tests/unittests/OfflineStorageTests_SQLite.cpp @@ -10,8 +10,11 @@ #include "common/MockIRuntimeConfig.hpp" #include "utils/Utils.hpp" #include "offline/OfflineStorage_SQLite.hpp" +#include +#include #include #include +#include #if !defined(_WIN32) #include #endif @@ -107,7 +110,6 @@ struct OfflineStorageTests_SQLite : public Test } }; - class TestRecordConsumer { public: operator std::function() @@ -132,6 +134,60 @@ TEST_F(OfflineStorageTests_SQLite, InitializeAndShutdownCreateFileThatCanBeDelet initializeStorage(); } +TEST_F(OfflineStorageTests_SQLite, ConcurrentAccessAndShutdownAreSerialized) +{ + initializeStorage(); + EXPECT_CALL(observerMock, OnStorageOpenFailed("Database is not open")) + .Times(AnyNumber()); + EXPECT_CALL(observerMock, OnStorageFailed("Database is not open")) + .Times(AnyNumber()); + + std::atomic start{ false }; + std::atomic writerProgress{ 0 }; + std::atomic readerProgress{ 0 }; + + std::thread writer([&]() { + while (!start.load(std::memory_order_acquire)) + { + std::this_thread::yield(); + } + for (unsigned i = 0; i < 200; ++i) + { + offlineStorage->StoreRecord({ + "concurrent-" + std::to_string(i), + "token", + EventLatency_Normal, + EventPersistence_Normal, + static_cast(i + 1), + {} }); + writerProgress.store(i + 1, std::memory_order_release); + } + }); + + std::thread reader([&]() { + while (!start.load(std::memory_order_acquire)) + { + std::this_thread::yield(); + } + for (unsigned i = 0; i < 200; ++i) + { + (void)offlineStorage->GetRecords(false, EventLatency_Off, 1); + readerProgress.store(i + 1, std::memory_order_release); + } + }); + + start.store(true, std::memory_order_release); + while (writerProgress.load(std::memory_order_acquire) == 0 || + readerProgress.load(std::memory_order_acquire) == 0) + { + std::this_thread::yield(); + } + + offlineStorage->Shutdown(); + writer.join(); + reader.join(); +} + TEST_F(OfflineStorageTests_SQLite, StorageRecordConstructorSetsAllFields) { initializeStorage(); @@ -162,6 +218,84 @@ TEST_F(OfflineStorageTests_SQLite, GetAndReservedReturnsStoredRecord) EXPECT_THAT(consumer.records[0].reservedUntil, 0); } +TEST_F(OfflineStorageTests_SQLite, MalformedPersistedLatencyFallsBackToNormal) +{ + initializeStorage(); + offlineStorage->Execute( + "INSERT INTO events " + "(record_id,tenant_token,latency,persistence,timestamp,payload) " + "VALUES ('malformed-latency','token',987,1,1,X'010203')"); + + auto records = offlineStorage->GetRecords(false, EventLatency_Off); + ASSERT_THAT(records.size(), 1); + EXPECT_THAT(records[0].id, "malformed-latency"); + EXPECT_THAT(records[0].latency, EventLatency_Normal); + EXPECT_THAT(records[0].blob, StorageBlob({ 1, 2, 3 })); + + TestRecordConsumer consumer; + EXPECT_THAT( + offlineStorage->GetAndReserveRecords( + consumer, 100000, EventLatency_Off), + true); + ASSERT_THAT(consumer.records.size(), 1); + EXPECT_THAT(consumer.records[0].id, "malformed-latency"); + EXPECT_THAT(consumer.records[0].latency, EventLatency_Normal); + EXPECT_THAT(consumer.records[0].blob, StorageBlob({ 1, 2, 3 })); +} + +TEST_F(OfflineStorageTests_SQLite, StoreRecordsBatchStoresAllRecords) +{ + initializeStorage(); + std::vector batch; + const size_t kCount = 8; + for (size_t i = 0; i < kCount; i++) + { + batch.push_back({ "g" + std::to_string(i), "token", EventLatency_Normal, + EventPersistence_Normal, static_cast(i + 1), { static_cast(i) } }); + } + + // Every record in the batch is stored and individually retrievable. (The + // single-transaction batching is a performance optimization verified by + // benchmarking; this test covers the batch's storage correctness.) + EXPECT_THAT(offlineStorage->StoreRecords(batch), kCount); + + TestRecordConsumer consumer; + EXPECT_THAT(offlineStorage->GetAndReserveRecords(consumer, 100000), true); + ASSERT_THAT(consumer.records.size(), kCount); + for (size_t i = 0; i < kCount; i++) + { + std::string expectedId = "g" + std::to_string(i); + bool found = false; + for (auto const& r : consumer.records) + { + if (r.id == expectedId) { found = true; break; } + } + EXPECT_TRUE(found) << "record " << expectedId << " was not retrieved"; + } +} + +TEST_F(OfflineStorageTests_SQLite, StoreRecordsBatchDropsInvalidAndStoresValid) +{ + initializeStorage(); + std::vector batch = { + { "g1", "token", EventLatency_Normal, EventPersistence_Normal, 1, { 1 } }, // valid + { "g2", "token", EventLatency_Normal, EventPersistence_Normal, 0, { 2 } }, // invalid: timestamp <= 0 + }; + + // The invalid record is reported once during validation. + EXPECT_CALL(observerMock, OnStorageFailed("Invalid parameters")); + + // A permanently-invalid record is dropped (reported once) and the valid + // remainder is still stored. One bad record can never wedge the batch or, via + // a caller that re-queues on a short return (e.g. Flush), block the queue. + EXPECT_THAT(offlineStorage->StoreRecords(batch), static_cast(1)); + + TestRecordConsumer consumer; + EXPECT_THAT(offlineStorage->GetAndReserveRecords(consumer, 100000), true); + ASSERT_THAT(consumer.records.size(), static_cast(1)); + EXPECT_THAT(consumer.records[0].id, "g1"); +} + TEST_F(OfflineStorageTests_SQLite, ReservedRecordIsNotReturned) { initializeStorage(); @@ -566,9 +700,12 @@ TEST_F(OfflineStorageTests_SQLite, StoreThousandEventsTakesLessThanASecond) initializeStorage(); auto startTimeMs = PAL::getMonotonicTimeMs(); + std::vector records; + records.reserve(1000); for (int i = 0; i < 1000; ++i) { - EXPECT_THAT(offlineStorage->StoreRecord({std::to_string(i), "token", EventLatency_Normal, EventPersistence_Normal, 1, {}}), true); + records.push_back({std::to_string(i), "token", EventLatency_Normal, EventPersistence_Normal, 1, {}}); } + EXPECT_THAT(offlineStorage->StoreRecords(records), 1000u); TestRecordConsumer consumer; EXPECT_THAT(offlineStorage->GetAndReserveRecords(consumer, 10000, EventLatency_Normal, 1000), true); @@ -697,8 +834,7 @@ StorageRecord GOOD_RECORDS[] = { StorageRecord BAD_RECORDS[] = { { "", "tenant-token", EventLatency_Normal, EventPersistence_Normal, 2, { 1, 2, 3 } }, { "guid", "", EventLatency_Normal, EventPersistence_Normal, 2, { 1, 2, 3 } }, - { "guid", "tenant-token", EventLatency_Unspecified,EventPersistence_Normal, 0, {} }, - { "guid", "tenant-token", static_cast(987),EventPersistence_Normal, 0, {} }, + { "guid", "tenant-token", EventLatency_Unspecified, EventPersistence_Normal, 1, {} }, { "guid", "tenant-token", EventLatency_Normal, EventPersistence_Normal, -1, {} } }; @@ -804,6 +940,30 @@ TEST_F(OfflineStorageTests_SQLite, ExceededStorageSizeCausesDbToDropOldestEvents ASSERT_THAT(consumer.records.size(), 0); } +TEST_F(OfflineStorageTests_SQLite, ResizeDbCompactsThePhysicalDatabase) +{ + constexpr size_t maximumSize = 5 * 1024 * 1024; + EXPECT_CALL(configMock, GetOfflineStorageMaximumSizeBytes()) + .WillRepeatedly(Return(maximumSize)); + configMock[CFG_BOOL_ENABLE_DB_DROP_IF_FULL] = true; + initializeStorage(false); + + std::vector records; + for (int i = 0; i < 12; ++i) + { + records.push_back({ + "record-" + std::to_string(i), + "token", + EventLatency_Normal, + EventPersistence_Normal, + i + 1, + StorageBlob(1024 * 1024) }); + } + + ASSERT_THAT(offlineStorage->StoreRecords(records), records.size()); + EXPECT_LE(offlineStorage->GetSize(), maximumSize); +} + TEST_F(OfflineStorageTests_SQLite, TrimmingAlwaysDropsAtLeastOneEvent) { EXPECT_CALL(configMock, GetOfflineStorageMaximumSizeBytes()) diff --git a/tests/unittests/PalTests.cpp b/tests/unittests/PalTests.cpp index c931ff376..a2719eda2 100644 --- a/tests/unittests/PalTests.cpp +++ b/tests/unittests/PalTests.cpp @@ -10,10 +10,18 @@ #include "Version.hpp" #include +#include +#include #include #include #include #include +#include +#include +#include +#include +#include +#include #ifdef HAVE_MAT_LOGGING #include "pal/PAL.hpp" @@ -225,6 +233,59 @@ namespace void ThrowNonStdException() { throw 123; } void Signal(std::atomic* ran) { ran->store(true); } }; + + class WorkerThreadScheduleTarget + { + public: + void Callback() {} + }; + + class BlockingCancellationTarget + { + public: + void Block() + { + std::unique_lock lock(m_lock); + m_entered = true; + m_stateChanged.notify_all(); + m_stateChanged.wait(lock, [this]() { return m_release; }); + } + + void Signal() + { + std::lock_guard lock(m_lock); + m_successorRan = true; + m_stateChanged.notify_all(); + } + + bool WaitUntilEntered() + { + std::unique_lock lock(m_lock); + return m_stateChanged.wait_for( + lock, std::chrono::seconds{5}, [this]() { return m_entered; }); + } + + bool WaitUntilSuccessorRan() + { + std::unique_lock lock(m_lock); + return m_stateChanged.wait_for( + lock, std::chrono::seconds{5}, [this]() { return m_successorRan; }); + } + + void Release() + { + std::lock_guard lock(m_lock); + m_release = true; + m_stateChanged.notify_all(); + } + + private: + std::mutex m_lock; + std::condition_variable m_stateChanged; + bool m_entered = false; + bool m_release = false; + bool m_successorRan = false; + }; } // A task throwing an exception must be contained by the worker thread loop; @@ -253,6 +314,143 @@ TEST_F(PalTests, WorkerThreadContainsThrowingTask) dispatcher->Join(); } +TEST_F(PalTests, ScheduleTaskAfterWorkerThreadJoinReturnsNoOpHandle) +{ + auto dispatcher = PAL::WorkerThreadFactory::Create(); + dispatcher->Join(); + WorkerThreadScheduleTarget target; + + auto handle = PAL::scheduleTask(dispatcher.get(), 100, &target, &WorkerThreadScheduleTarget::Callback); + + EXPECT_EQ(handle.GetTask(), nullptr); + EXPECT_TRUE(handle.Cancel()); +} + +TEST_F(PalTests, ScheduleTaskHandleClearsAfterWorkerThreadCallbackCompletes) +{ + auto dispatcher = PAL::WorkerThreadFactory::Create(); + std::atomic callbackRan(false); + + class WorkerThreadCompletionTarget + { + public: + explicit WorkerThreadCompletionTarget(std::atomic& callbackRan) : m_callbackRan(callbackRan) {} + void Callback() { m_callbackRan.store(true); } + + private: + std::atomic& m_callbackRan; + } target(callbackRan); + + auto handle = PAL::scheduleTask(dispatcher.get(), 0, &target, &WorkerThreadCompletionTarget::Callback); + + for (int i = 0; i < 500 && !callbackRan.load(); ++i) + PAL::sleep(10); + + ASSERT_TRUE(callbackRan.load()); + EXPECT_EQ(handle.GetTask(), nullptr); + EXPECT_TRUE(handle.Cancel()); + + dispatcher->Join(); +} + +TEST_F(PalTests, CancellingRunningTaskDoesNotDropSuccessor) +{ + auto dispatcher = PAL::WorkerThreadFactory::Create(); + constexpr int Iterations = 400; + + for (int iteration = 0; iteration < Iterations; ++iteration) + { + BlockingCancellationTarget target; + auto running = PAL::scheduleTask( + dispatcher.get(), 0, &target, &BlockingCancellationTarget::Block); + + if (!target.WaitUntilEntered()) + { + target.Release(); + dispatcher->Join(); + FAIL() << "Worker did not start the blocking task"; + return; + } + + auto successor = PAL::scheduleTask( + dispatcher.get(), 0, &target, &BlockingCancellationTarget::Signal); + std::promise cancelStarted; + auto cancelStartedFuture = cancelStarted.get_future(); + bool cancelResult = false; + std::thread cancelThread([&]() { + cancelStarted.set_value(); + cancelResult = running.Cancel(std::numeric_limits::max()); + }); + + cancelStartedFuture.wait(); + for (int i = 0; i < 100; ++i) + { + std::this_thread::yield(); + } + target.Release(); + cancelThread.join(); + + EXPECT_TRUE(cancelResult); + if (!target.WaitUntilSuccessorRan()) + { + dispatcher->Join(); + FAIL() << "Cancellation dropped the successor task at iteration " << iteration; + return; + } + (void)successor; + } + + dispatcher->Join(); +} + +namespace +{ + // Runs on the worker thread and releases the last reference to the dispatcher + // that owns this very thread, exercising the self-dispose path. + class SelfDisposeHelper + { + public: + std::function releaseLastRef; + std::atomic* done = nullptr; + void Run() + { + releaseLastRef(); // drops the last dispatcher reference on its own thread + done->store(true); + } + }; +} + +// The process-wide worker is shared by reference count, and a task can drop the last +// reference from within itself (e.g. by tearing down its LogManager/PAL) while running +// ON the worker thread. The worker must not be freed underneath its own still-running +// threadFunc: it detaches and defers destruction to the thread. This exercises that +// path and must not use-after-free (caught by ASAN). +TEST_F(PalTests, WorkerThreadSelfDisposeOnOwnThreadIsSafe) +{ + auto dispatcher = PAL::WorkerThreadFactory::Create(); + auto* raw = dispatcher.get(); + // 'box' holds the only remaining reference; the task releases it on the worker + // thread. Keep it in a shared box so a copy captured by the task's callable can + // reset it without naming the dispatcher's concrete type. + auto box = std::make_shared(std::move(dispatcher)); + + std::atomic done(false); + SelfDisposeHelper helper; + helper.releaseLastRef = [box]() { box->reset(); }; + helper.done = &done; + + PAL::dispatchTask(raw, &helper, &SelfDisposeHelper::Run); + + for (int i = 0; i < 500 && !done.load(); ++i) + PAL::sleep(10); + ASSERT_TRUE(done.load()); + + // Give the worker time to break its loop and delete itself after the task + // returns. Reaching here without a crash / ASAN report means the object was not + // freed underneath its own threadFunc. + PAL::sleep(200); +} + #ifdef HAVE_MAT_LOGGING class LogInitTest : public Test { diff --git a/tests/unittests/TaskDispatcherCAPITests.cpp b/tests/unittests/TaskDispatcherCAPITests.cpp index b227deb13..0a7a7814c 100644 --- a/tests/unittests/TaskDispatcherCAPITests.cpp +++ b/tests/unittests/TaskDispatcherCAPITests.cpp @@ -9,7 +9,11 @@ #include "pal/typename.hpp" #include "mat.h" +#include +#include +#include #include +#include using namespace testing; using namespace MAT; @@ -229,6 +233,156 @@ TEST(TaskDispatcherCAPITests, Join) EXPECT_EQ(wasJoined, true); } +namespace +{ + // Dispatcher that always drops (and deletes) the task, modeling the + // shutdown-drop path where Queue() cannot report failure. + class DroppingTaskDispatcher : public ITaskDispatcher + { + public: + bool cancelCalled = false; + void Join() override {} + void Queue(MAT::Task* task) override { delete task; } + bool Cancel(MAT::Task* /*task*/, uint64_t /*waitTime*/ = 0) override + { + cancelCalled = true; + return false; + } + }; + + struct NoopCallbackTarget + { + void Callback(int, int) {} + }; + + struct BlockingCallbackTarget + { + std::atomic entered{false}; + std::atomic release{false}; + + void Callback(int, int) + { + entered.store(true, std::memory_order_release); + while (!release.load(std::memory_order_acquire)) + { + std::this_thread::yield(); + } + } + }; +} + +// When the dispatcher drops the task (for example during shutdown), scheduleTask +// must return a no-op handle rather than one pointing at the freed task, so the +// caller never holds a dangling pointer and Cancel() is a safe no-op. +TEST(TaskDispatcherCAPITests, ScheduleTaskReturnsNoOpHandleWhenTaskDropped) +{ + DroppingTaskDispatcher dispatcher; + NoopCallbackTarget target; + + auto handle = scheduleTask(&dispatcher, 100 /*delayMs*/, &target, &NoopCallbackTarget::Callback, 1, 2); + + EXPECT_EQ(handle.GetTask(), nullptr); + EXPECT_TRUE(handle.Cancel()); + EXPECT_FALSE(dispatcher.cancelCalled); +} + +namespace +{ + struct DeferredExecutionState + { + std::string taskId; + task_callback_fn_t callback = nullptr; + std::atomic cancelCalled{false}; + }; + + static std::unique_ptr s_deferredExecutionState; + + void EVTSDK_LIBABI_CDECL OnDeferredTaskDispatcherQueue(evt_task_t* task, task_callback_fn_t callback) + { + s_deferredExecutionState->taskId = task->id; + s_deferredExecutionState->callback = callback; + } + + bool EVTSDK_LIBABI_CDECL OnDeferredTaskDispatcherCancel(const char* taskId) + { + s_deferredExecutionState->cancelCalled.store(true, std::memory_order_release); + return (s_deferredExecutionState->taskId == taskId); + } + + void EVTSDK_LIBABI_CDECL OnDeferredTaskDispatcherJoin() + {} +} + +TEST(TaskDispatcherCAPITests, ScheduleTaskHandleClearsAfterAsyncCallbackCompletes) +{ + TaskDispatcher_CAPI taskDispatcher(&OnDeferredTaskDispatcherQueue, &OnDeferredTaskDispatcherCancel, &OnDeferredTaskDispatcherJoin); + s_deferredExecutionState.reset(new DeferredExecutionState()); + + NoopCallbackTarget target; + auto handle = scheduleTask(&taskDispatcher, 100 /*delayMs*/, &target, &NoopCallbackTarget::Callback, 1, 2); + + ASSERT_NE(handle.GetTask(), nullptr); + ASSERT_NE(s_deferredExecutionState->callback, nullptr); + + s_deferredExecutionState->callback(s_deferredExecutionState->taskId.c_str()); + + EXPECT_EQ(handle.GetTask(), nullptr); + EXPECT_TRUE(handle.Cancel()); + EXPECT_FALSE(s_deferredExecutionState->cancelCalled); + + s_deferredExecutionState.reset(); +} + +TEST(TaskDispatcherCAPITests, CancelWaitsForCallbackAlreadyInProgress) +{ + TaskDispatcher_CAPI taskDispatcher(&OnDeferredTaskDispatcherQueue, &OnDeferredTaskDispatcherCancel, &OnDeferredTaskDispatcherJoin); + s_deferredExecutionState.reset(new DeferredExecutionState()); + + BlockingCallbackTarget target; + auto handle = scheduleTask(&taskDispatcher, 100 /*delayMs*/, &target, &BlockingCallbackTarget::Callback, 1, 2); + ASSERT_NE(s_deferredExecutionState->callback, nullptr); + + std::thread callbackThread([&]() { + s_deferredExecutionState->callback(s_deferredExecutionState->taskId.c_str()); + }); + + while (!target.entered.load(std::memory_order_acquire)) + { + std::this_thread::yield(); + } + + std::atomic cancelReturned{false}; + bool cancelResult = false; + std::thread cancelThread([&]() { + cancelResult = handle.Cancel(std::numeric_limits::max()); + cancelReturned.store(true, std::memory_order_release); + }); + + bool cancelWasWaiting = false; + for (int i = 0; i < 1000; ++i) + { + if (cancelReturned.load(std::memory_order_acquire)) + { + break; + } + if (s_deferredExecutionState->cancelCalled.load(std::memory_order_acquire)) + { + cancelWasWaiting = true; + break; + } + std::this_thread::sleep_for(std::chrono::milliseconds(1)); + } + + target.release.store(true, std::memory_order_release); + callbackThread.join(); + cancelThread.join(); + + EXPECT_TRUE(cancelWasWaiting); + EXPECT_TRUE(cancelResult); + EXPECT_EQ(handle.GetTask(), nullptr); + s_deferredExecutionState.reset(); +} + TEST(TaskDispatcherCAPITests, ExecuteCallbackThatThrowsIsContained) { TaskDispatcher_CAPI taskDispatcher(&OnTaskDispatcherQueue, &OnTaskDispatcherCancel, &OnTaskDispatcherJoin); @@ -247,4 +401,3 @@ TEST(TaskDispatcherCAPITests, ExecuteCallbackThatThrowsIsContained) EXPECT_NO_THROW(dispatchTask(&taskDispatcher, testHelper.get(), &TestHelper::Callback, 10 /*param1*/, 20 /*param2*/)); EXPECT_EQ(wasExecuted, true); } - diff --git a/tests/unittests/TransmissionPolicyManagerTests.cpp b/tests/unittests/TransmissionPolicyManagerTests.cpp index 6cbdb99f5..5ee9ce6ac 100644 --- a/tests/unittests/TransmissionPolicyManagerTests.cpp +++ b/tests/unittests/TransmissionPolicyManagerTests.cpp @@ -2,23 +2,47 @@ // Copyright (c) Microsoft Corporation. All rights reserved. // SPDX-License-Identifier: Apache-2.0 // -// -// TODO: re-enable TPM testcases for backoff configuration change -// #include "common/Common.hpp" #include "common/MockIRuntimeConfig.hpp" #include "common/MockIBandwidthController.hpp" +#include "common/MockITelemetrySystem.hpp" #include "tpm/TransmissionPolicyManager.hpp" #include "TransmitProfiles.hpp" +#include +#include +#include +#include + using namespace testing; using namespace MAT; +class TransmissionPolicyManagerTestSystem : public testing::MockITelemetrySystem +{ +public: + explicit TransmissionPolicyManagerTestSystem(IRuntimeConfig& config) + : m_config(config) + { + } + + IRuntimeConfig& getConfig() override + { + return m_config; + } + +private: + IRuntimeConfig& m_config; +}; class TransmissionPolicyManager4Test : public TransmissionPolicyManager { public: + TransmissionPolicyManager4Test(ITelemetrySystem& system, ITaskDispatcher& taskDispatcher, IBandwidthController* bandwidthController) + : TransmissionPolicyManager(system, taskDispatcher, bandwidthController) + { + } + TransmissionPolicyManager4Test(ITelemetrySystem& system, IBandwidthController* bandwidthController) - : TransmissionPolicyManager(system, *PAL::getDefaultTaskDispatcher(), bandwidthController) + : TransmissionPolicyManager4Test(system, *PAL::getDefaultTaskDispatcher(), bandwidthController) { } @@ -32,6 +56,11 @@ class TransmissionPolicyManager4Test : public TransmissionPolicyManager { TransmissionPolicyManager::scheduleUpload(delay, latency, force); } + bool handleStopParent() + { + return TransmissionPolicyManager::handleStop(); + } + using TransmissionPolicyManager::increaseBackoff; using TransmissionPolicyManager::addUpload; using TransmissionPolicyManager::removeUpload; @@ -69,10 +98,174 @@ class TransmissionPolicyManager4Test : public TransmissionPolicyManager { } }; +class BlockingCancelTaskDispatcher : public ITaskDispatcher +{ +public: + ~BlockingCancelTaskDispatcher() override + { + Join(); + } + + void Join() override + { + std::lock_guard lock(m_tasksMutex); + for (auto* task : m_tasks) + { + delete task; + } + m_tasks.clear(); + } + + void Queue(Task* task) override + { + std::lock_guard lock(m_tasksMutex); + m_tasks.push_back(task); + } + + bool Cancel(Task* task, uint64_t waitTime = 0) override + { + { + std::lock_guard lock(m_tasksMutex); + auto it = std::find(m_tasks.begin(), m_tasks.end(), task); + if (it == m_tasks.end()) + { + return false; + } + delete *it; + m_tasks.erase(it); + } + + { + std::lock_guard lock(m_cancelMutex); + m_waitTime = waitTime; + m_cancelEntered = true; + } + m_cancelEnteredCv.notify_all(); + + std::unique_lock lock(m_cancelMutex); + m_cancelReleasedCv.wait(lock, [this]() { return m_cancelReleased; }); + return true; + } + + bool WaitForCancel(const std::chrono::milliseconds timeout) + { + std::unique_lock lock(m_cancelMutex); + return m_cancelEnteredCv.wait_for(lock, timeout, [this]() { return m_cancelEntered; }); + } + + void ReleaseCancel() + { + { + std::lock_guard lock(m_cancelMutex); + m_cancelReleased = true; + } + m_cancelReleasedCv.notify_all(); + } + + uint64_t WaitTime() + { + std::lock_guard lock(m_cancelMutex); + return m_waitTime; + } + +private: + std::mutex m_tasksMutex; + std::vector m_tasks; + + std::mutex m_cancelMutex; + std::condition_variable m_cancelEnteredCv; + std::condition_variable m_cancelReleasedCv; + uint64_t m_waitTime = 0; + bool m_cancelEntered = false; + bool m_cancelReleased = false; +}; + +class RunningTaskDispatcher : public ITaskDispatcher +{ +public: + ~RunningTaskDispatcher() override + { + std::lock_guard lock(m_tasksMutex); + for (auto* task : m_tasks) + { + delete task; + } + m_tasks.clear(); + } + + void Join() override + { + std::lock_guard lock(m_tasksMutex); + for (auto* task : m_tasks) + { + delete task; + } + m_tasks.clear(); + } + + void Queue(Task* task) override + { + std::lock_guard lock(m_tasksMutex); + m_tasks.push_back(task); + } + + bool Cancel(Task* task, uint64_t waitTime = 0) override + { + UNREFERENCED_PARAMETER(task); + UNREFERENCED_PARAMETER(waitTime); + // Simulate a task that is currently executing on the worker: + // cancellation can never proceed without waiting for the run + // to complete, so a no-wait cancel must return false. + std::lock_guard lock(m_tasksMutex); + m_cancelCount++; + return false; + } + + size_t QueuedCount() const + { + std::lock_guard lock(m_tasksMutex); + return m_tasks.size(); + } + + size_t CancelCount() const + { + std::lock_guard lock(m_tasksMutex); + return m_cancelCount; + } + + void RunQueuedTasks() + { + std::vector tasks; + { + std::lock_guard lock(m_tasksMutex); + tasks.swap(m_tasks); + } + for (auto* task : tasks) + { + (*task)(); + delete task; + } + } + +private: + mutable std::mutex m_tasksMutex; + std::vector m_tasks; + size_t m_cancelCount = 0; +}; + +class DroppingTaskDispatcher : public ITaskDispatcher +{ +public: + void Join() override {} + void Queue(Task* task) override { delete task; } + bool Cancel(Task*, uint64_t = 0) override { return false; } +}; + class TransmissionPolicyManagerTests : public StrictMock { protected: StrictMock runtimeConfigMock; StrictMock bandwidthControllerMock; + TransmissionPolicyManagerTestSystem system; TransmissionPolicyManager4Test tpm; RouteSink initiateUpload{this, &TransmissionPolicyManagerTests::resultInitiateUpload}; @@ -80,7 +273,8 @@ class TransmissionPolicyManagerTests : public StrictMock { protected: TransmissionPolicyManagerTests() - : tpm(testing::getSystem(), &bandwidthControllerMock) + : system(runtimeConfigMock) + , tpm(system, &bandwidthControllerMock) { tpm.initiateUpload >> initiateUpload; tpm.allUploadsFinished >> allUploadsFinished; @@ -95,23 +289,23 @@ class TransmissionPolicyManagerTests : public StrictMock { .WillRepeatedly(Return(1000000)); EXPECT_CALL(runtimeConfigMock, GetMinimumUploadBandwidthBps()) .WillRepeatedly(Return(1000000)); + EXPECT_CALL(runtimeConfigMock, GetUploadRetryBackoffConfig()) + .WillRepeatedly(Return(DefaultBackoffConfig)); ON_CALL(tpm, uploadAsync(_)). WillByDefault(Invoke(&tpm, &TransmissionPolicyManager4Test::uploadAsyncParent)); } }; -#if 0 -TEST_F(TransmissionPolicyManagerTests, StartSchedulesUploadImmediately) +TEST_F(TransmissionPolicyManagerTests, StartSchedulesUploadAfterInitialDelay) { tpm.uploadScheduled(false); tpm.paused(false); - EXPECT_CALL(tpm, scheduleUpload(0, EventLatency_Normal,false)).WillOnce(Return()); + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 1000 }, EventLatency_Normal, false)).WillOnce(Return()); EXPECT_THAT(tpm.start(), true); // EXPECT_CALL(tpm, uploadAsync(EventLatency_Normal)).WillOnce(Return()); EXPECT_THAT(tpm.paused(), false); } -#endif TEST_F(TransmissionPolicyManagerTests, StopLeavesNoScheduledUploads) { @@ -153,8 +347,8 @@ TEST_F(TransmissionPolicyManagerTests, IncomingEventDoesNothingWhenPaused) { tpm.paused(true); - auto event = new IncomingEventContext(); - tpm.eventArrived(event); + IncomingEventContext event; + tpm.eventArrived(&event); } TEST_F(TransmissionPolicyManagerTests, IncomingEventSchedulesUpload) @@ -174,13 +368,13 @@ TEST_F(TransmissionPolicyManagerTests, IncomingEventSchedulesUpload) EXPECT_TRUE(TransmitProfiles::load(customProfile)); EXPECT_TRUE(TransmitProfiles::setProfile("Fred")); - auto event = new IncomingEventContext(); - event->record.latency = EventLatency_Normal; + IncomingEventContext event; + event.record.latency = EventLatency_Normal; EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds { 1000 }, EventLatency_Normal, true)) .WillOnce(Return()); - tpm.eventArrived(event); + tpm.eventArrived(&event); } TEST_F(TransmissionPolicyManagerTests, ProfileAffectsSchedule) @@ -200,10 +394,10 @@ TEST_F(TransmissionPolicyManagerTests, ProfileAffectsSchedule) EXPECT_TRUE(TransmitProfiles::load(customProfile)); EXPECT_TRUE(TransmitProfiles::setProfile("Fred")); - auto event = new IncomingEventContext(); - event->record.latency = EventLatency_Normal; + IncomingEventContext event; + event.record.latency = EventLatency_Normal; EXPECT_CALL(tpm, scheduleUpload(_, _, _)).Times(0); - tpm.eventArrived(event); + tpm.eventArrived(&event); TransmitProfiles::reset(); } @@ -224,10 +418,10 @@ TEST_F(TransmissionPolicyManagerTests, NoUploadForNegative) EXPECT_TRUE(TransmitProfiles::load(customProfile)); EXPECT_TRUE(TransmitProfiles::setProfile("Fred")); - auto event = new IncomingEventContext(); - event->record.latency = EventLatency_Normal; + IncomingEventContext event; + event.record.latency = EventLatency_Normal; EXPECT_CALL(tpm, scheduleUpload(_, _, _)).Times(0); - tpm.eventArrived(event); + tpm.eventArrived(&event); EXPECT_CALL(tpm, uploadAsync(_)).Times(0); tpm.scheduleUploadParent(std::chrono::milliseconds{-1000}, EventLatency_RealTime, true); TransmitProfiles::reset(); @@ -237,12 +431,12 @@ TEST_F(TransmissionPolicyManagerTests, ImmediateIncomingEventStartsUploadImmedia { tpm.paused(false); - auto event = new IncomingEventContext(); - event->record.latency = EventLatency_Max; + IncomingEventContext event; + event.record.latency = EventLatency_Max; EventsUploadContextPtr upload; EXPECT_CALL(*this, resultInitiateUpload(_)) .WillOnce(SaveArg<0>(&upload)); - tpm.eventArrived(event); + tpm.eventArrived(&event); ASSERT_THAT(upload, NotNull()); EXPECT_THAT(upload->requestedMinLatency, EventLatency_Max); @@ -264,7 +458,7 @@ TEST_F(TransmissionPolicyManagerTests, UploadDoesNothingWhenAlreadyActive) EXPECT_CALL( tpm, uploadAsync(_) ).Times(0); } -#if 0 +#ifdef ENABLE_BW_CONTROLLER TEST_F(TransmissionPolicyManagerTests, UploadPostponedWithInsufficientAvailableBandwidth) { tpm.uploadScheduled(true); @@ -272,9 +466,9 @@ TEST_F(TransmissionPolicyManagerTests, UploadPostponedWithInsufficientAvailableB EXPECT_CALL(bandwidthControllerMock, GetProposedBandwidthBps()) .WillOnce(Return(999999)); - EXPECT_CALL(tpm, scheduleUpload(1000, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 1000 }, EventLatency_Normal, false)) .WillOnce(Return()); - tpm.uploadAsync(EventLatency_Normal); + tpm.uploadAsyncParent(EventLatency_Normal); EXPECT_THAT(tpm.uploadScheduled(), false); } @@ -288,7 +482,7 @@ TEST_F(TransmissionPolicyManagerTests, UploadInitiatesUpload) EventsUploadContextPtr upload; EXPECT_CALL(*this, resultInitiateUpload(_)) .WillOnce(SaveArg<0>(&upload)); - tpm.uploadAsync(EventLatency_Normal); + tpm.uploadAsyncParent(EventLatency_Normal); EXPECT_THAT(tpm.uploadScheduled(), false); EXPECT_THAT(upload, NotNull()); @@ -330,7 +524,6 @@ TEST_F(TransmissionPolicyManagerTests, SuccessfulUploadSchedulesNextOneImmediate tpm.eventsUploadSuccessful(upload); } -#if 0 TEST_F(TransmissionPolicyManagerTests, RejectedUploadSchedulesNextOneWithLargerDelay) { EXPECT_CALL(runtimeConfigMock, GetUploadRetryBackoffConfig()) @@ -344,76 +537,70 @@ TEST_F(TransmissionPolicyManagerTests, RejectedUploadSchedulesNextOneWithLargerD tpm.eventsUploadRejected(upload); upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(6000, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 6000 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadRejected(upload); } -#endif -#if 0 TEST_F(TransmissionPolicyManagerTests, FailedUploadSchedulesNextOneWithLargerDelay) { EXPECT_CALL(runtimeConfigMock, GetUploadRetryBackoffConfig()) .WillRepeatedly(Return("E,3000,300000,2,0")); auto upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(3000, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 3000 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadFailed(upload); upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(6000, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 6000 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadFailed(upload); } -#endif -#if 0 TEST_F(TransmissionPolicyManagerTests, SuccessfulUploadResetsBackoffDelay) { EXPECT_CALL(runtimeConfigMock, GetUploadRetryBackoffConfig()) .WillRepeatedly(Return("E,3000,300000,2,0")); auto upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(3000, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 3000 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadRejected(upload); upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(0, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 0 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadSuccessful(upload); upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(3000, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 3000 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadRejected(upload); upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(6000, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 6000 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadFailed(upload); upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(0, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 0 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadSuccessful(upload); upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(3000, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 3000 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadFailed(upload); } -#endif -#if 0 TEST_F(TransmissionPolicyManagerTests, InvalidUploadRetryBackoffConfigKeepsUsingThePreviousOne) { EXPECT_CALL(runtimeConfigMock, GetUploadRetryBackoffConfig()) .WillRepeatedly(Return("E,1000,300000,2,0")); auto upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(1000, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 1000 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadFailed(upload); @@ -421,11 +608,10 @@ TEST_F(TransmissionPolicyManagerTests, InvalidUploadRetryBackoffConfigKeepsUsing .WillRepeatedly(Return("x,")); upload = tpm.fakeActiveUpload(); - EXPECT_CALL(tpm, scheduleUpload(2000, EventLatency_Normal, false)) + EXPECT_CALL(tpm, scheduleUpload(std::chrono::milliseconds{ 2000 }, EventLatency_Normal, false)) .WillOnce(Return()); tpm.eventsUploadFailed(upload); } -#endif TEST_F(TransmissionPolicyManagerTests, AbortedUploadDoesNotScheduleNextOne) { @@ -491,11 +677,11 @@ TEST_F(TransmissionPolicyManagerTests, FredProfile) EXPECT_TRUE(TransmitProfiles::setProfile("Fred_Profile")); tpm.paused(false); - auto event = new IncomingEventContext(); - event->record.latency = EventLatency_Normal; + IncomingEventContext event; + event.record.latency = EventLatency_Normal; EXPECT_CALL(tpm, scheduleUpload(_, _, _)) .Times(0); - tpm.eventArrived(event); + tpm.eventArrived(&event); } TEST_F(TransmissionPolicyManagerTests, Constructor_IsPaused_True) @@ -608,6 +794,124 @@ TEST_F(TransmissionPolicyManagerTests, cancelUploadTask_ScheduledUpload_IsUpload ASSERT_FALSE(tpm.m_isUploadScheduled); } +TEST_F(TransmissionPolicyManagerTests, cancelUploadTask_WaitForCompletionUsesFiniteDispatcherWait) +{ + BlockingCancelTaskDispatcher dispatcher; + TransmissionPolicyManager4Test blockingTpm(testing::getSystem(), dispatcher, &bandwidthControllerMock); + blockingTpm.paused(false); + blockingTpm.scheduleUploadParent(std::chrono::milliseconds{ 1000 }, EventLatency_Normal, false); + + auto cancel = std::async(std::launch::async, [&blockingTpm]() { + return blockingTpm.cancelUploadTask(true); + }); + + if (!dispatcher.WaitForCancel(std::chrono::seconds{ 5 })) + { + dispatcher.ReleaseCancel(); + cancel.get(); + FAIL() << "Timed out waiting for cancel to block"; + } + + EXPECT_EQ(dispatcher.WaitTime(), static_cast(DefaultTaskCancelTime.count())); + dispatcher.ReleaseCancel(); + EXPECT_TRUE(cancel.get()); +} + +TEST_F(TransmissionPolicyManagerTests, StopInvalidatesTaskWhenDispatcherCannotCancel) +{ + RunningTaskDispatcher dispatcher; + TransmissionPolicyManager4Test runningTpm(testing::getSystem(), dispatcher, &bandwidthControllerMock); + runningTpm.paused(false); + runningTpm.scheduleUploadParent(std::chrono::milliseconds{ 1000 }, EventLatency_Normal, false); + + EXPECT_TRUE(runningTpm.handleStopParent()); + + EXPECT_EQ(dispatcher.CancelCount(), 1u); + EXPECT_FALSE(runningTpm.m_isUploadScheduled); + EXPECT_EQ(runningTpm.m_scheduledUploadTime, std::numeric_limits::max()); + EXPECT_CALL(runningTpm, uploadAsync(_)).Times(0); + dispatcher.RunQueuedTasks(); +} + +TEST_F(TransmissionPolicyManagerTests, ForceScheduleRetainsImmediateUploadWhenCancelBlocks) +{ + BlockingCancelTaskDispatcher dispatcher; + TransmissionPolicyManager4Test blockingTpm(testing::getSystem(), dispatcher, &bandwidthControllerMock); + blockingTpm.paused(false); + + blockingTpm.scheduleUploadParent(std::chrono::milliseconds{ 1000 }, EventLatency_Normal, false); + auto delayedUploadTime = blockingTpm.m_scheduledUploadTime; + + auto forceSchedule = std::async(std::launch::async, [&blockingTpm]() { + blockingTpm.scheduleUploadParent(std::chrono::milliseconds{}, EventLatency_RealTime, true); + }); + + if (!dispatcher.WaitForCancel(std::chrono::seconds{ 5 })) + { + dispatcher.ReleaseCancel(); + forceSchedule.get(); + FAIL() << "Timed out waiting for cancel to block"; + } + + auto delayedSchedule = std::async(std::launch::async, [&blockingTpm]() { + blockingTpm.scheduleUploadParent(std::chrono::milliseconds{ 1000 }, EventLatency_Normal, false); + }); + + EXPECT_EQ(delayedSchedule.wait_for(std::chrono::milliseconds{ 100 }), std::future_status::timeout); + + dispatcher.ReleaseCancel(); + + forceSchedule.get(); + delayedSchedule.get(); + + ASSERT_TRUE(blockingTpm.m_isUploadScheduled); + EXPECT_LT(blockingTpm.m_scheduledUploadTime, delayedUploadTime); +} + +TEST_F(TransmissionPolicyManagerTests, ForceScheduleAppliesLatencyWhenRunningCancelFails) +{ + RunningTaskDispatcher dispatcher; + TransmissionPolicyManager4Test runningTpm(testing::getSystem(), dispatcher, &bandwidthControllerMock); + runningTpm.paused(false); + + // Queue an initial upload so m_scheduledUpload has a non-null task and + // m_isUploadScheduled is set; the dispatcher's Cancel will fail later + // (simulating the "task currently executing on worker" race). + runningTpm.scheduleUploadParent(std::chrono::milliseconds{ 1000 }, EventLatency_Normal, false); + ASSERT_TRUE(runningTpm.m_isUploadScheduled); + ASSERT_EQ(dispatcher.QueuedCount(), 1u); + + auto scheduledTimeBefore = runningTpm.m_scheduledUploadTime; + // Reset m_runningLatency so we can observe the force path updating it + // (the initial schedule may have bumped it depending on the active + // profile's timers). + runningTpm.runningLatency(EventLatency_Normal); + + // Force a higher-priority schedule. The dispatcher's no-wait cancel + // returns false, so the previous task remains in flight. The fix in + // scheduleUpload must propagate the new latency to m_runningLatency + // so the running task picks it up under the same mutex. + runningTpm.scheduleUploadParent(std::chrono::milliseconds{}, EventLatency_RealTime, true); + + EXPECT_GE(dispatcher.CancelCount(), 1u); + EXPECT_EQ(dispatcher.QueuedCount(), 1u); + EXPECT_TRUE(runningTpm.m_isUploadScheduled); + EXPECT_EQ(runningTpm.m_runningLatency, EventLatency_RealTime); + EXPECT_EQ(runningTpm.m_scheduledUploadTime, scheduledTimeBefore); +} + +TEST_F(TransmissionPolicyManagerTests, DroppedScheduleDoesNotLatchUploadState) +{ + DroppingTaskDispatcher dispatcher; + TransmissionPolicyManager4Test droppingTpm(testing::getSystem(), dispatcher, &bandwidthControllerMock); + droppingTpm.paused(false); + + droppingTpm.scheduleUploadParent(std::chrono::milliseconds{ 1000 }, EventLatency_Normal, false); + + EXPECT_FALSE(droppingTpm.m_isUploadScheduled); + EXPECT_EQ(droppingTpm.m_scheduledUploadTime, std::numeric_limits::max()); +} + TEST_F(TransmissionPolicyManagerTests, increaseBackoff_EmptyBackoffObject_ReturnZero) { tpm.m_backoff = nullptr; diff --git a/tests/unittests/TransmitProfilesTests.cpp b/tests/unittests/TransmitProfilesTests.cpp index 58e9d36b5..ce8839de5 100644 --- a/tests/unittests/TransmitProfilesTests.cpp +++ b/tests/unittests/TransmitProfilesTests.cpp @@ -375,6 +375,24 @@ R"([{ ASSERT_TRUE(TransmitProfiles::load(badRule)); } +TEST_F(TransmitProfilesTests, load_Json_RuleWithLowBatteryPowerState_MapsToPowerSourceLowBattery) +{ + // A rule using the "low_battery" powerState must map to PowerSource_LowBattery + // rather than silently falling back to the default PowerSource_Any. + const std::string profile = +R"([{ + "name": "LowBatteryProfile", + "rules": [ + { "powerState": "low_battery", "timers": [ 8, 4, 2 ] } + ] +}])"; + + ASSERT_TRUE(TransmitProfiles::load(profile)); + const auto& rules = TransmitProfiles::profiles[std::string{"LowBatteryProfile"}].rules; + ASSERT_EQ(rules.size(), size_t{1}); + ASSERT_EQ(rules[0].powerState, PowerSource_LowBattery); +} + /* The following tests probably should not pass. But they do.