Logging via the HTTP API (#4074)

Squashed commit of the following: commit 16771dc Author: Age Manning <Age@AgeManning.com> Date: Wed May 17 15:27:47 2023 +1000 fmt commit 1deeafe Merge: 9f5ca3d b29bb2e Author: Age Manning <Age@AgeManning.com> Date: Wed May 17 15:26:13 2023 +1000 Merge latest unstable commit 9f5ca3d Author: Age Manning <Age@AgeManning.com> Date: Wed May 17 15:24:06 2023 +1000 Enable SSE logs only on GUI flag and misc reviewers comments commit 5eeca70 Merge: 3efdbe2 d64be0d Author: Age Manning <Age@AgeManning.com> Date: Tue May 9 10:08:05 2023 +1000 Merge latest unstable commit 3efdbe2 Author: Age Manning <Age@AgeManning.com> Date: Mon May 8 17:13:12 2023 +1000 fmt commit 202aad8 Author: Age Manning <Age@AgeManning.com> Date: Wed May 3 16:30:19 2023 +1000 Remove api token requirement for sse logs commit 5411d5a Author: Age Manning <Age@AgeManning.com> Date: Wed May 3 15:57:59 2023 +1000 Remove double json encoding commit 29fb985 Author: Age Manning <Age@AgeManning.com> Date: Wed May 3 14:32:31 2023 +1000 fmt commit 3e10b26 Merge: 37ec9b7 826e748 Author: Age Manning <Age@AgeManning.com> Date: Wed May 3 14:30:41 2023 +1000 Merge latest unstable commit 37ec9b7 Author: Age Manning <Age@AgeManning.com> Date: Tue Mar 14 16:25:45 2023 +1100 Revert old clippy change commit b3d0167 Author: Age Manning <Age@AgeManning.com> Date: Tue Mar 14 14:45:31 2023 +1100 Appease clippy commit 1df3191 Author: Age Manning <Age@AgeManning.com> Date: Tue Mar 14 14:08:28 2023 +1100 Fix tests commit fc7645e Author: Age Manning <Age@AgeManning.com> Date: Tue Mar 14 13:43:52 2023 +1100 Fix logging tests via tokio upgrade commit 4988a15 Merge: 6cf9338 90cef1d Author: Age Manning <Age@AgeManning.com> Date: Mon Mar 13 15:47:26 2023 +1100 Merge latest unstable commit 6cf9338 Merge: 5deabe0 3ad77fb Author: Age Manning <Age@AgeManning.com> Date: Mon Mar 13 15:39:51 2023 +1100 Merge latest unstable commit 5deabe0 Author: Age Manning <Age@AgeManning.com> Date: Mon Mar 13 15:39:45 2023 +1100 fmt commit 5f24f65 Author: Age Manning <Age@AgeManning.com> Date: Mon Mar 13 15:38:36 2023 +1100 A working version commit 4da3351 Author: Age Manning <Age@AgeManning.com> Date: Thu Mar 9 13:44:22 2023 +1100 Tokio broadcast version commit e34aab2 Merge: cd6edbc 9d821ce Author: Age Manning <Age@AgeManning.com> Date: Thu Mar 9 13:17:38 2023 +1100 Merge pull request #3 from michaelsproul/sse-logs Workaround format_args! with closure commit 9d821ce Author: Michael Sproul <micsproul@gmail.com> Date: Thu Mar 9 11:57:51 2023 +1100 Workaround format_args! with closure commit cd6edbc Author: Age Manning <Age@AgeManning.com> Date: Thu Mar 9 11:18:02 2023 +1100 Getting closer commit e9eb455 Author: Age Manning <Age@AgeManning.com> Date: Wed Mar 8 16:38:58 2023 +1100 Crossbeam version commit b688cfb Author: Age Manning <Age@AgeManning.com> Date: Tue Mar 7 14:56:17 2023 +1100 More temp commits commit 228b930 Merge: 035ca37 17d9a62 Author: Age Manning <Age@AgeManning.com> Date: Wed Mar 1 13:05:45 2023 +1100 Merge latest unstable commit 035ca37 Author: Age Manning <Age@AgeManning.com> Date: Wed Feb 8 20:24:39 2023 +1100 Temp progress
sigp · May 20, 2023 · c9f79de · c9f79de
1 parent 981c72e
commit c9f79de
Show file tree

Hide file tree

Showing 23 changed files with 863 additions and 216 deletions.
diff --git a/Cargo.lock b/Cargo.lock
diff --git a/beacon_node/client/Cargo.toml b/beacon_node/client/Cargo.toml
@@ -6,7 +6,6 @@ edition = "2021"
 
 [dev-dependencies]
 serde_yaml = "0.8.13"
-logging = { path = "../../common/logging" }
 state_processing = { path = "../../consensus/state_processing" }
 operation_pool = { path = "../operation_pool" }
 tokio = "1.14.0"
@@ -17,6 +16,7 @@ store = { path = "../store" }
 network = { path = "../network" }
 timer = { path = "../timer" }
 lighthouse_network = { path = "../lighthouse_network" }
+logging = { path = "../../common/logging" }
 parking_lot = "0.12.0"
 types = { path = "../../consensus/types" }
 eth2_config = { path = "../../common/eth2_config" }

diff --git a/beacon_node/client/src/builder.rs b/beacon_node/client/src/builder.rs
@@ -478,6 +478,7 @@ where
                         network_globals: None,
                         eth1_service: Some(genesis_service.eth1_service.clone()),
                         log: context.log().clone(),
+                        sse_logging_components: runtime_context.sse_logging_components.clone(),
                     });
 
                     // Discard the error from the oneshot.
