holochain 0.7.0-dev.22

Holochain, a framework for distributed applications
Documentation 
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136

use crate::core::ribosome::CallContext;
use crate::core::ribosome::RibosomeT;
use holochain_types::prelude::*;
use once_cell::unsync::Lazy;
use std::sync::Arc;
use wasmer::RuntimeError;

#[cfg(test)]
use once_cell::sync::Lazy as SyncLazy;
#[cfg(test)]
use std::sync::atomic::AtomicBool;

#[cfg(test)]
static CAPTURE: AtomicBool = AtomicBool::new(false);
#[cfg(test)]
static CAPTURED: SyncLazy<Arc<std::sync::Mutex<Vec<TraceMsg>>>> =
    SyncLazy::new(|| Arc::new(std::sync::Mutex::new(Vec::new())));

#[cfg_attr(feature = "instrument", tracing::instrument(skip(input)))]
pub fn wasm_trace(input: TraceMsg) {
    match input.level {
        holochain_types::prelude::Level::TRACE => tracing::trace!("{}", input.msg),
        holochain_types::prelude::Level::DEBUG => tracing::debug!("{}", input.msg),
        holochain_types::prelude::Level::INFO => tracing::info!("{}", input.msg),
        holochain_types::prelude::Level::WARN => tracing::warn!("{}", input.msg),
        holochain_types::prelude::Level::ERROR => tracing::error!("{}", input.msg),
    }
}

pub fn trace(
    _ribosome: Arc<impl RibosomeT>,
    _call_context: Arc<CallContext>,
    input: TraceMsg,
) -> Result<(), RuntimeError> {
    // Avoid dialing out to the environment on every trace.
    let wasm_log = Lazy::new(|| {
        std::env::var("WASM_LOG").unwrap_or_else(|_| "[wasm_trace]=debug".to_string())
    });
    let collector = tracing_subscriber::fmt()
        .with_env_filter(tracing_subscriber::EnvFilter::new((*wasm_log).clone()))
        .with_target(false)
        .finish();

    #[cfg(test)]
    if CAPTURE.load(std::sync::atomic::Ordering::Relaxed) {
        CAPTURED.lock().unwrap().push(input.clone());
    }

    tracing::subscriber::with_default(collector, || wasm_trace(input));
    Ok(())
}

#[cfg(test)]
#[cfg(feature = "slow_tests")]
pub mod wasm_test {
    use super::*;

    use crate::fixt::CallContextFixturator;
    use crate::fixt::RealRibosomeFixturator;
    use crate::test_utils::RibosomeTestFixture;
    use holochain_wasm_test_utils::TestWasm;
    use std::sync::Arc;

    /// we can get an entry hash out of the fn directly
    #[tokio::test(flavor = "multi_thread")]
    async fn trace_test() {
        let ribosome = RealRibosomeFixturator::new(crate::fixt::Zomes(vec![]))
            .next()
            .unwrap();
        let call_context = CallContextFixturator::new(::fixt::Unpredictable)
            .next()
            .unwrap();
        let input = TraceMsg {
            level: holochain_types::prelude::Level::DEBUG,
            msg: "ribosome trace works".to_string(),
        };

        let _: () = trace(Arc::new(ribosome), Arc::new(call_context), input).unwrap();
    }

    #[tokio::test(flavor = "multi_thread")]
    #[ignore = "Doesn't work concurrently"]
    async fn wasm_trace_test() {
        use holochain_types::prelude::Level::*;
        CAPTURE.store(true, std::sync::atomic::Ordering::SeqCst);
        holochain_trace::test_run();
        let RibosomeTestFixture {
            conductor, alice, ..
        } = RibosomeTestFixture::new(TestWasm::Debug).await;

        let _: () = conductor.call(&alice, "debug", ()).await;
        let r: Vec<_> = CAPTURED.lock().unwrap().clone();
        let expect = vec![
            // two traces from the two validations of genesis entries
            TraceMsg {
                msg:
                    "integrity_test_wasm_debug:debug/src/integrity.rs:5 tracing in validation works"
                        .to_string(),
                level: INFO,
            },
            TraceMsg {
                msg:
                    "integrity_test_wasm_debug:debug/src/integrity.rs:5 tracing in validation works"
                        .to_string(),
                level: INFO,
            },
            // followed by the zome call traces
            TraceMsg {
                msg: "test_wasm_debug:debug/src/lib.rs:5 tracing works!".to_string(),
                level: TRACE,
            },
            TraceMsg {
                msg: "test_wasm_debug:debug/src/lib.rs:6 debug works".to_string(),
                level: DEBUG,
            },
            TraceMsg {
                msg: "test_wasm_debug:debug/src/lib.rs:7 info works".to_string(),
                level: INFO,
            },
            TraceMsg {
                msg: "test_wasm_debug:debug/src/lib.rs:8 warn works".to_string(),
                level: WARN,
            },
            TraceMsg {
                msg: "test_wasm_debug:debug/src/lib.rs:9 error works".to_string(),
                level: ERROR,
            },
            TraceMsg {
                msg: "test_wasm_debug:debug/src/lib.rs:10 foo = \"fields\"; bar = \"work\"; too"
                    .to_string(),
                level: DEBUG,
            },
        ];
        assert_eq!(r, expect);
    }
}