Skip to content

Change logging API from push to pull #55

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
ziopio merged 9 commits into from
Feb 26, 2025
Merged

Change logging API from push to pull #55

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
e1ceffa
Change logging API from push to pull
sylane Feb 19, 2025
d35c4f7
Fix doc grammatical error
sylane Feb 25, 2025
fe1d2c0
Upgrade to grisp_cryptoauth 2.4.1
ziopio Feb 25, 2025
8328bf4
Update jarl version and add flags in grisp.ini
ziopio Feb 25, 2025
1bd3ae3
Prevent crash if grisp_connect log handler is not setup properly
sylane Feb 26, 2025
bbe9b19
Update log configuration in README
sylane Feb 26, 2025
94bbb0a
Upgrade jarl
ziopio Feb 26, 2025
03f811d
Cleanup changelog
ziopio Feb 26, 2025
3af007c
Fix yet another grammar error in the doc
sylane Feb 26, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
8 changes: 4 additions & 4 deletions CHANGELOG.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,10 @@ road for namespaces. foo.bar.Buz is parsed into [foo, bar, <<"Buz">>] (if foo
and bar are already existing atoms, but 'Buz' is not).
- Upgrade grisp dependency to 2.8.0.
- Add jittered exponential backoff for reconnection.
- Changed logging API from push to pull. Instead of the client (grisp_connect)
pushing batches of log event to the server (grisp.io), the server is now pulling
them with the request `log.get`. In order to synchronize the client ring buffer,
the server sends `log.sync` notifications.

## Fixed

Expand All @@ -45,8 +49,6 @@ disconnected from the server.

## [1.0.0] - 2024-09-26

### What's Changed

#### Added
- NTP handling
- Connect to GRiSP.io
Expand All @@ -57,8 +59,6 @@ disconnected from the server.
- Use grisp_cryptoauth TLS helper to generate TLS options.
- Start integrating grisp updater.

**Full Changelog**: https://github.com/grisp/grisp_connect/commits/1.0.0

