From 8eef2e31985faf5f368c46c19b47f5c3d1a314b2 Mon Sep 17 00:00:00 2001 From: Aleksey Kashapov Date: Wed, 18 Mar 2026 15:55:21 +0300 Subject: [PATCH 1/4] Refactors and cleans up OTEL's log handler usage --- Makefile | 3 ++ apps/hellgate/src/hellgate.erl | 23 +++------ apps/hellgate/src/hg_otel_log_filter.erl | 24 +--------- apps/hellgate/src/hg_otel_log_handler.erl | 48 ------------------- apps/hellgate/test/hg_invoice_tests_SUITE.erl | 1 + rebar.lock | 4 +- 6 files changed, 14 insertions(+), 89 deletions(-) delete mode 100644 apps/hellgate/src/hg_otel_log_handler.erl diff --git a/Makefile b/Makefile index 86242248..5f110b5b 100644 --- a/Makefile +++ b/Makefile @@ -120,5 +120,8 @@ distclean: clean-build-image test: eunit common-test +dbg: + $(REBAR) ct -v --suite=apps/hellgate/test/hg_invoice_tests_SUITE.erl --group=all_non_destructive_tests --case=payment_big_cascade_success + cover-report: $(REBAR) cover diff --git a/apps/hellgate/src/hellgate.erl b/apps/hellgate/src/hellgate.erl index 17f7577e..b7ad3344 100644 --- a/apps/hellgate/src/hellgate.erl +++ b/apps/hellgate/src/hellgate.erl @@ -134,8 +134,10 @@ ensure_otel_log_handler() -> DelayMs = application:get_env(hellgate, otel_log_scheduled_delay_ms, 1000), TimeoutMs = application:get_env(hellgate, otel_log_exporting_timeout_ms, 300000), LogLevel = application:get_env(hellgate, otel_log_level, info), - HandlerConfig = #{ - report_cb => fun hg_otel_log_filter:format_otp_report_utf8/1, + LoggerHandlerConfig = #{ + level => LogLevel, + filter_default => log, + filters => [{hg_otel_trace_id_bytes, {fun hg_otel_log_filter:filter/2, undefined}}], exporter => {otel_exporter_logs_otlp, #{ protocol => http_protobuf, @@ -145,13 +147,7 @@ ensure_otel_log_handler() -> scheduled_delay_ms => DelayMs, exporting_timeout_ms => TimeoutMs }, - LoggerHandlerConfig = #{ - level => LogLevel, - filter_default => log, - filters => [{hg_otel_trace_id_bytes, {fun hg_otel_log_filter:filter/2, undefined}}], - config => HandlerConfig - }, - case logger:add_handler(otel_logs, hg_otel_log_handler, LoggerHandlerConfig) of + case logger:add_handler(otel_logs, otel_log_handler, LoggerHandlerConfig) of ok -> ok; {error, {already_exist, _}} -> @@ -171,13 +167,8 @@ ensure_otel_log_handler() -> flush_otel_logs() -> case logger:get_handler_config(otel_logs) of {ok, HandlerCfg} -> - Config = maps:get(config, HandlerCfg, #{}), - DelayMs = maps:get( - scheduled_delay_ms, - Config, - maps:get(scheduled_delay_ms, HandlerCfg, 1000) - ), - _ = logger:info("otel_log_handler_flush"), + _ = logger:info("Waiting for OTEL logs exporter to flush"), + DelayMs = maps:get(scheduled_delay_ms, HandlerCfg, 1000), timer:sleep(erlang:min(?FLUSH_MAX_WAIT_MS, DelayMs + ?FLUSH_EXPORT_OVERHEAD_MS)), ok; _ -> diff --git a/apps/hellgate/src/hg_otel_log_filter.erl b/apps/hellgate/src/hg_otel_log_filter.erl index 03018b60..f61aa9e2 100644 --- a/apps/hellgate/src/hg_otel_log_filter.erl +++ b/apps/hellgate/src/hg_otel_log_filter.erl @@ -6,16 +6,10 @@ -module(hg_otel_log_filter). -export([filter/2]). --export([format_otp_report_utf8/1]). -spec filter(logger:log_event(), term()) -> logger:filter_return(). filter(#{meta := Meta} = LogEvent, _FilterConfig) -> - case convert_otel_ids(Meta) of - Meta -> - LogEvent; - Meta1 -> - LogEvent#{meta => Meta1} - end. + LogEvent#{meta := convert_otel_ids(Meta)}. %% Конвертируем hex -> raw bytes только если формат hex (32/16 символов). %% OTLP LogRecord: trace_id=16 bytes, span_id=8 bytes. @@ -30,22 +24,6 @@ convert_otel_ids(#{otel_trace_id := TraceIdHex, otel_span_id := SpanIdHex} = Met convert_otel_ids(Meta) -> Meta. -%% logger:format_otp_report/1 возвращает chardata (часто list()), -%% из-за чего downstream JSON может сериализовать body как массив байт. -%% Явно приводим к UTF-8 binary(), чтобы body в OTel/Loki был строкой. --spec format_otp_report_utf8(logger:report()) -> {unicode:chardata(), list()}. -format_otp_report_utf8(Report) -> - Bin = - try logger:format_otp_report(Report) of - {Format, Args} -> - unicode:characters_to_binary(io_lib:format(Format, Args)) - catch - _:_ -> - %% Не даём report_cb падать: fallback в печатное представление отчёта. - unicode:characters_to_binary(io_lib:format("~tp", [Report])) - end, - {"~ts", [Bin]}. - hex_to_trace_id_bytes(Hex) when is_binary(Hex), byte_size(Hex) =:= 32 -> try <<(binary_to_integer(Hex, 16)):128>> diff --git a/apps/hellgate/src/hg_otel_log_handler.erl b/apps/hellgate/src/hg_otel_log_handler.erl deleted file mode 100644 index 2168620f..00000000 --- a/apps/hellgate/src/hg_otel_log_handler.erl +++ /dev/null @@ -1,48 +0,0 @@ --module(hg_otel_log_handler). - --export([log/2]). --export([adding_handler/1]). --export([removing_handler/1]). --export([changing_config/3]). --export([filter_config/1]). - --spec log(logger:log_event(), map()) -> ok. -log(LogEvent, Config) -> - otel_log_handler:log(LogEvent, Config). - --spec adding_handler(map()) -> {ok, map()} | {error, term()}. -adding_handler(Config) -> - otel_log_handler:adding_handler(merge_module_config(Config)). - --spec removing_handler(map()) -> ok. -removing_handler(Config) -> - otel_log_handler:removing_handler(Config). - --spec changing_config(set | update, map(), map()) -> {ok, map()} | {error, term()}. -changing_config(SetOrUpdate, OldConfig, NewConfig) -> - otel_log_handler:changing_config( - SetOrUpdate, - merge_module_config(OldConfig), - merge_module_config(NewConfig) - ). - --spec filter_config(map()) -> map(). -filter_config(Config) -> - otel_log_handler:filter_config(Config). - -%% Переносим ключи из вложенного config в корневой map для otel_log_handler. -%% Только ключи, которые ожидает otel_log_handler — чтобы случайно не перезаписать -%% верхнеуровневые настройки logger (level, filters, filter_default и т.д.). --define(OTEL_LOG_HANDLER_KEYS, [ - exporter, - report_cb, - max_queue_size, - scheduled_delay_ms, - exporting_timeout_ms -]). - -merge_module_config(#{config := ModuleConfig} = Config) when is_map(ModuleConfig) -> - OtelConfig = maps:with(?OTEL_LOG_HANDLER_KEYS, ModuleConfig), - maps:merge(Config, OtelConfig); -merge_module_config(Config) -> - Config. diff --git a/apps/hellgate/test/hg_invoice_tests_SUITE.erl b/apps/hellgate/test/hg_invoice_tests_SUITE.erl index c0ff2506..3661553f 100644 --- a/apps/hellgate/test/hg_invoice_tests_SUITE.erl +++ b/apps/hellgate/test/hg_invoice_tests_SUITE.erl @@ -499,6 +499,7 @@ groups() -> -spec init_per_suite(config()) -> config(). init_per_suite(C) -> + % ok = logger:set_primary_config(level, debug), % _ = dbg:tracer(), % _ = dbg:p(all, c), % _ = dbg:tpl({'hg_invoice_payment', 'p', '_'}, x), diff --git a/rebar.lock b/rebar.lock index e3f22424..8aeefdce 100644 --- a/rebar.lock +++ b/rebar.lock @@ -91,12 +91,12 @@ 0}, {<<"opentelemetry_experimental">>, {git_subdir,"https://github.com/valitydev/opentelemetry-erlang.git", - {ref,"685389b35fb188166e072c389a487a8e5a9f0804"}, + {ref,"ddf1efb45e3d2f334ff4b78f0d482f2ab9d32428"}, "apps/opentelemetry_experimental"}, 0}, {<<"opentelemetry_exporter">>, {git_subdir,"https://github.com/valitydev/opentelemetry-erlang.git", - {ref,"685389b35fb188166e072c389a487a8e5a9f0804"}, + {ref,"ddf1efb45e3d2f334ff4b78f0d482f2ab9d32428"}, "apps/opentelemetry_exporter"}, 0}, {<<"parse_trans">>,{pkg,<<"parse_trans">>,<<"3.3.1">>},2}, From d67c9cfefcdd308221fda6c133d38e0eb1d16004 Mon Sep 17 00:00:00 2001 From: Aleksey Kashapov Date: Wed, 25 Mar 2026 16:48:26 +0300 Subject: [PATCH 2/4] Bumps OTel lib and updates config accordingly --- apps/hellgate/src/hellgate.erl | 20 ++++++++++--------- apps/hellgate/test/hg_invoice_tests_SUITE.erl | 4 +++- rebar.lock | 10 +++++----- 3 files changed, 19 insertions(+), 15 deletions(-) diff --git a/apps/hellgate/src/hellgate.erl b/apps/hellgate/src/hellgate.erl index b7ad3344..a9443de8 100644 --- a/apps/hellgate/src/hellgate.erl +++ b/apps/hellgate/src/hellgate.erl @@ -133,19 +133,21 @@ ensure_otel_log_handler() -> MaxQueue = application:get_env(hellgate, otel_log_max_queue_size, 2048), DelayMs = application:get_env(hellgate, otel_log_scheduled_delay_ms, 1000), TimeoutMs = application:get_env(hellgate, otel_log_exporting_timeout_ms, 300000), - LogLevel = application:get_env(hellgate, otel_log_level, info), + LogLevel = application:get_env(hellgate, otel_log_level, debug), LoggerHandlerConfig = #{ level => LogLevel, filter_default => log, filters => [{hg_otel_trace_id_bytes, {fun hg_otel_log_filter:filter/2, undefined}}], - exporter => - {otel_exporter_logs_otlp, #{ - protocol => http_protobuf, - ssl_options => [] - }}, - max_queue_size => MaxQueue, - scheduled_delay_ms => DelayMs, - exporting_timeout_ms => TimeoutMs + config => #{ + exporter => + {otel_exporter_logs_otlp, #{ + protocol => http_protobuf, + ssl_options => [] + }}, + max_queue_size => MaxQueue, + scheduled_delay_ms => DelayMs, + exporting_timeout_ms => TimeoutMs + } }, case logger:add_handler(otel_logs, otel_log_handler, LoggerHandlerConfig) of ok -> diff --git a/apps/hellgate/test/hg_invoice_tests_SUITE.erl b/apps/hellgate/test/hg_invoice_tests_SUITE.erl index 3661553f..cccd846d 100644 --- a/apps/hellgate/test/hg_invoice_tests_SUITE.erl +++ b/apps/hellgate/test/hg_invoice_tests_SUITE.erl @@ -499,7 +499,9 @@ groups() -> -spec init_per_suite(config()) -> config(). init_per_suite(C) -> - % ok = logger:set_primary_config(level, debug), + %% NOTE Comment out primary logger's level change to revert to default + %% verbosity of info level. + ok = logger:set_primary_config(level, debug), % _ = dbg:tracer(), % _ = dbg:p(all, c), % _ = dbg:tpl({'hg_invoice_payment', 'p', '_'}, x), diff --git a/rebar.lock b/rebar.lock index 8aeefdce..c8902e45 100644 --- a/rebar.lock +++ b/rebar.lock @@ -91,12 +91,12 @@ 0}, {<<"opentelemetry_experimental">>, {git_subdir,"https://github.com/valitydev/opentelemetry-erlang.git", - {ref,"ddf1efb45e3d2f334ff4b78f0d482f2ab9d32428"}, + {ref,"4f3f219ae8dda86259346b622b3d13b841fceeb9"}, "apps/opentelemetry_experimental"}, 0}, {<<"opentelemetry_exporter">>, {git_subdir,"https://github.com/valitydev/opentelemetry-erlang.git", - {ref,"ddf1efb45e3d2f334ff4b78f0d482f2ab9d32428"}, + {ref,"4f3f219ae8dda86259346b622b3d13b841fceeb9"}, "apps/opentelemetry_exporter"}, 0}, {<<"parse_trans">>,{pkg,<<"parse_trans">>,<<"3.3.1">>},2}, @@ -132,7 +132,7 @@ {ref,"3a60e5dc5bbd709495024f26e100b041c3547fd9"}}, 1}, {<<"tls_certificate_check">>, - {pkg,<<"tls_certificate_check">>,<<"1.31.0">>}, + {pkg,<<"tls_certificate_check">>,<<"1.32.0">>}, 1}, {<<"unicode_util_compat">>,{pkg,<<"unicode_util_compat">>,<<"0.7.1">>},2}, {<<"woody">>, @@ -172,7 +172,7 @@ {<<"ranch">>, <<"8C7A100A139FD57F17327B6413E4167AC559FBC04CA7448E9BE9057311597A1D">>}, {<<"recon">>, <<"CBA53FA8DB83AD968C9A652E09C3ED7DDCC4DA434F27C3EAA9CA47FFB2B1FF03">>}, {<<"ssl_verify_fun">>, <<"354C321CF377240C7B8716899E182CE4890C5938111A1296ADD3EC74CF1715DF">>}, - {<<"tls_certificate_check">>, <<"9A910B54D8CB96CC810CABF4C0129F21360F82022B20180849F1442A25CCBB04">>}, + {<<"tls_certificate_check">>, <<"A9BA9F1EA59F6728F564BC990047B56539C48F17866C2DEFA51D3C872A8DCDF6">>}, {<<"unicode_util_compat">>, <<"A48703A25C170EEDADCA83B11E88985AF08D35F37C6F664D6DCFB106A97782FC">>}]}, {pkg_hash_ext,[ {<<"accept">>, <<"CA69388943F5DAD2E7232A5478F16086E3C872F48E32B88B378E1885A59F5649">>}, @@ -206,6 +206,6 @@ {<<"ranch">>, <<"49FBCFD3682FAB1F5D109351B61257676DA1A2FDBE295904176D5E521A2DDFE5">>}, {<<"recon">>, <<"2C7523C8DEE91DFF41F6B3D63CBA2BD49EB6D2FE5BF1EEC0DF7F87EB5E230E1C">>}, {<<"ssl_verify_fun">>, <<"FE4C190E8F37401D30167C8C405EDA19469F34577987C76DDE613E838BBC67F8">>}, - {<<"tls_certificate_check">>, <<"9D2B41B128D5507BD8AD93E1A998E06D0AB2F9A772AF343F4C00BF76C6BE1532">>}, + {<<"tls_certificate_check">>, <<"38E38DB768244D808E11ED27F812E7D927EA5F999007B07D0473DB44D7F7CC51">>}, {<<"unicode_util_compat">>, <<"B3A917854CE3AE233619744AD1E0102E05673136776FB2FA76234F3E03B23642">>}]} ]. From 04a72feafc7bf6aef62c36006476a97d9bcdc0e4 Mon Sep 17 00:00:00 2001 From: Aleksey Kashapov Date: Thu, 26 Mar 2026 14:26:56 +0300 Subject: [PATCH 3/4] Bumps otel logs exporter and removes unnecessary log filter --- apps/hellgate/src/hellgate.erl | 2 - apps/hellgate/src/hg_otel_log_filter.erl | 43 ------------------- rebar.lock | 4 +- .../provisioning/datasources/datasources.yaml | 2 +- 4 files changed, 3 insertions(+), 48 deletions(-) delete mode 100644 apps/hellgate/src/hg_otel_log_filter.erl diff --git a/apps/hellgate/src/hellgate.erl b/apps/hellgate/src/hellgate.erl index a9443de8..bec4980f 100644 --- a/apps/hellgate/src/hellgate.erl +++ b/apps/hellgate/src/hellgate.erl @@ -136,8 +136,6 @@ ensure_otel_log_handler() -> LogLevel = application:get_env(hellgate, otel_log_level, debug), LoggerHandlerConfig = #{ level => LogLevel, - filter_default => log, - filters => [{hg_otel_trace_id_bytes, {fun hg_otel_log_filter:filter/2, undefined}}], config => #{ exporter => {otel_exporter_logs_otlp, #{ diff --git a/apps/hellgate/src/hg_otel_log_filter.erl b/apps/hellgate/src/hg_otel_log_filter.erl deleted file mode 100644 index f61aa9e2..00000000 --- a/apps/hellgate/src/hg_otel_log_filter.erl +++ /dev/null @@ -1,43 +0,0 @@ -%%% @doc -%%% Logger filter для otel_logs handler: конвертирует otel_trace_id и otel_span_id -%%% из hex-формата (32/16 символов) в raw bytes (16/8 байт), как требует OTLP LogRecord. -%%% opentelemetry hex_span_ctx возвращает hex, collector ожидает bytes. -%%% @end --module(hg_otel_log_filter). - --export([filter/2]). - --spec filter(logger:log_event(), term()) -> logger:filter_return(). -filter(#{meta := Meta} = LogEvent, _FilterConfig) -> - LogEvent#{meta := convert_otel_ids(Meta)}. - -%% Конвертируем hex -> raw bytes только если формат hex (32/16 символов). -%% OTLP LogRecord: trace_id=16 bytes, span_id=8 bytes. -convert_otel_ids(#{otel_trace_id := TraceIdHex, otel_span_id := SpanIdHex} = Meta) -> - case {hex_to_trace_id_bytes(TraceIdHex), hex_to_span_id_bytes(SpanIdHex)} of - {TraceIdBytes, SpanIdBytes} when TraceIdBytes =/= undefined, SpanIdBytes =/= undefined -> - Meta#{otel_trace_id => TraceIdBytes, otel_span_id => SpanIdBytes}; - _ -> - %% Некорректный формат — убираем, чтобы otel_otlp_logs не отправил в OTLP - maps:without([otel_trace_id, otel_span_id, otel_trace_flags], Meta) - end; -convert_otel_ids(Meta) -> - Meta. - -hex_to_trace_id_bytes(Hex) when is_binary(Hex), byte_size(Hex) =:= 32 -> - try - <<(binary_to_integer(Hex, 16)):128>> - catch - _:_ -> undefined - end; -hex_to_trace_id_bytes(_) -> - undefined. - -hex_to_span_id_bytes(Hex) when is_binary(Hex), byte_size(Hex) =:= 16 -> - try - <<(binary_to_integer(Hex, 16)):64>> - catch - _:_ -> undefined - end; -hex_to_span_id_bytes(_) -> - undefined. diff --git a/rebar.lock b/rebar.lock index c8902e45..a7b1cf92 100644 --- a/rebar.lock +++ b/rebar.lock @@ -91,12 +91,12 @@ 0}, {<<"opentelemetry_experimental">>, {git_subdir,"https://github.com/valitydev/opentelemetry-erlang.git", - {ref,"4f3f219ae8dda86259346b622b3d13b841fceeb9"}, + {ref,"8c87f66a123dc5046327716aff346f2f4800a5db"}, "apps/opentelemetry_experimental"}, 0}, {<<"opentelemetry_exporter">>, {git_subdir,"https://github.com/valitydev/opentelemetry-erlang.git", - {ref,"4f3f219ae8dda86259346b622b3d13b841fceeb9"}, + {ref,"8c87f66a123dc5046327716aff346f2f4800a5db"}, "apps/opentelemetry_exporter"}, 0}, {<<"parse_trans">>,{pkg,<<"parse_trans">>,<<"3.3.1">>},2}, diff --git a/test/tracing/grafana/provisioning/datasources/datasources.yaml b/test/tracing/grafana/provisioning/datasources/datasources.yaml index d89d5448..39b979d1 100644 --- a/test/tracing/grafana/provisioning/datasources/datasources.yaml +++ b/test/tracing/grafana/provisioning/datasources/datasources.yaml @@ -13,7 +13,7 @@ datasources: # По structured metadata (Fields) — trace_id из OTLP не в теле лога - name: trace_id matcherType: label - matcherRegex: '^trace_id$' + matcherRegex: '^otel_trace_id$' datasourceUid: tempo url: '$${__value.raw}' urlDisplayLabel: 'View Trace' From f81e7f1bbaacc38cb36e4c185aa2ae6309090748 Mon Sep 17 00:00:00 2001 From: Aleksey Kashapov Date: Thu, 26 Mar 2026 17:07:15 +0300 Subject: [PATCH 4/4] Fixes charlist in party client's span events --- apps/hellgate/test/hg_ct_helper.erl | 2 +- config/sys.config | 2 +- rebar.lock | 4 ++-- .../tracing/grafana/provisioning/datasources/datasources.yaml | 2 +- 4 files changed, 5 insertions(+), 5 deletions(-) diff --git a/apps/hellgate/test/hg_ct_helper.erl b/apps/hellgate/test/hg_ct_helper.erl index 7edfcfd0..6e453f8c 100644 --- a/apps/hellgate/test/hg_ct_helper.erl +++ b/apps/hellgate/test/hg_ct_helper.erl @@ -216,7 +216,7 @@ start_app(party_client = AppName) -> { start_app(AppName, [ {services, #{ - party_management => "http://party-management:8022/v1/processing/partymgmt" + party_management => <<"http://party-management:8022/v1/processing/partymgmt">> }}, {woody, #{ % disabled | safe | aggressive diff --git a/config/sys.config b/config/sys.config index 39baf969..4b727f71 100644 --- a/config/sys.config +++ b/config/sys.config @@ -171,7 +171,7 @@ {party_client, [ {services, #{ - party_management => "http://party-management:8022/v1/processing/partymgmt" + party_management => <<"http://party-management:8022/v1/processing/partymgmt">> }}, {woody, #{ % disabled | safe | aggressive diff --git a/rebar.lock b/rebar.lock index a7b1cf92..94f4b53f 100644 --- a/rebar.lock +++ b/rebar.lock @@ -91,12 +91,12 @@ 0}, {<<"opentelemetry_experimental">>, {git_subdir,"https://github.com/valitydev/opentelemetry-erlang.git", - {ref,"8c87f66a123dc5046327716aff346f2f4800a5db"}, + {ref,"21c41d1eb6dffb95d51c4b1cd89b38eae00fc08a"}, "apps/opentelemetry_experimental"}, 0}, {<<"opentelemetry_exporter">>, {git_subdir,"https://github.com/valitydev/opentelemetry-erlang.git", - {ref,"8c87f66a123dc5046327716aff346f2f4800a5db"}, + {ref,"21c41d1eb6dffb95d51c4b1cd89b38eae00fc08a"}, "apps/opentelemetry_exporter"}, 0}, {<<"parse_trans">>,{pkg,<<"parse_trans">>,<<"3.3.1">>},2}, diff --git a/test/tracing/grafana/provisioning/datasources/datasources.yaml b/test/tracing/grafana/provisioning/datasources/datasources.yaml index 39b979d1..d89d5448 100644 --- a/test/tracing/grafana/provisioning/datasources/datasources.yaml +++ b/test/tracing/grafana/provisioning/datasources/datasources.yaml @@ -13,7 +13,7 @@ datasources: # По structured metadata (Fields) — trace_id из OTLP не в теле лога - name: trace_id matcherType: label - matcherRegex: '^otel_trace_id$' + matcherRegex: '^trace_id$' datasourceUid: tempo url: '$${__value.raw}' urlDisplayLabel: 'View Trace'