TD-686: Adds scoper handler OTel-instrumentalisation (#6)

* Revives CI
* Adds disregard of optional dependency during xref check
* Allows to pass meta to span on scope creation
* Updates woody handler test

.github/workflows/basic-linters.yml

@@ -0,0 +1,10 @@
+name: Vality basic linters
+
+on:
+  pull_request:
+    branches:
+      - "*"
+
+jobs:
+  lint:
+    uses: valitydev/base-workflows/.github/workflows/basic-linters.yml@v1

.github/workflows/erlang-checks.yml

@@ -30,7 +30,7 @@ jobs:
   run:
     name: Run checks
     needs: setup
-    uses: valitydev/erlang-workflows/.github/workflows/erlang-parallel-build.yml@v1.0.3
+    uses: valitydev/erlang-workflows/.github/workflows/erlang-parallel-build.yml@v1.0.12
     with:
       otp-version: ${{ needs.setup.outputs.otp-version }}
       rebar-version: ${{ needs.setup.outputs.rebar-version }}

rebar.config

@@ -25,7 +25,10 @@
 ]}.
 
 %% Common project dependencies.
-{deps, []}.
+{deps, [
+    {genlib, {git, "https://github.com/valitydev/genlib.git", {branch, "master"}}},
+    {opentelemetry_api, "1.2.1"}
+]}.
 
 %% XRef checks
 {xref_checks, [
@@ -55,7 +58,7 @@
     {test, [
         {cover_enabled, true},
         {plugins, [
-            {rebar3_thrift_compiler, {git, "https://github.com/rbkmoney/rebar3_thrift_compiler.git", {tag, "0.4"}}}
+            {rebar3_thrift_compiler, {git, "https://github.com/valitydev/rebar3_thrift_compiler.git", {tag, "0.3.1"}}}
         ]},
         {thrift_compiler_opts, [
             {in_dir, "test"},
@@ -72,8 +75,9 @@
         ]},
         {deps, [
             {lager, "3.9.2"},
-            {genlib, {git, "https://github.com/rbkmoney/genlib.git", {branch, "master"}}},
-            {woody, {git, "https://github.com/rbkmoney/woody_erlang.git", {branch, "master"}}}
+            {genlib, {git, "https://github.com/valitydev/genlib.git", {branch, "master"}}},
+            {woody, {git, "https://github.com/valitydev/woody_erlang.git", {branch, "master"}}},
+            {opentelemetry, "1.3.0"}
         ]},
         {dialyzer, [
             {plt_extra_apps, [
@@ -82,13 +86,14 @@
                 genlib,
                 snowflake,
                 common_test,
-                public_key
+                public_key,
+                opentelemetry
             ]}
         ]}
     ]}
 ]}.
 