@@ -698,6 +699,7 @@ where
                 network_senders: self.network_senders.clone(),
                 network_globals: self.network_globals.clone(),
                 eth1_service: self.eth1_service.clone(),
+                sse_logging_components: runtime_context.sse_logging_components.clone(),
                 log: log.clone(),
             });
 

diff --git a/beacon_node/http_api/Cargo.toml b/beacon_node/http_api/Cargo.toml
@@ -36,11 +36,11 @@ tree_hash = "0.5.0"
 sysinfo = "0.26.5"
 system_health = { path = "../../common/system_health" }
 directory = { path = "../../common/directory" }
+logging = { path = "../../common/logging" }
 ethereum_serde_utils = "0.5.0"
 operation_pool = { path = "../operation_pool" }
 sensitive_url = { path = "../../common/sensitive_url" }
 unused_port = {path = "../../common/unused_port"}
-logging = { path = "../../common/logging" }
 store = { path = "../store" }
 
 [dev-dependencies]
@@ -51,4 +51,4 @@ genesis = { path = "../genesis" }
 
 [[test]]
 name = "bn_http_api_tests"
-path = "tests/main.rs"
+path = "tests/main.rs"
diff --git a/beacon_node/http_api/src/lib.rs b/beacon_node/http_api/src/lib.rs
@@ -36,6 +36,7 @@ use eth2::types::{
 };
 use lighthouse_network::{types::SyncState, EnrExt, NetworkGlobals, PeerId, PubsubMessage};
 use lighthouse_version::version_with_platform;
+use logging::SSELoggingComponents;
 use network::{NetworkMessage, NetworkSenders, ValidatorSubscriptionMessage};
 use operation_pool::ReceivedPreCapella;
 use parking_lot::RwLock;
@@ -108,6 +109,7 @@ pub struct Context<T: BeaconChainTypes> {
     pub network_senders: Option<NetworkSenders<T::EthSpec>>,
     pub network_globals: Option<Arc<NetworkGlobals<T::EthSpec>>>,
     pub eth1_service: Option<eth1::Service>,
+    pub sse_logging_components: Option<SSELoggingComponents>,
     pub log: Logger,
 }
 
@@ -448,6 +450,9 @@ pub fn serve<T: BeaconChainTypes>(
     let inner_ctx = ctx.clone();
     let log_filter = warp::any().map(move || inner_ctx.log.clone());
 
+    let inner_components = ctx.sse_logging_components.clone();
+    let sse_component_filter = warp::any().map(move || inner_components.clone());
+
     // Create a `warp` filter that provides access to local system information.
     let system_info = Arc::new(RwLock::new(sysinfo::System::new()));
     {
@@ -3729,6 +3734,44 @@ pub fn serve<T: BeaconChainTypes>(
             },
         );
 
+    // Subscribe to logs via Server Side Events
+    // /lighthouse/logs
+    let lighthouse_log_events = warp::path("lighthouse")
+        .and(warp::path("logs"))
+        .and(warp::path::end())
+        .and(sse_component_filter)
+        .and_then(|sse_component: Option<SSELoggingComponents>| {
+            blocking_response_task(move || {
+                if let Some(logging_components) = sse_component {
+                    // Build a JSON stream
+                    let s =
+                        BroadcastStream::new(logging_components.sender.subscribe()).map(|msg| {
+                            match msg {
+                                Ok(data) => {
+                                    // Serialize to json
+                                    match data.to_json_string() {
+                                        // Send the json as a Server Side Event
+                                        Ok(json) => Ok(Event::default().data(json)),
+                                        Err(e) => Err(warp_utils::reject::server_sent_event_error(
+                                            format!("Unable to serialize to JSON {}", e),
+                                        )),
+                                    }
+                                }
+                                Err(e) => Err(warp_utils::reject::server_sent_event_error(
+                                    format!("Unable to receive event {}", e),
+                                )),
+                            }
+                        });
+
+                    Ok::<_, warp::Rejection>(warp::sse::reply(warp::sse::keep_alive().stream(s)))
+                } else {
+                    Err(warp_utils::reject::custom_server_error(
+                        "SSE Logging is not enabled".to_string(),
+                    ))
+                }
+            })
+        });
+
     // Define the ultimate set of routes that will be provided to the server.
     // Use `uor` rather than `or` in order to simplify types (see `UnifyingOrFilter`).
     let routes = warp::get()
@@ -3796,6 +3839,7 @@ pub fn serve<T: BeaconChainTypes>(
                 .uor(get_lighthouse_block_packing_efficiency)
                 .uor(get_lighthouse_merge_readiness)
                 .uor(get_events)
+                .uor(lighthouse_log_events.boxed())
                 .recover(warp_utils::reject::handle_rejection),
         )
         .boxed()

diff --git a/beacon_node/http_api/src/test_utils.rs b/beacon_node/http_api/src/test_utils.rs
@@ -198,6 +198,7 @@ pub async fn create_api_server_on_port<T: BeaconChainTypes>(
         network_senders: Some(network_senders),
         network_globals: Some(network_globals),
         eth1_service: Some(eth1_service),
+        sse_logging_components: None,
         log,
     });
 

