hb_event.erl - Event Logging & Prometheus Metrics

Overview

Purpose: Event logging, debugging, and Prometheus counter integration
Module: hb_event
Metrics: Prometheus counter-based event tracking
Pattern: Process-based event aggregation with caching

This module provides event logging and metric collection for HyperBEAM. It wraps Prometheus counters with intelligent filtering, caching, and overload protection while maintaining high performance through process dictionary optimization.

Event System

Events in HyperBEAM serve dual purposes:

Debugging: Conditional printing to console based on topic filters
Metrics: Prometheus counter increments for operational monitoring

The system automatically aggregates events by topic and name, avoiding performance overhead for high-frequency events.

Dependencies

Metrics: prometheus_counter
HyperBEAM: hb_opts, hb_format, hb_name, hb_message, hb_test_utils
Erlang/OTP: ets

Public Functions Overview

%% Event Logging
-spec log(X) -> X.
-spec log(Topic, X) -> X.
-spec log(Topic, X, Mod) -> X.
-spec log(Topic, X, Mod, Func) -> X.
-spec log(Topic, X, Mod, Func, Line) -> X.
-spec log(Topic, X, Mod, Func, Line, Opts) -> X.
 
%% Counter Management
-spec increment(Topic, Message, Opts) -> ignored | tuple().
-spec increment(Topic, Message, Opts, Count) -> ignored | tuple().
-spec increment_callers(Topic) -> ok.
 
%% Counter Queries
-spec counters() -> Counters :: map().
-spec diff(Fun) -> {Diff :: map(), Result :: term()}.
-spec diff(Fun, Opts) -> {Diff :: map(), Result :: term()}.

Public Functions

1. log/1 through log/6

-spec log(X) -> X.
-spec log(Topic, X) -> X.
-spec log(Topic, X, Mod) -> X.
-spec log(Topic, X, Mod, Func) -> X.
-spec log(Topic, X, Mod, Func, Line) -> X.
-spec log(Topic, X, Mod, Func, Line, Opts) -> X
    when
        Topic :: atom() | binary(),
        X :: term(),
        Mod :: atom() | string(),
        Func :: atom() | string(),
        Line :: integer() | string(),
        Opts :: map().

Description: Log an event with optional topic, module, function, and line information. Conditionally prints to console based on debug_print option. Always returns the logged value unchanged (allowing inline usage). Increments Prometheus counters.

Test Code:

-module(hb_event_log_test).
-include_lib("eunit/include/eunit.hrl").
 
log_simple_test() ->
    Value = <<"test data">>,
    Result = hb_event:log(Value),
    ?assertEqual(Value, Result).
 
log_with_topic_test() ->
    Value = {test_event, 123},
    Result = hb_event:log(test_topic, Value),
    ?assertEqual(Value, Result).
 
log_with_module_test() ->
    Value = <<"event">>,
    Result = hb_event:log(topic, Value, test_module),
    ?assertEqual(Value, Result).
 
log_full_test() ->
    Value = {complex, event, [data]},
    Result = hb_event:log(
        test_topic,
        Value,
        test_module,
        test_function,
        42,
        #{}
    ),
    ?assertEqual(Value, Result).
 
log_inline_usage_test() ->
    % Log can be used inline in expressions
    Result = 
        case hb_event:log(calculation, {step, 1}) of
            {step, N} -> N * 2
        end,
    ?assertEqual(2, Result).
 
log_with_debug_print_test() ->
    Opts = #{debug_print => [test_topic]},
    Value = <<"printed">>,
    Result = hb_event:log(test_topic, Value, test_mod, undefined, undefined, Opts),
    ?assertEqual(Value, Result).

2. increment/3, increment/4

-spec increment(Topic, Message, Opts) -> ignored | tuple()
    when
        Topic :: atom() | binary(),
        Message :: term(),
        Opts :: map().
 
