Skip to content

Commit 2670e0d

Browse files
author
bykhovtsev
committed
refactor: change the way adding src tvm id in access log
``` void Middleware::OnCallStart(MiddlewareCallContext& context) const { // Add common storage to extra log tags for other middlewares context.GetStorageContext().Emplace(kLogExtraTag, logging::LogExtra{}); } ``` This is a rather difficult operation involving dynamic allocation. It is cheaper not to create a kLogExtraTag key if it is not used. On the other hand `SetAdditionalLogKeys` is a bit more convinient contract, cause it is not neccessary for a middleware check if LogExtra variable exists commit_hash:5d13b5f73902e2b3fe4083cc47025728938bc0a9
1 parent 1ede5ce commit 2670e0d

File tree

10 files changed

+66
-28
lines changed

10 files changed

+66
-28
lines changed

.mapping.json

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2222,6 +2222,7 @@
22222222
"grpc/include/userver/ugrpc/server/impl/stream_adapter.hpp":"taxi/uservices/userver/grpc/include/userver/ugrpc/server/impl/stream_adapter.hpp",
22232223
"grpc/include/userver/ugrpc/server/metadata_utils.hpp":"taxi/uservices/userver/grpc/include/userver/ugrpc/server/metadata_utils.hpp",
22242224
"grpc/include/userver/ugrpc/server/middlewares/access_log/component.hpp":"taxi/uservices/userver/grpc/include/userver/ugrpc/server/middlewares/access_log/component.hpp",
2225+
"grpc/include/userver/ugrpc/server/middlewares/access_log/log_extra.hpp":"taxi/uservices/userver/grpc/include/userver/ugrpc/server/middlewares/access_log/log_extra.hpp",
22252226
"grpc/include/userver/ugrpc/server/middlewares/baggage/component.hpp":"taxi/uservices/userver/grpc/include/userver/ugrpc/server/middlewares/baggage/component.hpp",
22262227
"grpc/include/userver/ugrpc/server/middlewares/baggage/middleware.hpp":"taxi/uservices/userver/grpc/include/userver/ugrpc/server/middlewares/baggage/middleware.hpp",
22272228
"grpc/include/userver/ugrpc/server/middlewares/base.hpp":"taxi/uservices/userver/grpc/include/userver/ugrpc/server/middlewares/base.hpp",
@@ -2351,6 +2352,7 @@
23512352
"grpc/src/ugrpc/server/impl/service_worker.cpp":"taxi/uservices/userver/grpc/src/ugrpc/server/impl/service_worker.cpp",
23522353
"grpc/src/ugrpc/server/impl/service_worker_impl.cpp":"taxi/uservices/userver/grpc/src/ugrpc/server/impl/service_worker_impl.cpp",
23532354
"grpc/src/ugrpc/server/middlewares/access_log/component.cpp":"taxi/uservices/userver/grpc/src/ugrpc/server/middlewares/access_log/component.cpp",
2355+
"grpc/src/ugrpc/server/middlewares/access_log/log_extra.cpp":"taxi/uservices/userver/grpc/src/ugrpc/server/middlewares/access_log/log_extra.cpp",
23542356
"grpc/src/ugrpc/server/middlewares/access_log/middleware.cpp":"taxi/uservices/userver/grpc/src/ugrpc/server/middlewares/access_log/middleware.cpp",
23552357
"grpc/src/ugrpc/server/middlewares/access_log/middleware.hpp":"taxi/uservices/userver/grpc/src/ugrpc/server/middlewares/access_log/middleware.hpp",
23562358
"grpc/src/ugrpc/server/middlewares/baggage/middleware.cpp":"taxi/uservices/userver/grpc/src/ugrpc/server/middlewares/baggage/middleware.cpp",

grpc/benchmarks/format_log_message.cpp

