Change logging API from push to pull (#55)

* Change logging API from push to pull

* Upgrade to grisp_cryptoauth 2.4.1

* Update jarl version to 1.0.1

* Add reboot flags in grisp.ini

* Prevent crash if grisp_connect log handler is not setup properly

* Update log configuration in README

* Cleanup changelog

---------

Co-authored-by: Luca Succi <[email protected]>

Author: sylane

CHANGELOG.md

@@ -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
 
@@ -45,8 +49,6 @@ disconnected from the server.
 
 ## [1.0.0] - 2024-09-26
 
-### What's Changed
-
 #### Added
 - NTP handling
 - Connect to GRiSP.io
@@ -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

README.md

@@ -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, []}
+        ]}
     ]}
 ].
 ```

docs/grisp_connect_api.md

@@ -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>
@@ -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

docs/grisp_connect_architecture.md

@@ -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

grisp/grisp2/common/deploy/files/grisp.ini.mustache

@@ -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

rebar.config

@@ -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"}

rebar.lock

@@ -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">>}]}
 ].

src/grisp_connect.app.src

@@ -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,

src/grisp_connect_api.erl

@@ -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};
@@ -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}.

src/grisp_connect_client.erl

@@ -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}]};
@@ -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(),