-spec increment(Topic, Message, Opts, Count) -> ignored | tuple()
    when
        Topic :: atom() | binary(),
        Message :: term(),
        Opts :: map(),
        Count :: integer().

Description: Increment Prometheus counter for topic and message. Filters out high-frequency topics to avoid performance costs. Spawns event server if needed. Returns ignored for filtered topics, otherwise returns the sent message tuple.

Filtered Topics (always ignored):

global
ao_core
ao_internal
ao_devices
ao_subresolution
signature_base
id_base
parsing

Test Code:

-module(hb_event_increment_test).
-include_lib("eunit/include/eunit.hrl").
 
increment_basic_test() ->
    % Non-filtered topics return the sent message tuple
    Result = hb_event:increment(test_topic, {event, 1}, #{}),
    ?assertMatch({increment, _, _, _}, Result).
 
increment_with_count_test() ->
    Result = hb_event:increment(test_topic, {event, 2}, #{}, 5),
    ?assertMatch({increment, _, _, 5}, Result).
 
increment_filtered_topic_test() ->
    Result = hb_event:increment(global, {event, 3}, #{}),
    ?assertEqual(ignored, Result).
 
increment_ao_core_filtered_test() ->
    Result = hb_event:increment(ao_core, {event, 4}, #{}),
    ?assertEqual(ignored, Result).
 
increment_debug_prefix_ignored_test() ->
    Result = hb_event:increment(test, {debug_something, 5}, #{}),
    ?assertEqual(ignored, Result).
 
increment_multiple_test() ->
    hb_event:increment(test_topic, {event, 1}, #{}),
    hb_event:increment(test_topic, {event, 2}, #{}),
    hb_event:increment(test_topic, {event, 1}, #{}),
    
    % counters/0 requires prometheus - may fail without it
    case catch hb_event:counters() of
        {'EXIT', _} -> ok;  % Prometheus not running
        Counters -> ?assert(is_map(Counters))
    end.

3. increment_callers/1, increment_callers/2

-spec increment_callers(Topic) -> ok
    when
        Topic :: atom() | binary().
 
-spec increment_callers(Topic, Type) -> ok
    when
        Topic :: atom() | binary(),
        Type :: erlang | process.

Description: Increment counters for call paths and individual callers. EXTREMELY EXPENSIVE - generates stacktrace. Only use in development. Creates two counter types:

{Topic}-call-paths: Full call stack traces
{Topic}-callers: Individual calling functions

Test Code:

-module(hb_event_callers_test).
-include_lib("eunit/include/eunit.hrl").
 
increment_callers_test() ->
    % Warning: Expensive operation - generates stacktrace
    hb_event:increment_callers(test_profile),
    ?assert(true).  % Just test it doesn't crash
 
increment_callers_erlang_test() ->
    hb_event:increment_callers(test_erlang, erlang),
    ?assert(true).
 
increment_callers_process_test() ->
    hb_event:increment_callers(test_process, process),
    ?assert(true).

4. counters/0

-spec counters() -> Counters
    when
        Counters :: map().

Description: Return aggregated event counters as a nested map structure: #{Topic => #{Event => Count}}.

Test Code:

-module(hb_event_counters_test).
-include_lib("eunit/include/eunit.hrl").
 
counters_basic_test() ->
    % counters/0 requires prometheus ETS table
    case catch hb_event:counters() of
        {'EXIT', _} -> ok;  % Prometheus not running
        Counters -> ?assert(is_map(Counters))
    end.
 
counters_structure_test() ->
    hb_event:increment(test_topic, {event1, data}, #{}),
    hb_event:increment(test_topic, {event2, data}, #{}),
    
    case catch hb_event:counters() of
        {'EXIT', _} -> ok;  % Prometheus not running
        Counters ->
            ?assert(is_map(Counters)),
            case maps:get(<<"test_topic">>, Counters, undefined) of
                undefined -> ?assert(true);  % May be filtered
                TopicMap -> ?assert(is_map(TopicMap))
            end
    end.

5. diff/1, diff/2

-spec diff(Fun) -> {Diff, Result}
    when
        Fun :: fun(() -> term()),
        Diff :: map(),
        Result :: term().
 
-spec diff(Fun, Opts) -> {Diff, Result}
    when
        Fun :: fun(() -> term()),
        Opts :: map(),
        Diff :: map(),
        Result :: term().

Description: Execute function and return the difference in event counters before and after execution, along with function result. Useful for profiling event generation.

Test Code:

-module(hb_event_diff_test).
-include_lib("eunit/include/eunit.hrl").
 
diff_basic_test() ->
    Fun = fun() ->
        hb_event:increment(test, {action, 1}, #{}),
        <<"result">>
    end,
    
    % diff/1 uses counters/0 which requires prometheus
    case catch hb_event:diff(Fun) of
        {'EXIT', _} -> ok;  % Prometheus not running
        {Diff, Result} ->
            ?assertEqual(<<"result">>, Result),
            ?assert(is_map(Diff))
    end.
 
diff_with_opts_test() ->
    Fun = fun() ->
        hb_event:increment(test, {action, 2}, #{}),
        42
    end,
    
    case catch hb_event:diff(Fun, #{}) of
        {'EXIT', _} -> ok;
        {Diff, Result} ->
            ?assertEqual(42, Result),
            ?assert(is_map(Diff))
    end.

Common Patterns

%% Simple event logging (inline usage)
Value = hb_event:log(calculation, {step, 1, result}),
% Value == {step, 1, result}
 
%% Conditional printing
Opts = #{debug_print => [http, ao_result]},
hb_event:log(http, {request, URL}, test_module, get, 42, Opts).
% Prints only if topic 'http' in debug_print list
 
%% Increment custom metric
hb_event:increment(my_topic, {operation, completed}, #{}).
 
%% Increment with count
hb_event:increment(my_topic, {batch, processed}, #{}, 100).
 
%% Profile event generation
{EventDiff, Result} = hb_event:diff(fun() ->
    process_messages(Messages),
    compute_result()
end).
% EventDiff shows which events were generated
 
%% Get current counters
AllCounters = hb_event:counters().
% #{
%   <<"topic1">> => #{
%       <<"event1">> => 42,
%       <<"event2">> => 17
%   },
%   ...
% }
 
%% Profile expensive call stack (development only!)
expensive_operation(),
hb_event:increment_callers(expensive_op).
% Records full call stack - VERY SLOW

Configuration

Debug Printing

Control which events print to console:

%% Print all events
Opts = #{debug_print => true}.
 
%% Print specific topics
Opts = #{debug_print => [http, ao_result, custom_topic]}.
 
%% No printing
Opts = #{debug_print => false}.  % or omit
 
%% Print specific modules
Opts = #{debug_print => [my_module]}.

Caching

Print decisions are cached in process dictionary:

% First check: looks up option
should_print(http, Opts).  % Checks opts, caches result
 
% Subsequent checks: uses cache
should_print(http, Opts).  % Returns cached result

Event Server

Architecture

%% Single event server per HyperBEAM instance
%% Registered name: hb_event
%% Manages Prometheus counter registration and increments
 
Server Process
    ↓
await prometheus_started()
    ↓
declare counters
    ↓
receive loop:
    {increment, Topic, Event, Count}
        → prometheus_counter:inc(...)
        → check queue length
        → handle_events()

Overload Protection

%% If message queue exceeds threshold (10,000 messages)
%% Randomly sample warnings to avoid flooding console
 
-define(OVERLOAD_QUEUE_LENGTH, 10000).
 
handle_events() ->
    receive
        {increment, Topic, Event, Count} ->
            case message_queue_len() of
                Len when Len > 10000 ->
                    % Random warning based on queue size
                    case rand:uniform(max(1000, Len - 10000)) of
                        1 -> print_warning(Len, Event);
                        _ -> ignored
                    end;
                _ -> ok
            end,
            prometheus_counter:inc(Event, [Topic, Event], Count)
    end.

Performance

Event Logging Overhead

%% Benchmark: ~1,000,000+ events/second on modern hardware
 
benchmark_event_test() ->
    Iterations = benchmark(fun() ->
        log(test_module, {test, 1})
    end),
    % Expected: >= 1,000 iterations/ms
    ?assert(Iterations >= 1000).

Print Lookup Caching

%% First lookup: Full option traversal
%% Subsequent lookups: O(1) process dictionary access
 
benchmark_print_lookup_test() ->
    Iterations = benchmark(fun() ->
        should_print(test_module, Opts)
    end),
    % Expected: >= 1,000 iterations/ms
    ?assert(Iterations >= 1000).

Increment Performance

%% Benchmark: ~1,000,000+ increments/second
 
benchmark_increment_test() ->
    Iterations = benchmark(fun() ->
        increment(test_module, {test, 1}, #{})
    end),
    ?assert(Iterations >= 1000).

Filtered Events

Always Ignored Topics

These high-frequency topics are always filtered to avoid performance costs:

increment(global, _, _, _) -> ignored;
increment(ao_core, _, _, _) -> ignored;
increment(ao_internal, _, _, _) -> ignored;
increment(ao_devices, _, _, _) -> ignored;
increment(ao_subresolution, _, _, _) -> ignored;
increment(signature_base, _, _, _) -> ignored;
increment(id_base, _, _, _) -> ignored;
increment(parsing, _, _, _) -> ignored;

Debug Prefix Filter

Events starting with "debug" are always ignored:

parse_name({debug_something, data}) -> <<"debug_something">> -> ignored.

Macros

Event Macro

%% Defined in include/hb.hrl
-define(event(X), hb_event:log(global, X, ?MODULE, ?FUNCTION_NAME, ?LINE)).
-define(event(Topic, X), hb_event:log(Topic, X, ?MODULE, ?FUNCTION_NAME, ?LINE)).
 
%% Usage in code
?event({operation, completed, Data}).
?event(http, {request, URL}).

Conditional Compilation

%% Define NO_EVENTS to disable all event logging
-ifdef(NO_EVENTS).
log(_) -> ok.
increment(_, _, _) -> ok.
-else.
% Normal implementation
-endif.

Prometheus Integration

Counter Schema

%% Prometheus counter declaration
prometheus_counter:declare([
    {name, <<"event">>},
    {help, <<"AO-Core execution events">>},
    {labels, [topic, event]}
]).
 
%% Counter access
%% Name: event
%% Labels: [topic, event]
%% Value: Count
 
%% Example counter:
%% event{topic="http",event="request"} = 42

Counter Aggregation

%% Raw ETS table format
{{default, <<"event">>, [Topic, Event], _}, Count, _}
 
%% Aggregated format (from counters/0)
#{
    Topic => #{
        Event => Count
    }
}

References

Prometheus - prometheus_counter documentation
HyperBEAM Formatting - hb_format.erl
Process Dictionary - Erlang caching strategy
ETS Tables - Prometheus counter storage

Notes

Return Value: log/X always returns logged value unchanged
Inline Usage: Can be used inline in expressions without disruption
Process Dictionary: Caches print decisions per process
Single Server: One event server per HyperBEAM instance
Overload Protection: Random sampling when queue exceeds 10,000
High Performance: ~1M+ events/second on modern hardware
Filtered Topics: Several high-frequency topics always ignored
Prometheus: Automatically registers and increments counters
Debug Prefix: Events starting with "debug" are ignored
Conditional Compilation: Can disable all events with NO_EVENTS flag
Expensive Operation: increment_callers generates stacktrace - development only
Event Diffing: diff/1,2 useful for profiling event generation
Topic Flexibility: Topics can be atoms or binaries
Message Queue: Monitor with Prometheus for system health
ETS Backend: Counters stored in prometheus_counter_table