feat: body logging for user log

* clean up ENV vars into one place
* change ONESDK_LOG to only be on/off
* implement PeekableStream
* do not log TRACE into developer dump log

README.md

@@ -24,12 +24,11 @@ This will require to have Development requirements installed. In case of buildin
 
 The OneSDK uses these environment variables:
 
-- `ONESDK_LOG=warn` - controls the level of logging intended for users. Set to `trace` to log everything intended for users. See [tracing_subscriber directives](https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html#directives) for full syntax.
+- `ONESDK_LOG=on` - controls logging intended for users. Values `1`, `on`, `yes` and `true` are recognized as positive.
 - `ONESDK_REGISTRY_URL=http://localhost:8321` - Superface registry base URL
 - `ONESDK_CONFIG_CACHE_DURATION=3600` - duration in seconds of how long to cache documents (profiles, maps, providers) before downloading or reading them from the file system again
 - `ONESDK_CONFIG_DEV_DUMP_BUFFER_SIZE=1048576` - size of the developer log dump ring buffer
 - `ONESDK_DEV_LOG=off` - controls the level of logging intended for developers. Set to `trace` to see everything that is logged, including user log and metrics. See [tracing_subscriber directives](https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html#directives) for full syntax.
-- `ONESDK_REPLACE_MAP_STDLIB=` - path to replacement map stdlib, intended for development only, may be removed at any time
 
 ## Supported languages
 

core/core/Cargo.toml

@@ -17,18 +17,17 @@ thiserror = { workspace = true }
 
 serde = { workspace = true }
 serde_json = { workspace = true }
-
 jsonschema = { workspace = true }
+base64 = { workspace = true }
+url = { workspace = true }
 
 sf_std = { path = "../host_to_core_std", package = "host_to_core_std" }
 map_std = { path = "../core_to_map_std", package = "core_to_map_std" }
 interpreter_js = { path = "../interpreter_js" }
 
-base64 = { workspace = true }
-
 sha2 = { workspace = true }
 hex = { workspace = true }
 
 tracing = { workspace = true }
 tracing-subscriber = { version = "0.3", features = ["env-filter", "fmt", "json"] }
-chrono = { version = "0.4", default-features = false, features = ["std", "clock"] }
+chrono = { version = "0.4", default-features = false, features = ["clock", "std"] }

core/core/src/lib.rs

@@ -51,7 +51,7 @@ pub extern "C" fn __export_oneclient_core_setup() {
 
     // initialize observability
     // SAFETY: setup is only allowed to be called once
-    unsafe { observability::init(config.developer_dump_buffer_size) };
+    unsafe { observability::init(&config) };
 
     // now that we have logging we can start printing stuff
     tracing::debug!(target: "@user", "oneclient_core_setup called");
@@ -64,7 +64,7 @@ pub extern "C" fn __export_oneclient_core_setup() {
     }
 
     // here we panic on error because there is nothing to teardown
-    lock.replace(OneClientCore::new(config).unwrap());
+    lock.replace(OneClientCore::new(&config).unwrap());
 }
 
 #[no_mangle]

core/core/src/mock.rs

@@ -8,8 +8,7 @@ use sf_std::unstable::{
     perform::{set_perform_output_result_in, PerformInput},
     HostValue,
 };
-use tracing::metadata::LevelFilter;
-use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, EnvFilter, Layer};
+use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
 
 use crate::bindings::MessageExchangeFfi;
 
@@ -23,16 +22,7 @@ pub fn __export_oneclient_core_setup() {
 
     // initialize tracing
     tracing_subscriber::registry()
-        .with(
-            tracing_subscriber::fmt::layer()
-                .with_writer(std::io::stderr)
-                .with_filter(
-                    EnvFilter::builder()
-                        .with_default_directive(LevelFilter::TRACE.into())
-                        .with_env_var("ONESDK_DEV_LOG")
-                        .from_env_lossy(),
-                ),
-        )
+        .with(tracing_subscriber::fmt::layer().with_writer(std::io::stderr))
         .init();
 
     tracing::debug!("mocked oneclient core setup");

core/core/src/observability/mod.rs

@@ -7,6 +7,7 @@ use tracing_subscriber::{
 };
 
 use self::buffer::{RingEventBuffer, SharedEventBuffer, TracingEventBuffer, VecEventBuffer};
+use crate::sf_core::CoreConfiguration;
 
 mod buffer;
 pub mod metrics;
@@ -15,17 +16,19 @@ static mut METRICS_BUFFER: Option<SharedEventBuffer<VecEventBuffer>> = None;
 static mut DEVELOPER_DUMP_BUFFER: Option<SharedEventBuffer<RingEventBuffer>> = None;
 
 /// SAFETY: must only be called once during initialization of the program
-pub unsafe fn init(ring_event_buffer_size: usize) {
+pub unsafe fn init(config: &CoreConfiguration) {
     // SAFETY: this is only called once and there is no asynchronous mutation
     unsafe {
         METRICS_BUFFER.replace(SharedEventBuffer::new(VecEventBuffer::new()));
         DEVELOPER_DUMP_BUFFER.replace(SharedEventBuffer::new(RingEventBuffer::new(
-            ring_event_buffer_size,
+            config.developer_dump_buffer_size,
         )));
 
         init_tracing(
             // METRICS_BUFFER.as_ref().cloned().unwrap(),
             DEVELOPER_DUMP_BUFFER.as_ref().cloned().unwrap(),
+            config.user_log,
+            &config.developer_log,
         );
     }
 
@@ -44,13 +47,20 @@ pub unsafe fn init(ring_event_buffer_size: usize) {
             message = message.as_ref(),
             location = info.location().map(|l| (l.file(), l.line(), l.column()))
         );
+        tracing::error!(
+            target: "panic",
+            message = message.as_ref(),
+            location = ?info.location().map(|l| format!("{}:{}:{}", l.file(), l.line(), l.column()))
+        );
     }));
 }
 
 fn init_tracing(
     // TODO: we don't use tracing to store metrics in the metrics buffer because we need more complex fields than tracing currently supports
     // _metrics_buffer: SharedEventBuffer<VecEventBuffer>,
     developer_dump_buffer: SharedEventBuffer<RingEventBuffer>,
+    user_log: bool,
+    developer_log: &str,
 ) {
     // we set up these layers:
     // * user layer (@user) - output intended/relevant for users of the sdk
@@ -59,32 +69,26 @@ fn init_tracing(
     // * dump layer (not @metrics) - output dumped after a panic, excluding metrics which are dumped separately
 
     let user_layer = tracing_subscriber::fmt::layer()
-        .with_target(false)
+        .event_format(format::format().with_target(false).with_level(false))
         .with_writer(std::io::stdout)
-        .with_filter(FilterFn::new(|metadata| {
-            metadata.target().starts_with("@user")
-        }))
-        .with_filter(
-            EnvFilter::builder()
-                .with_default_directive(LevelFilter::WARN.into())
-                .with_env_var("ONESDK_LOG")
-                .from_env_lossy(),
-        );
+        .with_filter(FilterFn::new(move |metadata| {
+            user_log && metadata.target().starts_with("@user")
+        }));
 
     let developer_layer = tracing_subscriber::fmt::layer()
         .with_writer(std::io::stderr)
         .with_filter(
             EnvFilter::builder()
                 .with_default_directive(LevelFilter::OFF.into())
-                .with_env_var("ONESDK_DEV_LOG")
-                .from_env_lossy(),
+                .parse_lossy(developer_log),
         );
 
     let developer_dump_layer = tracing_subscriber::fmt::layer()
+        .with_writer(developer_dump_buffer)
         .event_format(
             format::format().with_ansi(false), // disable ansi colors because this will usually go into a file
         )
-        .with_writer(developer_dump_buffer);
+        .with_filter(LevelFilter::DEBUG);
 
     tracing_subscriber::registry()
         .with(user_layer)

core/core/src/sf_core.rs

@@ -35,10 +35,14 @@ use cache::DocumentCache;
 pub use config::CoreConfiguration;
 use map_std_impl::MapStdImpl;
 
-use self::cache::{MapCacheEntry, ProfileCacheEntry, ProviderJsonCacheEntry};
+use self::{
+    cache::{MapCacheEntry, ProfileCacheEntry, ProviderJsonCacheEntry},
+    map_std_impl::MapStdImplConfig,
+};
 
 type Fs = sf_std::unstable::fs::FsConvenience<MessageExchangeFfi, StreamExchangeFfi>;
 type HttpRequest = sf_std::unstable::http::HttpRequest<MessageExchangeFfi, StreamExchangeFfi>;
+type HttpResponse = sf_std::unstable::http::HttpResponse<StreamExchangeFfi>;
 type IoStream = sf_std::unstable::IoStream<StreamExchangeFfi>;
 
 #[derive(Debug)]
@@ -47,27 +51,32 @@ pub struct OneClientCore {
     provider_cache: DocumentCache<ProviderJsonCacheEntry>,
     map_cache: DocumentCache<MapCacheEntry>,
     security_validator: JsonSchemaValidator,
+    mapstd_config: MapStdImplConfig,
 }
 impl OneClientCore {
     const MAP_STDLIB_JS: &str = include_str!("../assets/js/map_std.js");
 
     // TODO: Use thiserror and define specific errors
-    pub fn new(config: CoreConfiguration) -> anyhow::Result<Self> {
+    pub fn new(config: &CoreConfiguration) -> anyhow::Result<Self> {
         tracing::info!(target: "@user", config = ?config);
 
         crate::observability::metrics::log_metric!(Init);
 
         Ok(Self {
-            profile_cache: DocumentCache::new(config.cache_duration),
-            provider_cache: DocumentCache::new(config.cache_duration),
-            map_cache: DocumentCache::new(config.cache_duration),
+            profile_cache: DocumentCache::new(config.cache_duration, config.registry_url.clone()),
+            provider_cache: DocumentCache::new(config.cache_duration, config.registry_url.clone()),
+            map_cache: DocumentCache::new(config.cache_duration, config.registry_url.clone()),
             security_validator: JsonSchemaValidator::new(
                 &serde_json::Value::from_str(include_str!(
                     "../assets/schemas/security_values.json"
                 ))
                 .expect("Valid JSON"),
             )
             .expect("Valid JSON Schema for security values exists"),
+            mapstd_config: MapStdImplConfig {
+                log_http_transactions: config.user_log,
+                log_http_transactions_body_max_size: config.user_log_http_body_max_size,
+            },
         })
     }
 
@@ -251,7 +260,7 @@ impl OneClientCore {
         // start interpreting stdlib and then map code
         // TODO: should this be here or should we hold an instance of the interpreter in global state
         // and clear per-perform data each time it is called?
-        let mut interpreter = try_metrics!(JsInterpreter::new(MapStdImpl::new()));
+        let mut interpreter = try_metrics!(JsInterpreter::new(MapStdImpl::new(self.mapstd_config)));
         // here we allow runtime stdlib replacement for development purposes
         // this might be removed in the future
         try_metrics!(match std::env::var("ONESDK_REPLACE_MAP_STDLIB").ok() {

core/core/src/sf_core/cache.rs

@@ -4,6 +4,8 @@ use std::{
     time::{Duration, Instant},
 };
 
+use url::Url;
+
 use sf_std::unstable::{http::HttpCallError, provider::ProviderJson};
 
 use super::{digest, Fs, HttpRequest};
@@ -102,17 +104,19 @@ impl<E: std::fmt::Debug> std::fmt::Debug for DocumentCacheEntry<E> {
 pub struct DocumentCache<E> {
     map: HashMap<String, DocumentCacheEntry<E>>,
     cache_duration: Duration,
+    registry_url: Url,
 }
 impl<E> DocumentCache<E> {
     const FILE_URL_PREFIX: &str = "file://";
     const HTTP_URL_PREFIX: &str = "http://";
     const HTTPS_URL_PREFIX: &str = "https://";
     const BASE64_URL_PREFIX: &str = "data:;base64,";
 
-    pub fn new(cache_duration: Duration) -> Self {
+    pub fn new(cache_duration: Duration, registry_url: Url) -> Self {
         Self {
             map: HashMap::new(),
             cache_duration,
+            registry_url,
         }
     }
 
@@ -147,11 +151,15 @@ impl<E> DocumentCache<E> {
                 {
                     Self::cache_http(url)
                 } else {
-                    let url_base = std::env::var("ONESDK_REGISTRY_URL")
-                        .unwrap_or("http://localhost:8321".to_string());
-                    let url = format!("{}/{}.js", url_base, url);
-
-                    Self::cache_http(&url)
+                    let file = format!("{}.js", url);
+                    let full_url = self.registry_url.join(&file).map_err(|_e| {
+                        DocumentCacheError::HttpLoadFailed(
+                            url.to_string(),
+                            HttpCallError::InvalidUrl(file.clone()),
+                        )
+                    })?;
+
+                    Self::cache_http(full_url.as_str())
                 }
             }
         }?;

core/core/src/sf_core/config.rs

@@ -1,5 +1,7 @@
 use std::time::Duration;
 
+use url::Url;
+
 #[derive(Debug, thiserror::Error)]
 pub enum CoreConfigurationEnvError {
     #[error("Variable {0} could not be parsed as {1}")]
@@ -8,8 +10,15 @@ pub enum CoreConfigurationEnvError {
 
 #[derive(Debug)]
 pub struct CoreConfiguration {
+    /// Duration to cache documents for.
     pub cache_duration: Duration,
+    /// Size of the developer dump buffer in bytes.
     pub developer_dump_buffer_size: usize,
+    /// URL to document registry from which to downlaod documents.
+    pub registry_url: Url,
+    pub user_log: bool,
+    pub user_log_http_body_max_size: usize,
+    pub developer_log: String,
 }
 impl CoreConfiguration {
     pub fn from_env() -> Result<Self, CoreConfigurationEnvError> {
@@ -30,8 +39,13 @@ impl CoreConfiguration {
             };
 
             (__internal parse String) => { |v| Result::<String, std::convert::Infallible>::Ok(v) };
+            (__internal parse Url) => { |v| Url::parse(&v) };
             (__internal parse u64) => { |v| v.parse::<u64>() };
             (__internal parse usize) => { |v| v.parse::<usize>() };
+            (__internal parse bool) => { |v| match v.as_str() {
+                "on" | "yes" | "true" | "1" => Ok::<bool, CoreConfigurationEnvError>(true),
+                _ => Ok(false)
+            } };
         }
 
         if let Some(v) = get_env!("ONESDK_CONFIG_CACHE_DURATION", u64 "seconds")? {
@@ -40,6 +54,15 @@ impl CoreConfiguration {
         if let Some(v) = get_env!("ONESDK_CONFIG_DEV_DUMP_BUFFER_SIZE", usize "buffer size")? {
             base.developer_dump_buffer_size = v;
         }
+        if let Some(v) = get_env!("ONESDK_LOG", bool "boolean")? {
+            base.user_log = v;
+        }
+        if let Some(v) = get_env!("ONESDK_REGISTRY_URL", Url "url")? {
+            base.registry_url = v;
+        }
+        if let Some(v) = get_env!("ONESDK_DEV_LOG", String "string")? {
+            base.developer_log = v;
+        }
 
         Ok(base)
     }
@@ -49,6 +72,10 @@ impl Default for CoreConfiguration {
         Self {
             cache_duration: Duration::from_secs(60 * 60),
             developer_dump_buffer_size: 1024 * 1024, // 1 MiB
+            registry_url: Url::parse("http://localhost:8321").unwrap(),
+            user_log: false,
+            user_log_http_body_max_size: 1024 * 1024, // 1 MiB
+            developer_log: "off".to_string(),
         }
     }
 }