diff --git a/beacon_node/src/cli.rs b/beacon_node/src/cli.rs
@@ -1081,7 +1081,7 @@ pub fn cli_app<'a, 'b>() -> App<'a, 'b> {
                 .long("gui")
                 .hidden(true)
                 .help("Enable the graphical user interface and all its requirements. \
-                      This is equivalent to --http and --validator-monitor-auto.")
+                      This enables --http and --validator-monitor-auto and enables SSE logging.")
                 .takes_value(false)
         )
         .arg(

diff --git a/book/src/api-lighthouse.md b/book/src/api-lighthouse.md
@@ -679,3 +679,31 @@ Caveats:
   This is because the state _prior_ to the `start_epoch` needs to be loaded from the database, and
   loading a state on a boundary is most efficient.
 
+
+### `/lighthouse/logs`
+
+This is a Server Side Event subscription endpoint. This allows a user to read
+the Lighthouse logs directly from the HTTP API endpoint. This currently
+exposes INFO and higher level logs. It is only enabled when the `--gui` flag is set in the CLI.
+
+Example:
+
+```bash
+curl -N "http://localhost:5052/lighthouse/logs"
+```
+
+Should provide an output that emits log events as they occur:
+```json
+{
+"data": {
+	  "time": "Mar 13 15:28:41",
+	  "level": "INFO",
+	  "msg": "Syncing",
+	  "service": "slot_notifier",
+	  "est_time": "1 hr 27 mins",
+	  "speed": "5.33 slots/sec",
+	  "distance": "28141 slots (3 days 21 hrs)",
+	  "peers": "8"
+	}
+}
+```
diff --git a/book/src/api-vc-endpoints.md b/book/src/api-vc-endpoints.md
@@ -578,3 +578,33 @@ The following fields may be omitted or nullified to obtain default values:
 ### Example Response Body
 
 *No data is included in the response body.*
+
+## `GET /lighthouse/logs`
+
+Provides a subscription to receive logs as Server Side Events. Currently the
+logs emitted are INFO level or higher.
+
+### HTTP Specification
+
+| Property          | Specification                              |
+|-------------------|--------------------------------------------|
+| Path              | `/lighthouse/logs`                         |
+| Method            | GET                                        |
+| Required Headers  | None                                       |
+| Typical Responses | 200                                        |
+
+### Example Response Body
+
+```json
+{
+  "data": {
+	  "time": "Mar 13 15:26:53",
+	  "level": "INFO",
+	  "msg": "Connected to beacon node(s)",
+	  "service": "notifier",
+	  "synced": 1,
+	  "available": 1,
+	  "total": 1
+  }
+}
+```
diff --git a/common/logging/Cargo.toml b/common/logging/Cargo.toml
@@ -10,6 +10,13 @@ test_logger = [] # Print log output to stderr when running tests instead of drop
 [dependencies]
 slog = "2.5.2"
 slog-term = "2.6.0"
+tokio = { version = "1.26.0", features = ["sync"] }
 lighthouse_metrics = { path = "../lighthouse_metrics" }
 lazy_static = "1.4.0"
 sloggers = { version = "2.1.1", features = ["json"] }
+slog-async = "2.7.0"
+take_mut = "0.2.2"
+parking_lot = "0.12.1"
+serde = "1.0.153" 
+serde_json = "1.0.94"
+chrono = "0.4.23"