-{project_plugins, [
+{plugins, [
     {rebar3_lint, "1.0.1"},
     {erlfmt, "1.0.0"},
     {covertool, "2.0.4"}

rebar.lock

@@ -1 +1,17 @@
-[].
+{"1.2.0",
+[{<<"genlib">>,
+  {git,"https://github.com/valitydev/genlib.git",
+       {ref,"f6074551d6586998e91a97ea20acb47241254ff3"}},
+  0},
+ {<<"opentelemetry_api">>,{pkg,<<"opentelemetry_api">>,<<"1.2.1">>},0},
+ {<<"opentelemetry_semantic_conventions">>,
+  {pkg,<<"opentelemetry_semantic_conventions">>,<<"0.2.0">>},
+  1}]}.
+[
+{pkg_hash,[
+ {<<"opentelemetry_api">>, <<"7B69ED4F40025C005DE0B74FCE8C0549625D59CB4DF12D15C32FE6DC5076FF42">>},
+ {<<"opentelemetry_semantic_conventions">>, <<"B67FE459C2938FCAB341CB0951C44860C62347C005ACE1B50F8402576F241435">>}]},
+{pkg_hash_ext,[
+ {<<"opentelemetry_api">>, <<"6D7A27B7CAD2AD69A09CABF6670514CAFCEC717C8441BEB5C96322BAC3D05350">>},
+ {<<"opentelemetry_semantic_conventions">>, <<"D61FA1F5639EE8668D74B527E6806E0503EFC55A42DB7B5F39939D84C07D6895">>}]}
+].

src/scoper.app.src

@@ -4,7 +4,9 @@
     {registered, []},
     {applications, [
         kernel,
-        stdlib
+        stdlib,
+        genlib,
+        opentelemetry_api
     ]},
     {env, []},
     {modules, []},

src/scoper.erl

@@ -52,6 +52,7 @@ add_scope(Name, Meta) ->
             ok = error_logger:warning_msg("Scoper: attempt to add taken scope ~p; scopes: ~p", [Name, Scopes]);
         false ->
             set_scope_names([Name | Scopes]),
+            set_otel_span_attributes(Name, Meta),
             store(Name, Meta)
     end.
 
@@ -74,6 +75,7 @@ add_meta(Meta) when map_size(Meta) =:= 0 ->
 add_meta(Meta) ->
     try
         ScopeName = get_current_scope(),
+        set_otel_span_attributes(ScopeName, Meta),
         store(ScopeName, maps:merge(find(ScopeName), Meta))
     catch
         throw:{scoper, no_scopes} ->
@@ -143,3 +145,11 @@ find(Key) ->
 -spec delete(scope()) -> ok.
 delete(Key) ->
     scoper_storage:delete(Key).
+
+-spec set_otel_span_attributes(scope(), meta()) -> ok.
+set_otel_span_attributes(_Name, NewMeta) when map_size(NewMeta) =:= 0 ->
+    ok;
+set_otel_span_attributes(Name, NewMeta) ->
+    Attributes = genlib_map:flatten_join($., #{Name => NewMeta}),
+    _ = otel_span:set_attributes(otel_tracer:current_span_ctx(), Attributes),
+    ok.

src/scoper_woody_event_handler.erl

@@ -6,9 +6,10 @@
 %% woody_event_handler behaviour callbacks
 -export([handle_event/4]).
 
--ignore_xref([{woody_event_handler, format_event, 3}]).
--ignore_xref([{woody_event_handler, format_meta, 3}]).
--ignore_xref([{woody_event_handler, get_event_severity, 2}]).
+-ignore_xref({woody_event_handler, get_event_severity, 2}).
+-ignore_xref({woody_event_handler, format_meta, 3}).
+-ignore_xref({woody_event_handler, format_event, 3}).
+-ignore_xref({woody_event_handler_otel, handle_event, 4}).
 
 -type options() :: #{
     event_handler_opts => woody_event_handler:options()
@@ -24,27 +25,61 @@
     RpcId :: woody:rpc_id() | undefined,
     Meta :: woody_event_handler:event_meta(),
     Opts :: options().
+handle_event(Event, RpcId, Meta, Opts) ->
+    ok = before_event(Event, RpcId, Meta, Opts),
+    _ = handle_event_(Event, RpcId, Meta, Opts),
+    ok = after_event(Event, RpcId, Meta, Opts).
+
+%% Otel wraps
+
+-define(IS_START_EVENT(Event),
+    (Event =:= 'client begin' orelse
+        Event =:= 'call service' orelse
+        Event =:= 'client send' orelse
+        Event =:= 'client resolve begin' orelse
+        Event =:= 'client cache begin' orelse
+        Event =:= 'server receive' orelse
+        Event =:= 'invoke service handler')
+).
+
+-define(IS_SPECIAL_EVENT(Event),
+    (Event =:= 'internal error' orelse
+        Event =:= 'trace event')
+).
+
+before_event(Event, RpcId, Meta, Opts) when ?IS_START_EVENT(Event) orelse ?IS_SPECIAL_EVENT(Event) ->
+    woody_event_handler_otel:handle_event(Event, RpcId, Meta, Opts);
+before_event(_Event, _RpcId, _Meta, _Opts) ->
+    ok.
+
+after_event(Event, RpcId, Meta, Opts) when not (?IS_START_EVENT(Event) orelse ?IS_SPECIAL_EVENT(Event)) ->
+    woody_event_handler_otel:handle_event(Event, RpcId, Meta, Opts);
+after_event(_Event, _RpcId, _Meta, _Opts) ->
+    ok.
+
+%% Scope handling
+
 %% client scoping
-handle_event('client begin', _RpcID, _Meta, _Opts) ->
+handle_event_('client begin', _RpcID, _Meta, _Opts) ->
     scoper:add_scope(get_scope_name(client));
-handle_event('client cache begin', _RpcID, _Meta, _Opts) ->
+handle_event_('client cache begin', _RpcID, _Meta, _Opts) ->
     scoper:add_scope(get_scope_name(caching_client));
-handle_event('client end', _RpcID, _Meta, _Opts) ->
+handle_event_('client end', _RpcID, _Meta, _Opts) ->
     scoper:remove_scope();
-handle_event('client cache end', _RpcID, _Meta, _Opts) ->
+handle_event_('client cache end', _RpcID, _Meta, _Opts) ->
     scoper:remove_scope();
 %% server scoping
-handle_event(Event = 'server receive', RpcID, RawMeta, Opts) ->
+handle_event_(Event = 'server receive', RpcID, RawMeta, Opts) ->
     ok = add_server_meta(RpcID),
     do_handle_event(Event, RpcID, RawMeta, Opts);
-handle_event(Event = 'server send', RpcID, RawMeta, Opts) ->
+handle_event_(Event = 'server send', RpcID, RawMeta, Opts) ->
     ok = do_handle_event(Event, RpcID, RawMeta, Opts),
     remove_server_meta();
 %% special cases
-handle_event(Event = 'internal error', RpcID, RawMeta, Opts) ->
+handle_event_(Event = 'internal error', RpcID, RawMeta, Opts) ->
     ok = do_handle_event(Event, RpcID, RawMeta, Opts),
     final_error_cleanup(RawMeta);
-handle_event(Event = 'trace event', RpcID, RawMeta = #{role := Role}, Opts) ->
+handle_event_(Event = 'trace event', RpcID, RawMeta = #{role := Role}, Opts) ->
     case lists:member(get_scope_name(Role), scoper:get_scope_names()) of
         true ->
             do_handle_event(Event, RpcID, RawMeta, Opts);
@@ -55,7 +90,7 @@ handle_event(Event = 'trace event', RpcID, RawMeta = #{role := Role}, Opts) ->
             )
     end;
 %% the rest
-handle_event(Event, RpcID, RawMeta, Opts) ->
+handle_event_(Event, RpcID, RawMeta, Opts) ->
     do_handle_event(Event, RpcID, RawMeta, Opts).
 
 %%

test/scoper_event_handler_SUITE.erl

@@ -2,6 +2,8 @@
 
 -include_lib("common_test/include/ct.hrl").
 -include_lib("stdlib/include/assert.hrl").
+-include_lib("opentelemetry_api/include/opentelemetry.hrl").
+-include_lib("opentelemetry/include/otel_span.hrl").
 
 -export([all/0]).
 -export([init_per_suite/1]).
@@ -33,6 +35,8 @@ all() ->
 -spec init_per_suite(config()) -> config().
 init_per_suite(C) ->
     {ok, Apps1} = application:ensure_all_started(scoper),
+    ok = application:set_env([{opentelemetry, [{span_processor, simple}]}]),
+    ok = application:start(opentelemetry),
     {ok, Apps2} = application:ensure_all_started(woody),
     ok = logger:set_primary_config(level, debug),
     [{apps, Apps1 ++ Apps2} | C].
@@ -60,6 +64,7 @@ handler_logs_events(_C) ->
     %% NOTE
     %% Test that scoper properly handles woody events.
     %% The purpose is to catch regressions early against woody master.
+    ok = otel_simple_processor:set_exporter(otel_exporter_pid, self()),
     ServerId = ?FUNCTION_NAME,
     HandlerId = ?FUNCTION_NAME,
     {ok, Pid, Url} = start_woody_server(ServerId),
@@ -73,6 +78,7 @@ handler_logs_events(_C) ->
     {ok, #'GeneratedID'{}} = call_woody_service('GenerateID', {{snowflake, #'SnowflakeSchema'{}}}, Url),
     ok = stop_woody_server(Pid),
     ok = logger:remove_handler(HandlerId),
+    {Logs, Spans} = discriminate_msg(flush_msg_queue(1000)),
     ?assertMatch(
         [
             {relay, HandlerId, started},
@@ -156,9 +162,38 @@ handler_logs_events(_C) ->
                 })},
             {relay, HandlerId, terminated}
         ],
-        flush_msg_queue(1000)
+        Logs
+    ),
+    ?assertMatch(
+        [
+            {span, #span{
+                trace_id = TraceId,
+                parent_span_id = SpanId,
+                name = <<"server Generator:GenerateID">>,
+                kind = ?SPAN_KIND_SERVER
+            }},
+            {span, #span{
+                trace_id = TraceId,
+                span_id = SpanId,
+                name = <<"client Generator:GenerateID">>,
+                kind = ?SPAN_KIND_CLIENT
+            }}
+        ],
+        Spans
     ).
 
+discriminate_msg(Messages) ->
+    {Logs, Spans} = lists:foldl(
+        fun
+            ({span, _} = M, {L, S}) -> {L, [M | S]};
+            ({relay, handler_logs_events, _} = M, {L, S}) -> {[M | L], S};
+            (_M, {L, S}) -> {L, S}
+        end,
+        {[], []},
+        Messages
+    ),
+    {lists:reverse(Logs), lists:reverse(Spans)}.
+
 flush_msg_queue(Timeout) ->
     receive
         M -> [M | flush_msg_queue(Timeout)]