Lines changed: 3 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -17,18 +17,16 @@ void FormatLogMessage(benchmark::State& state) {
1717
std::string peer = "2a02:aaaa:aaaa:aaaa::1:1f";
1818
std::chrono::system_clock::time_point start_time(std::chrono::seconds{1024 * 1024 * 42});
1919
std::string_view call_name = "hello.HelloService/SayHello";
20-
logging::LogExtra log_extra;
2120

2221
// NOLINTNEXTLINE(clang-analyzer-deadcode.DeadStores)
2322
for (auto _ : state) {
24-
auto result = ugrpc::server::impl::FormatLogMessage(
25-
metadata, peer, start_time, call_name, grpc::StatusCode::OK, log_extra
26-
);
23+
auto result =
24+
ugrpc::server::impl::FormatLogMessage(metadata, peer, start_time, call_name, grpc::StatusCode::OK, nullptr);
2725
benchmark::DoNotOptimize(result);
2826
}
2927

3028
auto result =
31-
ugrpc::server::impl::FormatLogMessage(metadata, peer, start_time, call_name, grpc::StatusCode::OK, log_extra);
29+
ugrpc::server::impl::FormatLogMessage(metadata, peer, start_time, call_name, grpc::StatusCode::OK, nullptr);
3230

3331
const std::string_view log_line_view{result.ExtractTextLogItem().log_line}; // Convert SmallString to string_view
3432

grpc/include/userver/ugrpc/server/middlewares/access_log/component.hpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,7 +15,7 @@ USERVER_NAMESPACE_BEGIN
1515
namespace ugrpc::server::middlewares::access_log {
1616

1717
/// @brief Storage to handle additional fields in access_log
18-
/// @snippet grpc/tests/logging_test.cpp
18+
/// @snippet grpc/tests/logging_test.cpp grpc log extra tag
1919
inline const utils::AnyStorageDataTag<ugrpc::server::StorageContext, logging::LogExtra> kLogExtraTag;
2020

2121
/// @ingroup userver_components userver_base_classes
Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
#pragma once
2+
3+
#include <userver/logging/log_extra.hpp>
4+
#include <userver/ugrpc/server/middlewares/base.hpp>
5+
6+
USERVER_NAMESPACE_BEGIN
7+
8+
namespace ugrpc::server::middlewares::access_log {
9+
/// @brief Adds or extends log extra fields for gRPC access logging
10+
/// @param context Middleware call context containing the storage
11+
/// @param log_extra Additional log fields to add (will be moved from)
12+
/// @snippet grpc/tests/logging_test.cpp grpc log extra tag
13+
///
14+
/// If log extra fields already exist in the context, extends them with new fields.
15+
/// Otherwise, creates new log extra storage with the provided fields.
16+
void SetAdditionalLogKeys(MiddlewareCallContext& context, logging::LogExtra&& log_extra);
17+
} // namespace ugrpc::server::middlewares::access_log
18+
19+
USERVER_NAMESPACE_END

grpc/src/ugrpc/server/impl/format_log_message.cpp

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -74,7 +74,7 @@ logging::impl::LogExtraTskvFormatter FormatLogMessage(
7474
std::chrono::system_clock::time_point start_time,
7575
std::string_view call_name,
7676
grpc::StatusCode code,
77-
const logging::LogExtra& log_extra
77+
const logging::LogExtra* log_extra
7878
) {
7979
static const auto timezone = utils::datetime::LocalTimezoneTimestring(start_time, "%z");
8080

@@ -120,7 +120,9 @@ logging::impl::LogExtraTskvFormatter FormatLogMessage(
120120
ToString(code)
121121
);
122122

123-
formatter.Append(log_extra);
123+
if (log_extra) {
124+
formatter.Append(*log_extra);
125+
}
124126

125127
return formatter;
126128
}

grpc/src/ugrpc/server/impl/format_log_message.hpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@ logging::impl::LogExtraTskvFormatter FormatLogMessage(
1919
std::chrono::system_clock::time_point start_time,
2020
std::string_view call_name,
2121
grpc::StatusCode code,
22-
const logging::LogExtra& log_extra
22+
const logging::LogExtra* log_extra
2323
);
2424

2525
} // namespace ugrpc::server::impl
Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,21 @@
1+
#include <userver/ugrpc/server/middlewares/access_log/log_extra.hpp>
2+
3+
#include <userver/ugrpc/server/middlewares/access_log/component.hpp>
4+
5+
USERVER_NAMESPACE_BEGIN
6+
7+
namespace ugrpc::server::middlewares::access_log {
8+
9+
void SetAdditionalLogKeys(MiddlewareCallContext& context, logging::LogExtra&& log_extra) {
10+
auto* extra = context.GetStorageContext().GetOptional(kLogExtraTag);
11+
12+
if (extra) {
13+
extra->Extend(std::move(log_extra));
14+
} else {
15+
context.GetStorageContext().Emplace(kLogExtraTag, std::move(log_extra));
16+
}
17+
}
18+
19+
} // namespace ugrpc::server::middlewares::access_log
20+
21+
USERVER_NAMESPACE_END

grpc/src/ugrpc/server/middlewares/access_log/middleware.cpp

Lines changed: 1 addition & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -21,7 +21,7 @@ void WriteAccessLog(
2121
constexpr auto kLevel = logging::Level::kInfo;
2222

2323
if (access_tskv_logger.ShouldLog(kLevel)) {
24-
const auto& log_extra = context.GetStorageContext().Get(kLogExtraTag);
24+
const auto* log_extra = context.GetStorageContext().GetOptional(kLogExtraTag);
2525

2626
access_tskv_logger.Log(
2727
kLevel,
@@ -45,11 +45,6 @@ void WriteAccessLog(
4545

4646
Middleware::Middleware(Settings&& settings) : logger_(std::move(settings.access_tskv_logger)) {}
4747

48-
void Middleware::OnCallStart(MiddlewareCallContext& context) const {
49-
// Add common storage to extra log tags for other middlewares
50-
context.GetStorageContext().Emplace(kLogExtraTag, logging::LogExtra{});
51-
}
52-
5348
void Middleware::OnCallFinish(MiddlewareCallContext& context, const grpc::Status& status) const {
5449
WriteAccessLog(context, status, *logger_);
5550
}

grpc/src/ugrpc/server/middlewares/access_log/middleware.hpp

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -17,8 +17,6 @@ class Middleware final : public MiddlewareBase {
1717
public:
1818
explicit Middleware(Settings&& settings);
1919

20-
void OnCallStart(MiddlewareCallContext& context) const override;
21-
2220
void OnCallFinish(MiddlewareCallContext& context, const grpc::Status& status) const override;
2321

2422
private:

grpc/tests/logging_test.cpp

Lines changed: 14 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -2,11 +2,11 @@
22

33
#include <gmock/gmock.h>
44

5+
#include <ugrpc/server/middlewares/access_log/middleware.hpp>
6+
#include <userver/ugrpc/server/middlewares/access_log/log_extra.hpp>
57
#include <userver/utest/log_capture_fixture.hpp>
68
#include <userver/utils/regex.hpp>
79

8-
#include <ugrpc/server/middlewares/access_log/middleware.hpp>
9-
1010
#include <tests/unit_test_client.usrv.pb.hpp>
1111
#include <tests/unit_test_service.usrv.pb.hpp>
1212
#include <userver/ugrpc/tests/service_fixtures.hpp>
@@ -73,17 +73,20 @@ class ServiceWithAccessLogFixture : public ugrpc::tests::ServiceFixtureBase {
7373
// Test middleware that adds custom tags to LogExtra
7474
class TagsMiddleware final : public ugrpc::server::MiddlewareBase {
7575
public:
76+
/// [grpc log extra tag]
7677
void OnCallStart(ugrpc::server::MiddlewareCallContext& context) const override {
77-
auto* log_extra = context.GetStorageContext().GetOptional(ugrpc::server::middlewares::access_log::kLogExtraTag);
78-
79-
if (log_extra) {
80-
log_extra->Extend("user_id", "12345");
81-
log_extra->Extend("session_id", "abc-def-ghi");
82-
log_extra->Extend("request_id", "req-98765");
83-
log_extra->Extend("custom_tag", "test-value");
84-
log_extra->Extend("numeric_tag", "42");
85-
}
78+
ugrpc::server::middlewares::access_log::SetAdditionalLogKeys(
79+
context,
80+
logging::LogExtra{
81+
std::pair<std::string, std::string>("user_id", "12345"),
82+
std::pair<std::string, std::string>("session_id", "abc-def-ghi"),
83+
std::pair<std::string, std::string>("request_id", "req-98765"),
84+
std::pair<std::string, std::string>("custom_tag", "test-value"),
85+
std::pair<std::string, std::string>("numeric_tag", "42"),
86+
}
87+
);
8688
}
89+
/// [grpc log extra tag]
8790
};
8891

8992
template <typename GrpcService>

0 commit comments

Comments
 (0)