Skip to content

Commit

Permalink
Add logging of per-context variables to logging system and network st…
Browse files Browse the repository at this point in the history
…ack (#1507)

* Minor code cleanups related to OLPEDGE-2893

Relates-to: OLPEDGE-2893
Signed-off-by: Hertlein, Ulrich <[email protected]>

* Add per-thread context values to logging system

This change adds a per-thread logging context to the logging
system, which can be set by the user and will then be logged
from all threads and tasks created with that context.

This is useful to correlate requests from the client to any
network requests made based on that request.

The logging formatter must be set up by including a
`MessageFormatter::ElementType::ContextValue` with the 'format'
set to the context key to use.

Resolves: OLPEDGE-2893
Signed-off-by: Hertlein, Ulrich <[email protected]>

* Store+track log context for Curl network stack

When a network requests is created, the current log context is
captured and subsequently made active whenever this request is
processed.

Resolves: OLPEDGE-2893
Signed-off-by: Hertlein, Ulrich <[email protected]>

---------

Signed-off-by: Hertlein, Ulrich <[email protected]>
Co-authored-by: Hertlein, Ulrich <[email protected]>
  • Loading branch information
uhertlein and Hertlein, Ulrich authored May 16, 2024
1 parent e2b4c85 commit a99a285
Show file tree
Hide file tree
Showing 12 changed files with 368 additions and 25 deletions.
2 changes: 2 additions & 0 deletions olp-cpp-sdk-core/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -156,6 +156,7 @@ set(OLP_SDK_LOGGING_HEADERS
./include/olp/core/logging/Format.h
./include/olp/core/logging/Level.h
./include/olp/core/logging/Log.h
./include/olp/core/logging/LogContext.h
./include/olp/core/logging/LogMessage.h
./include/olp/core/logging/MessageFormatter.h
)
Expand Down Expand Up @@ -361,6 +362,7 @@ set(OLP_SDK_LOGGING_SOURCES
./src/logging/FilterGroup.cpp
./src/logging/Format.cpp
./src/logging/Log.cpp
./src/logging/LogContext.cpp
./src/logging/MessageFormatter.cpp
./src/logging/ThreadId.cpp
./src/logging/ThreadId.h
Expand Down
4 changes: 2 additions & 2 deletions olp-cpp-sdk-core/include/olp/core/logging/Log.h
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/*
* Copyright (C) 2019-2021 HERE Europe B.V.
* Copyright (C) 2019-2024 HERE Europe B.V.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
Expand Down Expand Up @@ -61,7 +61,7 @@
*/
#define OLP_SDK_DO_LOG(level, tag, message) \
do { \
std::stringstream __strm; \
std::ostringstream __strm; \
__strm << message; \
::olp::logging::Log::logMessage(level, tag, __strm.str(), __FILE__, \
__LINE__, __FUNCTION__, \
Expand Down
81 changes: 81 additions & 0 deletions olp-cpp-sdk-core/include/olp/core/logging/LogContext.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,81 @@
/*
* Copyright (C) 2019-2024 HERE Europe B.V.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* https://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*
* SPDX-License-Identifier: Apache-2.0
* License-Filename: LICENSE
*/

#pragma once

#include <olp/core/CoreApi.h>

#include <functional>
#include <memory>
#include <string>
#include <unordered_map>

/**
* @brief The LogContext object stores per-thread key/value pairs that can be
* picked up in log messages using the
* 'olp::logging::MessageFormatter::ElementType::ContextValue' logging element.
*/
namespace olp {
namespace logging {
/// A context key/value map. The keys are required to be const and immutable.
using LogContext = std::unordered_map<std::string, std::string>;

/// A function that sets the current log context.
using LogContextSetter = std::function<void(std::shared_ptr<const LogContext>)>;

/// A function that gets the current log context.
using LogContextGetter = std::function<std::shared_ptr<const LogContext>()>;

/**
* Sets the getter and setter for the log context.
*
* @param[in] getter The log context getter, or the default getter if
* nullptr.
* @param[in] setter The log context setter, or the default setter if
* nullptr.
*/
CORE_API void SetLogContextGetterSetter(LogContextGetter getter,
LogContextSetter setter);

/// Gets the current thread context.
CORE_API std::shared_ptr<const LogContext> GetContext();

/// Gets a value from the current thread context.
CORE_API const std::string& GetContextValue(const std::string& key);

/**
* @brief The ScopedLogContext class takes ownership of a log context
* and makes it active on construction and restores the previous context on
* destruction.
*
* Passing 'nullptr' is the same as passing an empty LogContext.
*
* @see MessageFormatter::ElementType::Context
*/
class CORE_API ScopedLogContext final {
public:
ScopedLogContext(const std::shared_ptr<const LogContext>& context);
~ScopedLogContext();

private:
std::shared_ptr<const LogContext> context_;
std::shared_ptr<const LogContext> prev_context_;
};
} // namespace logging
} // namespace olp
5 changes: 3 additions & 2 deletions olp-cpp-sdk-core/include/olp/core/logging/MessageFormatter.h
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/*
* Copyright (C) 2019-2021 HERE Europe B.V.
* Copyright (C) 2019-2024 HERE Europe B.V.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
Expand Down Expand Up @@ -91,8 +91,9 @@ class CORE_API MessageFormatter {
/// `strftime()`.
TimeMs, ///< The millisecond portion of the timestamp. It is formatted as
///< an unsigned integer.
ThreadId ///< The thread ID of the thread that generated the message.
ThreadId, ///< The thread ID of the thread that generated the message.
///< It is formatted as an unsigned long.
ContextValue, ///< A key/value literal from LogContext; 'format' is the key to look up.
};

/**
Expand Down
28 changes: 17 additions & 11 deletions olp-cpp-sdk-core/src/http/curl/NetworkCurl.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -844,6 +844,7 @@ NetworkCurl::RequestHandle* NetworkCurl::GetHandle(
handle.send_time = std::chrono::steady_clock::now();
handle.error_text[0] = 0;
handle.skip_content = false;
handle.log_context = logging::GetContext();

return &handle;
}
Expand Down Expand Up @@ -1004,8 +1005,9 @@ void NetworkCurl::CompleteMessage(CURL* handle, CURLcode result) {
int index = GetHandleIndex(handle);
if (index >= 0 && index < static_cast<int>(handles_.size())) {
RequestHandle& rhandle = handles_[index];

logging::ScopedLogContext scopedLogContext(rhandle.log_context);
auto callback = rhandle.callback;

if (!callback) {
OLP_SDK_LOG_WARNING(
kLogTag,
Expand Down Expand Up @@ -1111,35 +1113,36 @@ void NetworkCurl::Run() {
events_.pop_front();

// Only handle handles that are actually used
if (!event.handle->in_use) {
auto* rhandle = event.handle;
if (!rhandle->in_use) {
continue;
}

if (event.type == EventInfo::Type::SEND_EVENT) {
auto res = curl_multi_add_handle(curl_, event.handle->handle);
auto res = curl_multi_add_handle(curl_, rhandle->handle);
if ((res != CURLM_OK) && (res != CURLM_CALL_MULTI_PERFORM)) {
OLP_SDK_LOG_ERROR(
kLogTag, "Send failed, id=" << event.handle->id << ", error="
<< curl_multi_strerror(res));
OLP_SDK_LOG_ERROR(kLogTag,
"Send failed, id=" << rhandle->id << ", error="
<< curl_multi_strerror(res));

// Do not add the handle to msgs vector in case it is a duplicate
// handle error as it will be reset in CompleteMessage handler,
// and curl will crash in the next call of curl_multi_perform
// function. In any other case, lets complete the message.
if (res != CURLM_ADDED_ALREADY) {
msgs.push_back(event.handle->handle);
msgs.push_back(rhandle->handle);
}
}
} else {
// Request was cancelled, so lets remove it from curl
auto code = curl_multi_remove_handle(curl_, event.handle->handle);
auto code = curl_multi_remove_handle(curl_, rhandle->handle);
if (code != CURLM_OK) {
OLP_SDK_LOG_ERROR(kLogTag, "curl_multi_remove_handle failed, error="
<< curl_multi_strerror(code));
}

lock.unlock();
CompleteMessage(event.handle->handle, CURLE_OPERATION_TIMEDOUT);
CompleteMessage(rhandle->handle, CURLE_OPERATION_TIMEDOUT);
lock.lock();
}
}
Expand Down Expand Up @@ -1195,7 +1198,10 @@ void NetworkCurl::Run() {
int handle_index = GetHandleIndex(handle);
if (handle_index >= 0) {
RequestHandle& rhandle = handles_[handle_index];
if (!rhandle.callback) {
logging::ScopedLogContext scopedLogContext(rhandle.log_context);

auto callback = rhandle.callback;
if (!callback) {
OLP_SDK_LOG_WARNING(
kLogTag,
"Request completed without callback, id=" << rhandle.id);
Expand All @@ -1208,7 +1214,7 @@ void NetworkCurl::Run() {
.WithError("CURL error")
.WithBytesDownloaded(download_bytes)
.WithBytesUploaded(upload_bytes);
rhandle.callback(response);
callback(response);
lock.lock();
}

Expand Down
4 changes: 3 additions & 1 deletion olp-cpp-sdk-core/src/http/curl/NetworkCurl.h
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/*
* Copyright (C) 2019-2023 HERE Europe B.V.
* Copyright (C) 2019-2024 HERE Europe B.V.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
Expand Down Expand Up @@ -59,6 +59,7 @@
#include "olp/core/http/Network.h"
#include "olp/core/http/NetworkInitializationSettings.h"
#include "olp/core/http/NetworkRequest.h"
#include "olp/core/logging/LogContext.h"

namespace olp {
namespace http {
Expand Down Expand Up @@ -134,6 +135,7 @@ class NetworkCurl : public olp::http::Network,
bool cancelled{};
bool skip_content{};
char error_text[CURL_ERROR_SIZE]{};
std::shared_ptr<const logging::LogContext> log_context;
};

/**
Expand Down
1 change: 1 addition & 0 deletions olp-cpp-sdk-core/src/logging/Log.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -180,6 +180,7 @@ void LogImpl::appendLogItem(const LogItem& log_item) {
appender_with_log_level.appender->append(log_item);
}
}

// implementation of public static Log API
//--------------------------------------------------------

Expand Down
79 changes: 79 additions & 0 deletions olp-cpp-sdk-core/src/logging/LogContext.cpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,79 @@
/*
* Copyright (C) 2019-2024 HERE Europe B.V.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* https://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*
* SPDX-License-Identifier: Apache-2.0
* License-Filename: LICENSE
*/

#include <olp/core/logging/LogContext.h>

#include <cassert>

namespace olp {
namespace logging {
namespace {
thread_local std::shared_ptr<const LogContext> tls_logContext;

LogContextSetter s_defaultLogContextSetter =
[](std::shared_ptr<const LogContext> context) {
tls_logContext = std::move(context);
};

LogContextSetter s_logContextSetter = s_defaultLogContextSetter;

LogContextGetter s_defaultLogContextGetter = []() { return tls_logContext; };
LogContextGetter s_logContextGetter = s_defaultLogContextGetter;

} // namespace

void SetLogContextGetterSetter(LogContextGetter getter,
LogContextSetter setter) {
s_logContextGetter = getter ? std::move(getter) : s_defaultLogContextGetter;
s_logContextSetter = setter ? std::move(setter) : s_defaultLogContextSetter;
}

std::shared_ptr<const LogContext> GetContext() {
assert(s_logContextGetter && "Invalid LogContext getter");
return s_logContextGetter();
}

const std::string& GetContextValue(const std::string& key) {
static std::string s_empty = "";
auto ctx = GetContext();
if (!ctx || key.empty())
return s_empty;

auto it = ctx->find(key);
if (it == ctx->end())
return s_empty;

return it->second;
}

ScopedLogContext::ScopedLogContext(
const std::shared_ptr<const LogContext>& context)
: context_(context) {
prev_context_ = GetContext();
assert(s_logContextSetter && "Invalid LogContext setter");
s_logContextSetter(context_);
}

ScopedLogContext::~ScopedLogContext() {
assert(s_logContextSetter && "Invalid LogContext setter");
s_logContextSetter(std::move(prev_context_));
}

} // namespace logging
} // namespace olp
10 changes: 8 additions & 2 deletions olp-cpp-sdk-core/src/logging/MessageFormatter.cpp
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/*
* Copyright (C) 2019-2021 HERE Europe B.V.
* Copyright (C) 2019-2024 HERE Europe B.V.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
Expand All @@ -18,11 +18,12 @@
*/

#include <olp/core/logging/Format.h>
#include <olp/core/logging/LogContext.h>
#include <olp/core/logging/MessageFormatter.h>

#include <algorithm>
#include <cassert>
#include <cstring>
#include <functional>
#include <string>

namespace olp {
Expand Down Expand Up @@ -180,6 +181,11 @@ std::string MessageFormatter::format(const LogMessage& message) const {
curElement =
curElementBuffer.format(element.format.c_str(), message.threadId);
break;
case ElementType::ContextValue:
// 'format' is key to lookup
curElement = curElementBuffer.format(
"%s", GetContextValue(element.format).c_str());
break;
default:
continue;
}
Expand Down
Loading

0 comments on commit a99a285

Please sign in to comment.