[Unreleased]: https://github.com/grisp/grisp_connect/compare/1.1.0...HEAD
[1.1.0]: https://github.com/grisp/grisp_connect/compare/1.0.0...1.1.0
[1.0.0]: https://github.com/grisp/grisp_connect/compare/6b59d16383b3e5154ef839bcf5c77a6b770aada5...1.0.0
46 changes: 28 additions & 18 deletions README.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -153,34 +153,44 @@ grisp_connect sets the following options as default values if no `tls_server_tru
## See all Logs on GRiSP.io

Once this app is started, it forwards all logs to GRiSP.io without the need of setting up anything. The only logs that we do not catch are the ones generated before `grisp_connect` boots.
If you want to see ALL logs, even from applications that boot before `grisp_connect`, you need to disable the default logger handler and set the grisp_connect handler as the default one. This involves changing the `kernel` and `grisp_connect` app configuration settings in your sys.config file.
If you want to see ALL logs, even from applications that boot before `grisp_connect`, you need to add the log handler in the kernel configuration and disable the one defined in the `grisp_connect` application configuration. This involves changing the `kernel` and `grisp_connect` app configuration settings in your sys.config file.

You can copy paste these settings. Here we both swap the default logger handler with the grisp_connect logger handler and also request it to print logs to stdout.
You can copy paste these settings:

```erlang
% sys.config
[
{kernel, [
% Disable 'default' handler (which buffers all log events in logger).
{logger, [{handler, default, undefined}]}
]},
{grisp_connect,[
{logger_level, notice},
{logger, [
% Enable the grisp_connect handler as default,
% so that it will receive all events from boot
{handler,
default, % name
grisp_connect_logger_bin, % module
#{
formatter => {grisp_connect_logger_bin, #{
% To see logs printed on the USB serial appoint a logger
% formatter module of your choice and set the stdout
% configuration stdout => {Formatter, FormatterConfig}
stdout => {logger_formatter, #{}}
}}
{handler, default, logger_std_h, #{
level => notice,
filter_default => log,
filters => [
% Filter out supervisor progress reports so TLS certificates
% are not swamping the console if the level is set to info...
{disable_progress, {fun logger_filters:progress/2, stop}}
]
}}
{handler, grisp_connect_log_handler, grisp_connect_logger_bin, #{
level => notice,
filter_default => log,
formatter => {grisp_connect_logger_bin, #{}},
filters => [
% Filter out supervisor progress reports so TLS certificates
% are not swamping grisp.io if level is set to info...
{disable_progress, {fun logger_filters:progress/2, stop}}
]
}
}
]}
]},
{grisp_connect, [
% Disable the log handler defined in grisp_connect application default
% configuration, as it was explicitly started in kernel configuration
% in order to catch the log entries before grisp_connect is started.
{logger, []}
]}
]}
].
```
Expand Down
38 changes: 38 additions & 0 deletions docs/grisp_connect_api.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -137,6 +137,34 @@ This should only be called if the new software is functioning as expected.
</p>
</details>

<details><summary><code>log.get</code> - retrieve a batch of log entry from the device </summary>
<p>

**`params`:**
| key (required *) | value | description |
| ----------------- | -------- | -------------------------------------- |
| `"max_batch_size"`| integer | Maximum number of events in the result |
| `"max_byte_size"` | integer | Maximum byte size of the result |

**`result`**: JSON Object
| key(required *) | value | description |
|-----------------|----------------|-------------------------------|
| dropped * | integer | Number of dropped log entries |
| events * | list of Events | The list of log events |

**`event format`:**
Each log event is a list of two elements, first the sequence number of the
event, and then an object describing the log event with the following fields:
- `meta`: meta data of the log entry as an object:
- `time`: log time in microseconds.
- `file`: `null` or a filename as a string.
- `mfa`: `null` or the function the log is from as a list with module name
as a tring, function name as a string and arity as an integer.
- `msg`: the log entry message, either as a string, or as a json object if it
is a report entry.
- `level`: the log level as a string.


### Notifications

<details><summary><code>update</code> <code>{"type":"software_update_event"}</code> - notify the current progess of grisp_updater </summary>
Expand All @@ -154,6 +182,16 @@ This should only be called if the new software is functioning as expected.
</p>
</details>

<details><summary><code>log.sync</code> - synchronize the device log buffer, truncating the entries the server is aware of </summary>
<p>

**`params`:**
| key (required *) | value | description |
| ----------------- | -------- | ------------------------------------------------ |
| `"seq"` * | integer | The sequence number of the last stored log event |
| `"dropped"` * | integer | The number of "confirmed dropped log events |


## Error Codes

### Default error codes
Expand Down
2 changes: 0 additions & 2 deletions docs/grisp_connect_architecture.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,10 +6,8 @@ graph TD

subgraph GrispConnectApp[Grisp Connect Application]
GrispConnectRootSup[Root Supervisor<br>grisp_connect_sup]
GrispConnectLogServer[Log Server<br>grisp_connect_log_server]
GrispConnectClient[Client<br>grisp_connect_client]

GrispConnectRootSup --Supervise--> GrispConnectLogServer
GrispConnectRootSup --Supervise--> GrispConnectClient
GrispConnectClient --Spawn and Monitor--> JarlConnection
end
Expand Down
3 changes: 3 additions & 0 deletions grisp/grisp2/common/deploy/files/grisp.ini.mustache
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,8 @@
[erlang]
args = erl.rtems -C multi_time_warp -- -mode embedded -home . -pa . -root {{release_name}} -bindir {{release_name}}/erts-{{erts_vsn}}/bin -boot {{release_name}}/releases/{{release_version}}/start -config {{release_name}}/releases/{{release_version}}/sys.config -kernel inetrc "./erl_inetrc"
shell = erlang
on_exit = reboot
on_crash = reboot

[network]
ip_self=dhcp
Expand Down
2 changes: 1 addition & 1 deletion rebar.config
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
{erl_opts, [debug_info]}.
{deps, [
jsx,
{jarl, {git, "https://github.com/grisp/jarl.git"}},
jarl,
{grisp, "~> 2.7"},
{grisp_cryptoauth, "~> 2.4"},
{certifi, "2.13.0"}
Expand Down
13 changes: 6 additions & 7 deletions rebar.lock
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2,29 +2,28 @@
[{<<"certifi">>,{pkg,<<"certifi">>,<<"2.13.0">>},0},
{<<"cowlib">>,{pkg,<<"cowlib">>,<<"2.13.0">>},2},
{<<"grisp">>,{pkg,<<"grisp">>,<<"2.8.0">>},0},
{<<"grisp_cryptoauth">>,{pkg,<<"grisp_cryptoauth">>,<<"2.4.0">>},0},
{<<"grisp_cryptoauth">>,{pkg,<<"grisp_cryptoauth">>,<<"2.4.1">>},0},
{<<"gun">>,{pkg,<<"gun">>,<<"2.1.0">>},1},
{<<"jarl">>,
{git,"https://github.com/grisp/jarl.git",
{ref,"8d20c3ca314aa5c448d5e16f52a2b887e11b26f7"}},
0},
{<<"jarl">>,{pkg,<<"jarl">>,<<"1.0.1">>},0},
{<<"jsx">>,{pkg,<<"jsx">>,<<"3.1.0">>},0},
{<<"mapz">>,{pkg,<<"mapz">>,<<"2.4.0">>},1}]}.
[
{pkg_hash,[
{<<"certifi">>, <<"E52BE248590050B2DD33B0BB274B56678F9068E67805DCA8AA8B1CCDB016BBF6">>},
{<<"cowlib">>, <<"DB8F7505D8332D98EF50A3EF34B34C1AFDDEC7506E4EE4DD4A3A266285D282CA">>},
{<<"grisp">>, <<"E0B7D4C3464702DBD62A867EDE76488226B0772B29DF7DBAE4E08E474F2B81F5">>},
{<<"grisp_cryptoauth">>, <<"60773DFCB597893A1E98BFE2974A74C277D9FF6CE16BD918BFD906D43AAB86C0">>},
{<<"grisp_cryptoauth">>, <<"AA623B135F000E03DBA0FCBB64C08B5F31E29B1DAC2B4E7A106BAFCA3878141C">>},
{<<"gun">>, <<"B4E4CBBF3026D21981C447E9E7CA856766046EFF693720BA43114D7F5DE36E87">>},
{<<"jarl">>, <<"B92ECC182498C33E9ED31DF7A0EF4BECAFAC0E1CB1C118C618E662BCC45CE7E9">>},
{<<"jsx">>, <<"D12516BAA0BB23A59BB35DCCAF02A1BD08243FCBB9EFE24F2D9D056CCFF71268">>},
{<<"mapz">>, <<"77A8E38B69BAB16C5D3EBD44E6C619F8AF1F1598B0CAAE301D266605A0865756">>}]},
{pkg_hash_ext,[
{<<"certifi">>, <<"8F3D9533A0F06070AFDFD5D596B32E21C6580667A492891851B0E2737BC507A1">>},
{<<"cowlib">>, <<"E1E1284DC3FC030A64B1AD0D8382AE7E99DA46C3246B815318A4B848873800A4">>},
{<<"grisp">>, <<"4BF7D6E31B03884C13402694D8CDC9B5ECADB53EA1B405453581FD2248D38928">>},
{<<"grisp_cryptoauth">>, <<"D9BD51BC877986404FCF6DB1E3DF196C919BD6F55398FA03262D1C4323410AB9">>},
{<<"grisp_cryptoauth">>, <<"A3B997EB54C6FC96B9FFCBB6207F453CD28CD86B4B44D4A6DE703174B4AAE065">>},
{<<"gun">>, <<"52FC7FC246BFC3B00E01AEA1C2854C70A366348574AB50C57DFE796D24A0101D">>},
{<<"jarl">>, <<"6786787231E0E966BB01B30EEFEC353D6760F5C490B419A126726AFB46BB1437">>},
{<<"jsx">>, <<"0C5CC8FDC11B53CC25CF65AC6705AD39E54ECC56D1C22E4ADB8F5A53FB9427F3">>},
{<<"mapz">>, <<"4B68DF5CF0522E0D6545DF7B681BC052865CDB78405AD4CC9C55FE45EE7B25BE">>}]}
].
1 change: 0 additions & 1 deletion src/grisp_connect.app.src
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,6 @@
{ws_request_timeout, 5_000},
{ws_ping_timeout, 60_000},
{ws_max_retries, infinity},
{logs_interval, 2_000},
{logs_batch_size, 100},
{logger, [
% Enable our own default handler,
Expand Down
17 changes: 12 additions & 5 deletions src/grisp_connect_api.erl
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,15 +19,19 @@
when Msg :: {request, Method :: jarl:method(), Params :: map() | list(), ReqRef :: binary() | integer()}
| {notification, jarl:method(), Params :: map() | list()}.
handle_msg({notification, M, Params}) ->
?LOG_ERROR("Received unexpected notification ~p: ~p", [M, Params]),
ok;
handle_msg({request, M, Params, ID})
when M == [?method_post]; M == [?method_get] ->
handle_notification(M, Params);
handle_msg({request, M, Params, ID}) ->
handle_request(M, Params, ID).


%--- Internal Funcitons --------------------------------------------------------

handle_notification([log, sync], Params) ->
grisp_connect_log:sync(Params);
handle_notification(Method, Params) ->
?LOG_ERROR("Received unexpected notification ~p: ~p", [Method, Params]),
ok.

handle_request([?method_get], #{type := <<"system_info">>} = _Params, ID) ->
Info = grisp_connect_updater:system_info(),
{reply, Info, ID};
Expand Down Expand Up @@ -73,5 +77,8 @@ handle_request([?method_post], #{type := <<"cancel">>}, ID) ->
ok ->
{reply, ok, ID}
end;
handle_request(_T, _P, ID) ->
handle_request([log, get], Params, ID) ->
{reply, grisp_connect_log:get(Params), ID};
handle_request(Method, Params, ID) ->
?LOG_ERROR("Received unexpected request ~p: ~p", [Method, Params]),
{error, method_not_found, undefined, undefined, ID}.
3 changes: 0 additions & 3 deletions src/grisp_connect_client.erl
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -213,7 +213,6 @@ connecting(info, {jarl, Conn, {connected, _}}, Data = #data{conn = Conn}) ->
connected(enter, _OldState, Data = #data{wait_calls = WaitCalls}) ->
% When entering connected, we reply to all wait_connected calls with ok
gen_statem:reply([{reply, F, ok} || F <- WaitCalls]),
grisp_connect_log_server:start(),
{keep_state, Data#data{wait_calls = [], last_error = undefined}};
connected({call, From}, is_connected, _) ->
{keep_state_and_data, [{reply, From, true}]};
Expand Down Expand Up @@ -371,13 +370,11 @@ conn_start(Data = #data{conn = undefined,
conn_close(Data = #data{conn = undefined}, _Reason) ->
Data;
conn_close(Data = #data{conn = Conn}, _Reason) ->
grisp_connect_log_server:stop(),
jarl:disconnect(Conn),
Data#data{conn = undefined}.

% Safe to call in any state
conn_died(Data) ->
grisp_connect_log_server:stop(),
Data#data{conn = undefined}.

-spec conn_request(data(), jarl:method(), atom(), map(),
Expand Down
91 changes: 91 additions & 0 deletions src/grisp_connect_log.erl
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,91 @@
%% @doc Utility module to handle logs.
%% @end
-module(grisp_connect_log).

-include_lib("kernel/include/logger.hrl").

% API functions
-export([get/1]).
-export([sync/1]).

%--- Macros --------------------------------------------------------------------

% FixMe:
% Sending over ~30_000 bytes over WS breaks rtems I/O driver.
% We want avoid to return chunks that are bigger then that.
-define(MAX_CHUNK_BYTES, 30_000).

%--- Types ---------------------------------------------------------------------

-type get_options() :: #{
max_batch_size => non_neg_integer(),
max_byte_size => non_neg_integer()
}.

-type sync_options() :: #{
seq := non_neg_integer(),
dropped => non_neg_integer()
}.


%--- API Functions -------------------------------------------------------------

-spec get(Opts :: get_options()) ->
#{dropped := non_neg_integer(), events := list()}.
get(Opts) ->
{ok, DefaultSize} = application:get_env(grisp_connect, logs_batch_size),
BatchSize = maps:get(max_batch_size, Opts, DefaultSize),
ByteSize = min(maps:get(max_byte_size, Opts, ?MAX_CHUNK_BYTES), ?MAX_CHUNK_BYTES),
{Events, Dropped} = grisp_connect_logger_bin:chunk(BatchSize, ByteSize),
#{events => [[Seq, jsonify(E)] || {Seq, E} <- Events],
dropped => Dropped}.

-spec sync(Opts :: sync_options()) -> ok.
sync(#{seq := Seq, dropped := Dropped}) ->
grisp_connect_logger_bin:sync(Seq, Dropped).


%--- Internal Functions --------------------------------------------------------

jsonify(Event) ->
jsonify_meta(jsonify_msg(binary_to_term(base64:decode(Event)))).

jsonify_msg(#{msg := {string, String}} = Event) ->
maps:put(msg, unicode:characters_to_binary(String), Event);
jsonify_msg(#{msg := {report, Report}} = Event) ->
case is_json_compatible(Report) of
true ->
maps:put(msg, Report, Event);
false ->
String = unicode:characters_to_binary(
io_lib:format("[JSON incompatible term]~n~tp", [Report])
),
maps:put(msg, String, Event)
end;
jsonify_msg(#{msg := {FormatString, Term}} = Event) ->
%FIXME: scan format and ensure unicode encoding
String = unicode:characters_to_binary(io_lib:format(FormatString, Term)),
maps:put(msg, String, Event).

jsonify_meta(#{meta := Meta} = Event) ->
MFA = case maps:is_key(mfa, Meta) of
true ->
{M, F, A} = maps:get(mfa, Meta),
[M, F, A];
false ->
null
end,
File = case maps:is_key(file, Meta) of
true -> unicode:characters_to_binary(maps:get(file, Meta));
false -> null
end,
Default = #{mfa => MFA, file => File},
Optional = maps:without(maps:keys(Default), Meta),
FilterFun = fun(Key, Value) -> jsx:is_term(#{Key => Value}) end,
maps:put(meta, maps:merge(maps:filter(FilterFun, Optional), Default), Event).

is_json_compatible(Term) ->
try jsx:is_term(Term)
catch error:_ ->
false
end.
Loading