From 5e130c421f555b3cb78d02e15c2645dc443fa4dc Mon Sep 17 00:00:00 2001 From: Maksym Arutyunyan Date: Wed, 22 May 2024 11:48:42 +0000 Subject: [PATCH 1/8] add rust/canister_logs --- rust/canister_logs/Cargo.lock | 482 +++++++++++++++++++++++++ rust/canister_logs/Cargo.toml | 12 + rust/canister_logs/README.md | 125 +++++++ rust/canister_logs/canister_logs.did | 7 + rust/canister_logs/dfx.json | 16 + rust/canister_logs/package-lock.json | 7 + rust/canister_logs/poll_logs.sh | 26 ++ rust/canister_logs/rust-toolchain.toml | 4 + rust/canister_logs/src/lib.rs | 32 ++ 9 files changed, 711 insertions(+) create mode 100644 rust/canister_logs/Cargo.lock create mode 100644 rust/canister_logs/Cargo.toml create mode 100644 rust/canister_logs/README.md create mode 100644 rust/canister_logs/canister_logs.did create mode 100644 rust/canister_logs/dfx.json create mode 100644 rust/canister_logs/package-lock.json create mode 100755 rust/canister_logs/poll_logs.sh create mode 100644 rust/canister_logs/rust-toolchain.toml create mode 100644 rust/canister_logs/src/lib.rs diff --git a/rust/canister_logs/Cargo.lock b/rust/canister_logs/Cargo.lock new file mode 100644 index 000000000..3144e1701 --- /dev/null +++ b/rust/canister_logs/Cargo.lock @@ -0,0 +1,482 @@ +# This file is automatically @generated by Cargo. +# It is not intended for manual editing. +version = 3 + +[[package]] +name = "anyhow" +version = "1.0.86" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b3d1d046238990b9cf5bcde22a3fb3584ee5cf65fb2765f454ed428c7a0063da" + +[[package]] +name = "arrayvec" +version = "0.5.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "23b62fc65de8e4e7f52534fb52b0f3ed04746ae267519eef2a83941e8085068b" + +[[package]] +name = "autocfg" +version = "1.3.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0c4b4d0bd25bd0b74681c0ad21497610ce1b7c91b1022cd21c80c6fbdd9476b0" + +[[package]] +name = "binread" +version = "2.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "16598dfc8e6578e9b597d9910ba2e73618385dc9f4b1d43dd92c349d6be6418f" +dependencies = [ + "binread_derive", + "lazy_static", + "rustversion", +] + +[[package]] +name = "binread_derive" +version = "2.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1d9672209df1714ee804b1f4d4f68c8eb2a90b1f7a07acf472f88ce198ef1fed" +dependencies = [ + "either", + "proc-macro2", + "quote", + "syn 1.0.109", +] + +[[package]] +name = "block-buffer" +version = "0.10.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3078c7629b62d3f0439517fa394996acacc5cbc91c5a20d8c658e77abd503a71" +dependencies = [ + "generic-array", +] + +[[package]] +name = "byteorder" +version = "1.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1fd0f2584146f6f2ef48085050886acf353beff7305ebd1ae69500e27c67f64b" + +[[package]] +name = "candid" +version = "0.10.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "dd5902d37352dffd8bd9177a2daa6444ce3cd0279c91763fb0171c053aa04335" +dependencies = [ + "anyhow", + "binread", + "byteorder", + "candid_derive", + "hex", + "ic_principal", + "leb128", + "num-bigint", + "num-traits", + "paste", + "pretty", + "serde", + "serde_bytes", + "stacker", + "thiserror", +] + +[[package]] +name = "candid_derive" +version = "0.6.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3de398570c386726e7a59d9887b68763c481477f9a043fb998a2e09d428df1a9" +dependencies = [ + "lazy_static", + "proc-macro2", + "quote", + "syn 2.0.65", +] + +[[package]] +name = "canister_logs" +version = "1.1.0" +dependencies = [ + "candid", + "ic-cdk", + "ic-cdk-macros", +] + +[[package]] +name = "cc" +version = "1.0.98" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "41c270e7540d725e65ac7f1b212ac8ce349719624d7bcff99f8e2e488e8cf03f" + +[[package]] +name = "cfg-if" +version = "1.0.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "baf1de4339761588bc0619e3cbc0120ee582ebb74b53b4efbf79117bd2da40fd" + +[[package]] +name = "cpufeatures" +version = "0.2.12" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "53fe5e26ff1b7aef8bca9c6080520cfb8d9333c7568e1829cef191a9723e5504" +dependencies = [ + "libc", +] + +[[package]] +name = "crc32fast" +version = "1.4.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a97769d94ddab943e4510d138150169a2758b5ef3eb191a9ee688de3e23ef7b3" +dependencies = [ + "cfg-if", +] + +[[package]] +name = "crypto-common" +version = "0.1.6" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1bfb12502f3fc46cca1bb51ac28df9d618d813cdc3d2f25b9fe775a34af26bb3" +dependencies = [ + "generic-array", + "typenum", +] + +[[package]] +name = "data-encoding" +version = "2.6.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e8566979429cf69b49a5c740c60791108e86440e8be149bbea4fe54d2c32d6e2" + +[[package]] +name = "digest" +version = "0.10.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9ed9a281f7bc9b7576e61468ba615a66a5c8cfdff42420a70aa82701a3b1e292" +dependencies = [ + "block-buffer", + "crypto-common", +] + +[[package]] +name = "either" +version = "1.12.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3dca9240753cf90908d7e4aac30f630662b02aebaa1b58a3cadabdb23385b58b" + +[[package]] +name = "generic-array" +version = "0.14.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "85649ca51fd72272d7821adaf274ad91c288277713d9c18820d8499a7ff69e9a" +dependencies = [ + "typenum", + "version_check", +] + +[[package]] +name = "hex" +version = "0.4.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7f24254aa9a54b5c858eaee2f5bccdb46aaf0e486a595ed5fd8f86ba55232a70" + +[[package]] +name = "ic-cdk" +version = "0.12.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9f3d204af0b11c45715169c997858edb58fa8407d08f4fae78a6b415dd39a362" +dependencies = [ + "candid", + "ic-cdk-macros", + "ic0", + "serde", + "serde_bytes", +] + +[[package]] +name = "ic-cdk-macros" +version = "0.8.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a5a618e4020cea88e933d8d2f8c7f86d570ec06213506a80d4f2c520a9bba512" +dependencies = [ + "candid", + "proc-macro2", + "quote", + "serde", + "serde_tokenstream", + "syn 1.0.109", +] + +[[package]] +name = "ic0" +version = "0.21.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a54b5297861c651551676e8c43df805dad175cc33bc97dbd992edbbb85dcbcdf" + +[[package]] +name = "ic_principal" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1762deb6f7c8d8c2bdee4b6c5a47b60195b74e9b5280faa5ba29692f8e17429c" +dependencies = [ + "crc32fast", + "data-encoding", + "serde", + "sha2", + "thiserror", +] + +[[package]] +name = "lazy_static" +version = "1.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e2abad23fbc42b3700f2f279844dc832adb2b2eb069b2df918f455c4e18cc646" + +[[package]] +name = "leb128" +version = "0.2.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "884e2677b40cc8c339eaefcb701c32ef1fd2493d71118dc0ca4b6a736c93bd67" + +[[package]] +name = "libc" +version = "0.2.155" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "97b3888a4aecf77e811145cadf6eef5901f4782c53886191b2f693f24761847c" + +[[package]] +name = "num-bigint" +version = "0.4.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c165a9ab64cf766f73521c0dd2cfdff64f488b8f0b3e621face3462d3db536d7" +dependencies = [ + "num-integer", + "num-traits", + "serde", +] + +[[package]] +name = "num-integer" +version = "0.1.46" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7969661fd2958a5cb096e56c8e1ad0444ac2bbcd0061bd28660485a44879858f" +dependencies = [ + "num-traits", +] + +[[package]] +name = "num-traits" +version = "0.2.19" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "071dfc062690e90b734c0b2273ce72ad0ffa95f0c74596bc250dcfd960262841" +dependencies = [ + "autocfg", +] + +[[package]] +name = "paste" +version = "1.0.15" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "57c0d7b74b563b49d38dae00a0c37d4d6de9b432382b2892f0574ddcae73fd0a" + +[[package]] +name = "pretty" +version = "0.12.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "b55c4d17d994b637e2f4daf6e5dc5d660d209d5642377d675d7a1c3ab69fa579" +dependencies = [ + "arrayvec", + "typed-arena", + "unicode-width", +] + +[[package]] +name = "proc-macro2" +version = "1.0.83" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0b33eb56c327dec362a9e55b3ad14f9d2f0904fb5a5b03b513ab5465399e9f43" +dependencies = [ + "unicode-ident", +] + +[[package]] +name = "psm" +version = "0.1.21" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5787f7cda34e3033a72192c018bc5883100330f362ef279a8cbccfce8bb4e874" +dependencies = [ + "cc", +] + +[[package]] +name = "quote" +version = "1.0.36" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "0fa76aaf39101c457836aec0ce2316dbdc3ab723cdda1c6bd4e6ad4208acaca7" +dependencies = [ + "proc-macro2", +] + +[[package]] +name = "rustversion" +version = "1.0.17" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "955d28af4278de8121b7ebeb796b6a45735dc01436d898801014aced2773a3d6" + +[[package]] +name = "serde" +version = "1.0.202" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "226b61a0d411b2ba5ff6d7f73a476ac4f8bb900373459cd00fab8512828ba395" +dependencies = [ + "serde_derive", +] + +[[package]] +name = "serde_bytes" +version = "0.11.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8b8497c313fd43ab992087548117643f6fcd935cbf36f176ffda0aacf9591734" +dependencies = [ + "serde", +] + +[[package]] +name = "serde_derive" +version = "1.0.202" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6048858004bcff69094cd972ed40a32500f153bd3be9f716b2eed2e8217c4838" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.65", +] + +[[package]] +name = "serde_tokenstream" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "797ba1d80299b264f3aac68ab5d12e5825a561749db4df7cd7c8083900c5d4e9" +dependencies = [ + "proc-macro2", + "serde", + "syn 1.0.109", +] + +[[package]] +name = "sha2" +version = "0.10.8" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "793db75ad2bcafc3ffa7c68b215fee268f537982cd901d132f89c6343f3a3dc8" +dependencies = [ + "cfg-if", + "cpufeatures", + "digest", +] + +[[package]] +name = "stacker" +version = "0.1.15" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c886bd4480155fd3ef527d45e9ac8dd7118a898a46530b7b94c3e21866259fce" +dependencies = [ + "cc", + "cfg-if", + "libc", + "psm", + "winapi", +] + +[[package]] +name = "syn" +version = "1.0.109" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "72b64191b275b66ffe2469e8af2c1cfe3bafa67b529ead792a6d0160888b4237" +dependencies = [ + "proc-macro2", + "quote", + "unicode-ident", +] + +[[package]] +name = "syn" +version = "2.0.65" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d2863d96a84c6439701d7a38f9de935ec562c8832cc55d1dde0f513b52fad106" +dependencies = [ + "proc-macro2", + "quote", + "unicode-ident", +] + +[[package]] +name = "thiserror" +version = "1.0.61" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "c546c80d6be4bc6a00c0f01730c08df82eaa7a7a61f11d656526506112cc1709" +dependencies = [ + "thiserror-impl", +] + +[[package]] +name = "thiserror-impl" +version = "1.0.61" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "46c3384250002a6d5af4d114f2845d37b57521033f30d5c3f46c4d70e1197533" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.65", +] + +[[package]] +name = "typed-arena" +version = "2.0.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6af6ae20167a9ece4bcb41af5b80f8a1f1df981f6391189ce00fd257af04126a" + +[[package]] +name = "typenum" +version = "1.17.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "42ff0bf0c66b8238c6f3b578df37d0b7848e55df8577b3f74f92a69acceeb825" + +[[package]] +name = "unicode-ident" +version = "1.0.12" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3354b9ac3fae1ff6755cb6db53683adb661634f67557942dea4facebec0fee4b" + +[[package]] +name = "unicode-width" +version = "0.1.12" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "68f5e5f3158ecfd4b8ff6fe086db7c8467a2dfdac97fe420f2b7c4aa97af66d6" + +[[package]] +name = "version_check" +version = "0.9.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "49874b5167b65d7193b8aba1567f5c7d93d001cafc34600cee003eda787e483f" + +[[package]] +name = "winapi" +version = "0.3.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5c839a674fcd7a98952e593242ea400abe93992746761e38641405d28b00f419" +dependencies = [ + "winapi-i686-pc-windows-gnu", + "winapi-x86_64-pc-windows-gnu", +] + +[[package]] +name = "winapi-i686-pc-windows-gnu" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ac3b87c63620426dd9b991e5ce0329eff545bccbbb34f3be09ff6fb6ab51b7b6" + +[[package]] +name = "winapi-x86_64-pc-windows-gnu" +version = "0.4.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "712e227841d057c1ee1cd2fb22fa7e5a5461ae8e48fa2ca79ec42cfc1931183f" diff --git a/rust/canister_logs/Cargo.toml b/rust/canister_logs/Cargo.toml new file mode 100644 index 000000000..e824b9cf9 --- /dev/null +++ b/rust/canister_logs/Cargo.toml @@ -0,0 +1,12 @@ +[package] +edition = "2021" +name = "canister_logs" +version = "1.1.0" + +[lib] +crate-type = ["cdylib"] + +[dependencies] +candid = "0.10" +ic-cdk = "0.12" +ic-cdk-macros = "0.8" diff --git a/rust/canister_logs/README.md b/rust/canister_logs/README.md new file mode 100644 index 000000000..4ead862d5 --- /dev/null +++ b/rust/canister_logs/README.md @@ -0,0 +1,125 @@ +--- +keywords: [beginner, rust, canister logs, logging] +--- + +# Canister logs + +[View this sample's code on GitHub](https://github.com/dfinity/examples/tree/master/rust/canister_logs) + +## Prerequisites +This example requires an installation of: + +- [x] Install the [IC SDK](https://internetcomputer.org/docs/current/developer-docs/setup/install/). +- [x] Download the following project files from GitHub: `git clone https://github.com/dfinity/examples/` + +You will need to have 3 terminal windows: +- Terminal A: Running a DFX instance and separating its output from anything else +- Terminal B: Deploying a canister and seeing its output +- Terminal C: Reading logs interactively + +### Step 1: Navigate into the folder containing the project's files and start a local instance of the replica with the command: + +```shell +# Terminal A -- for running DFX and separating its output from anything else. +$ cd examples/rust/canister_logs +$ dfx start --clean + +# Terminal B -- for deploying the canister and calling its methods. +$ cd examples/rust/canister_logs + +# Terminal C -- for polling logs. +$ cd examples/rust/canister_logs +``` + +### Step 2: Deploy the canister: + +```shell +# Terminal B +$ dfx deploy +``` + +### Step 3: Check canister has no logs yet: + +```shell +# Terminal B +$ dfx canister logs canister_logs + +# Expect to see no logs. +``` + +### Step 4: Call `print` method and check the logs: + +```shell +# Terminal B +$ dfx canister call canister_logs print hi +() + +# Expect to see new log entry. +$ dfx canister logs canister_logs +[0. 2024-05-22T11:37:28.080234848Z]: hi +``` + +### Step 5: Start constantly polling logs: + +In order not to call `dfx canister logs canister_logs` after every canister call in a separate terminal window/pane C start a script that will constantly poll logs: + +```shell +# Terminal C +$ ./poll_logs.sh +[0. 2024-05-22T11:37:28.080234848Z]: hi + +``` + +### Step 6: Call `print`, `trap`, `panic` and other canister methods: + +```shell +# Terminal B +$ dfx canister call canister_logs print hi! +() + +$ dfx canister call canister_logs print hello! +() + +$ dfx canister call canister_logs print yey! +() + +$ dfx canister call canister_logs trap oops! +Error: Failed update call. +Caused by: Failed update call. + The replica returned a rejection error: reject code CanisterError, reject message Canister bkyz2-fmaaa-aaaaa-qaaaq-cai trapped explicitly: oops!, error code None + +$ dfx canister call canister_logs panic aaa! +Error: Failed update call. +Caused by: Failed update call. + The replica returned a rejection error: reject code CanisterError, reject message Canister bkyz2-fmaaa-aaaaa-qaaaq-cai trapped explicitly: Panicked at 'aaa!', src/lib.rs:17:5, error code None + +$ dfx canister call canister_logs memory_oob +Error: Failed update call. +Caused by: Failed update call. + The replica returned a rejection error: reject code CanisterError, reject message Canister bkyz2-fmaaa-aaaaa-qaaaq-cai trapped: stable memory out of bounds, error code None + +$ dfx canister call canister_logs failed_unwrap +Error: Failed update call. +Caused by: Failed update call. + The replica returned a rejection error: reject code CanisterError, reject message Canister bkyz2-fmaaa-aaaaa-qaaaq-cai trapped explicitly: Panicked at 'called `Result::unwrap()` on an `Err` value: FromUtf8Error { bytes: [192, 255, 238], error: Utf8Error { valid_up_to: 0, error_len: Some(1) } }', src/lib.rs:31:47, error code None + +``` + +Observe recorded logs that might look similar to this: + +```shell +# Terminal C +[0. 2024-05-22T11:37:28.080234848Z]: hi +[1. 2024-05-22T11:43:32.152363971Z]: hello! +[2. 2024-05-22T11:43:36.317710491Z]: yey! +[3. 2024-05-22T11:43:40.592174915Z]: right before trap +[4. 2024-05-22T11:43:40.592174915Z]: [TRAP]: oops! +[5. 2024-05-22T11:43:49.904081741Z]: right before panic +[6. 2024-05-22T11:43:49.904081741Z]: Panicked at 'aaa!', src/lib.rs:17:5 +[7. 2024-05-22T11:43:49.904081741Z]: [TRAP]: Panicked at 'aaa!', src/lib.rs:17:5 +[8. 2024-05-22T11:43:54.400015642Z]: right before memory out of bounds +[9. 2024-05-22T11:43:54.400015642Z]: [TRAP]: stable memory out of bounds +[10. 2024-05-22T11:43:59.810358166Z]: right before failed unwrap +[11. 2024-05-22T11:43:59.810358166Z]: Panicked at 'called `Result::unwrap()` on an `Err` value: FromUtf8Error { bytes: [192, 255, 238], error: Utf8Error { valid_up_to: 0, error_len: Some(1) } }', src/lib.rs:31:47 +[12. 2024-05-22T11:43:59.810358166Z]: [TRAP]: Panicked at 'called `Result::unwrap()` on an `Err` value: FromUtf8Error { bytes: [192, 255, 238], error: Utf8Error { valid_up_to: 0, error_len: Some(1) } }', src/lib.rs:31:47 +``` diff --git a/rust/canister_logs/canister_logs.did b/rust/canister_logs/canister_logs.did new file mode 100644 index 000000000..2f372483b --- /dev/null +++ b/rust/canister_logs/canister_logs.did @@ -0,0 +1,7 @@ +service : { + "print" : (text) -> (); + "trap" : (text) -> (); + "panic" : (text) -> (); + "memory_oob" : () -> (); + "failed_unwrap" : () -> (); +}; \ No newline at end of file diff --git a/rust/canister_logs/dfx.json b/rust/canister_logs/dfx.json new file mode 100644 index 000000000..a5c583f21 --- /dev/null +++ b/rust/canister_logs/dfx.json @@ -0,0 +1,16 @@ +{ + "canisters": { + "canister_logs": { + "candid": "canister_logs.did", + "package": "canister_logs", + "type": "rust" + } + }, + "defaults": { + "build": { + "args": "", + "packtool": "" + } + }, + "version": 1 +} diff --git a/rust/canister_logs/package-lock.json b/rust/canister_logs/package-lock.json new file mode 100644 index 000000000..5f7a67cc6 --- /dev/null +++ b/rust/canister_logs/package-lock.json @@ -0,0 +1,7 @@ +{ + "name": "canister_logs", + "lockfileVersion": 3, + "requires": true, + "packages": {} + } + \ No newline at end of file diff --git a/rust/canister_logs/poll_logs.sh b/rust/canister_logs/poll_logs.sh new file mode 100755 index 000000000..5e2bdef20 --- /dev/null +++ b/rust/canister_logs/poll_logs.sh @@ -0,0 +1,26 @@ +#!/bin/bash + +# Function to fetch logs and filter out new lines +fetch_and_filter_logs() { + # Fetch logs + new_logs=$(dfx canister logs canister_logs) + + # Compare with previous logs to find new ones + while IFS= read -r line; do + if [[ ! "${previous_logs[*]}" =~ "$line" ]]; then + echo "$line" + fi + done <<< "$new_logs" + + # Update previous logs + previous_logs=("$new_logs") +} + +# Initial fetch and filter +fetch_and_filter_logs + +# Infinite loop to continuously fetch and filter logs +while true; do + fetch_and_filter_logs + sleep 1 +done \ No newline at end of file diff --git a/rust/canister_logs/rust-toolchain.toml b/rust/canister_logs/rust-toolchain.toml new file mode 100644 index 000000000..435fefb78 --- /dev/null +++ b/rust/canister_logs/rust-toolchain.toml @@ -0,0 +1,4 @@ +[toolchain] +channel = "1.74" +targets = ["wasm32-unknown-unknown"] +components = ["rustfmt", "clippy"] \ No newline at end of file diff --git a/rust/canister_logs/src/lib.rs b/rust/canister_logs/src/lib.rs new file mode 100644 index 000000000..983e6cff5 --- /dev/null +++ b/rust/canister_logs/src/lib.rs @@ -0,0 +1,32 @@ +use ic_cdk::update; + +#[update] +fn print(text: String) { + ic_cdk::print(text); +} + +#[update] +fn trap(message: String) { + ic_cdk::print("right before trap"); + ic_cdk::trap(&message); +} + +#[update] +fn panic(message: String) { + ic_cdk::print("right before panic"); + panic!("{}", message); +} + +#[update] +fn memory_oob() { + ic_cdk::print("right before memory out of bounds"); + const BUFFER_SIZE: u32 = 10; + let mut buffer = vec![0u8; BUFFER_SIZE as usize]; + ic_cdk::api::stable::stable_read(BUFFER_SIZE + 1, &mut buffer); // Reading memory outside of buffer should trap. +} + +#[update] +fn failed_unwrap() { + ic_cdk::print("right before failed unwrap"); + String::from_utf8(vec![0xc0, 0xff, 0xee]).unwrap(); // Invalid utf8 should panic. +} From 84367ac37b77ac42aa4dd0ec8358db02075e9330 Mon Sep 17 00:00:00 2001 From: Maksym Arutyunyan Date: Wed, 22 May 2024 12:23:12 +0000 Subject: [PATCH 2/8] add motoko version --- motoko/canister_logs/README.md | 103 ++++++++++++++++++++++++++++++ motoko/canister_logs/dfx.json | 14 ++++ motoko/canister_logs/poll_logs.sh | 26 ++++++++ motoko/canister_logs/src/Main.mo | 14 ++++ 4 files changed, 157 insertions(+) create mode 100644 motoko/canister_logs/README.md create mode 100644 motoko/canister_logs/dfx.json create mode 100755 motoko/canister_logs/poll_logs.sh create mode 100644 motoko/canister_logs/src/Main.mo diff --git a/motoko/canister_logs/README.md b/motoko/canister_logs/README.md new file mode 100644 index 000000000..7c4d8f35f --- /dev/null +++ b/motoko/canister_logs/README.md @@ -0,0 +1,103 @@ +--- +keywords: [beginner, motoko, canister logs, logging] +--- + +# Canister logs + +[View this sample's code on GitHub](https://github.com/dfinity/examples/tree/master/motoko/canister_logs) + +## Prerequisites +This example requires an installation of: + +- [x] Install the [IC SDK](https://internetcomputer.org/docs/current/developer-docs/setup/install/). +- [x] Download the following project files from GitHub: `git clone https://github.com/dfinity/examples/` + +You will need to have 3 terminal windows: +- Terminal A: Running a DFX instance and separating its output from anything else +- Terminal B: Deploying a canister and seeing its output +- Terminal C: Reading logs interactively + +### Step 1: Navigate into the folder containing the project's files and start a local instance of the replica with the command: + +```shell +# Terminal A -- for running DFX and separating its output from anything else. +$ cd examples/motoko/canister_logs +$ dfx start --clean + +# Terminal B -- for deploying the canister and calling its methods. +$ cd examples/motoko/canister_logs + +# Terminal C -- for polling logs. +$ cd examples/motoko/canister_logs +``` + +### Step 2: Deploy the canister: + +```shell +# Terminal B +$ dfx deploy +``` + +### Step 3: Check canister has no logs yet: + +```shell +# Terminal B +$ dfx canister logs CanisterLogs + +# Expect to see no logs. +``` + +### Step 4: Call `print` method and check the logs: + +```shell +# Terminal B +$ dfx canister call CanisterLogs print hi +() + +# Expect to see new log entry. +$ dfx canister logs CanisterLogs +[0. 2024-05-22T11:37:28.080234848Z]: hi +``` + +### Step 5: Start constantly polling logs: + +In order not to call `dfx canister logs CanisterLogs` after every canister call in a separate terminal window/pane C start a script that will constantly poll logs: + +```shell +# Terminal C +$ ./poll_logs.sh +[0. 2024-05-22T11:37:28.080234848Z]: hi + +``` + +### Step 6: Call `print`, `trap`, `panic` and other canister methods: + +```shell +# Terminal B +$ dfx canister call CanisterLogs print hi! +() + +$ dfx canister call CanisterLogs print hello! +() + +$ dfx canister call CanisterLogs print yey! +() + +$ dfx canister call CanisterLogs trap oops! +Error: Failed update call. +Caused by: Failed update call. + The replica returned a rejection error: reject code CanisterError, reject message Canister bkyz2-fmaaa-aaaaa-qaaaq-cai trapped explicitly: oops!, error code None + +``` + +Observe recorded logs that might look similar to this: + +```shell +# Terminal C +[0. 2024-05-22T12:21:52.333589617Z]: hi +[1. 2024-05-22T12:22:27.330332077Z]: hello! +[2. 2024-05-22T12:22:32.062734677Z]: yey! +[3. 2024-05-22T12:22:36.685104375Z]: right before trap +[4. 2024-05-22T12:22:36.685104375Z]: [TRAP]: oops! + +``` diff --git a/motoko/canister_logs/dfx.json b/motoko/canister_logs/dfx.json new file mode 100644 index 000000000..35944ab10 --- /dev/null +++ b/motoko/canister_logs/dfx.json @@ -0,0 +1,14 @@ +{ + "version": 1, + "canisters": { + "CanisterLogs": { + "type": "motoko", + "main": "src/Main.mo" + } + }, + "defaults": { + "build": { + "packtool": "" + } + } +} diff --git a/motoko/canister_logs/poll_logs.sh b/motoko/canister_logs/poll_logs.sh new file mode 100755 index 000000000..ae688c15e --- /dev/null +++ b/motoko/canister_logs/poll_logs.sh @@ -0,0 +1,26 @@ +#!/bin/bash + +# Function to fetch logs and filter out new lines +fetch_and_filter_logs() { + # Fetch logs + new_logs=$(dfx canister logs CanisterLogs) + + # Compare with previous logs to find new ones + while IFS= read -r line; do + if [[ ! "${previous_logs[*]}" =~ "$line" ]]; then + echo "$line" + fi + done <<< "$new_logs" + + # Update previous logs + previous_logs=("$new_logs") +} + +# Initial fetch and filter +fetch_and_filter_logs + +# Infinite loop to continuously fetch and filter logs +while true; do + fetch_and_filter_logs + sleep 1 +done \ No newline at end of file diff --git a/motoko/canister_logs/src/Main.mo b/motoko/canister_logs/src/Main.mo new file mode 100644 index 000000000..3aeac1ea8 --- /dev/null +++ b/motoko/canister_logs/src/Main.mo @@ -0,0 +1,14 @@ +import Debug "mo:base/Debug"; + +actor CanisterLogs { + + public func print(text : Text) : async () { + Debug.print(text); + }; + + public func trap(text : Text) : async () { + Debug.print("right before trap"); + Debug.trap(text); + }; + +}; From 8b498481e595fb02c345b0419debc1891a4e6fc5 Mon Sep 17 00:00:00 2001 From: Maksym Arutyunyan Date: Wed, 22 May 2024 12:23:53 +0000 Subject: [PATCH 3/8] . --- motoko/canister_logs/poll_logs.sh | 2 +- rust/canister_logs/poll_logs.sh | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/motoko/canister_logs/poll_logs.sh b/motoko/canister_logs/poll_logs.sh index ae688c15e..71d03f337 100755 --- a/motoko/canister_logs/poll_logs.sh +++ b/motoko/canister_logs/poll_logs.sh @@ -23,4 +23,4 @@ fetch_and_filter_logs while true; do fetch_and_filter_logs sleep 1 -done \ No newline at end of file +done diff --git a/rust/canister_logs/poll_logs.sh b/rust/canister_logs/poll_logs.sh index 5e2bdef20..7c839ada3 100755 --- a/rust/canister_logs/poll_logs.sh +++ b/rust/canister_logs/poll_logs.sh @@ -23,4 +23,4 @@ fetch_and_filter_logs while true; do fetch_and_filter_logs sleep 1 -done \ No newline at end of file +done From f9f465abac9c647190df6ffc59e93587a556f6a1 Mon Sep 17 00:00:00 2001 From: Maksym Arutyunyan Date: Wed, 22 May 2024 12:25:24 +0000 Subject: [PATCH 4/8] . --- rust/canister_logs/canister_logs.did | 2 +- rust/canister_logs/rust-toolchain.toml | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/rust/canister_logs/canister_logs.did b/rust/canister_logs/canister_logs.did index 2f372483b..ac8bc93fe 100644 --- a/rust/canister_logs/canister_logs.did +++ b/rust/canister_logs/canister_logs.did @@ -4,4 +4,4 @@ service : { "panic" : (text) -> (); "memory_oob" : () -> (); "failed_unwrap" : () -> (); -}; \ No newline at end of file +}; diff --git a/rust/canister_logs/rust-toolchain.toml b/rust/canister_logs/rust-toolchain.toml index 435fefb78..f8bb13962 100644 --- a/rust/canister_logs/rust-toolchain.toml +++ b/rust/canister_logs/rust-toolchain.toml @@ -1,4 +1,4 @@ [toolchain] channel = "1.74" targets = ["wasm32-unknown-unknown"] -components = ["rustfmt", "clippy"] \ No newline at end of file +components = ["rustfmt", "clippy"] From 81861bf8613a9e2c069392a52cda89c6da4b3c11 Mon Sep 17 00:00:00 2001 From: Maksym Arutyunyan Date: Wed, 22 May 2024 12:39:22 +0000 Subject: [PATCH 5/8] add timer traps example --- rust/canister_logs/Cargo.lock | 173 +++++++++++++++++++++++++++++++++- rust/canister_logs/Cargo.toml | 1 + rust/canister_logs/README.md | 71 ++++++++++---- rust/canister_logs/src/lib.rs | 22 ++++- 4 files changed, 246 insertions(+), 21 deletions(-) diff --git a/rust/canister_logs/Cargo.lock b/rust/canister_logs/Cargo.lock index 3144e1701..06ea8bc55 100644 --- a/rust/canister_logs/Cargo.lock +++ b/rust/canister_logs/Cargo.lock @@ -98,8 +98,9 @@ name = "canister_logs" version = "1.1.0" dependencies = [ "candid", - "ic-cdk", - "ic-cdk-macros", + "ic-cdk 0.12.1", + "ic-cdk-macros 0.8.4", + "ic-cdk-timers", ] [[package]] @@ -164,6 +165,95 @@ version = "1.12.0" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "3dca9240753cf90908d7e4aac30f630662b02aebaa1b58a3cadabdb23385b58b" +[[package]] +name = "futures" +version = "0.3.30" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "645c6916888f6cb6350d2550b80fb63e734897a8498abe35cfb732b6487804b0" +dependencies = [ + "futures-channel", + "futures-core", + "futures-executor", + "futures-io", + "futures-sink", + "futures-task", + "futures-util", +] + +[[package]] +name = "futures-channel" +version = "0.3.30" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "eac8f7d7865dcb88bd4373ab671c8cf4508703796caa2b1985a9ca867b3fcb78" +dependencies = [ + "futures-core", + "futures-sink", +] + +[[package]] +name = "futures-core" +version = "0.3.30" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "dfc6580bb841c5a68e9ef15c77ccc837b40a7504914d52e47b8b0e9bbda25a1d" + +[[package]] +name = "futures-executor" +version = "0.3.30" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a576fc72ae164fca6b9db127eaa9a9dda0d61316034f33a0a0d4eda41f02b01d" +dependencies = [ + "futures-core", + "futures-task", + "futures-util", +] + +[[package]] +name = "futures-io" +version = "0.3.30" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a44623e20b9681a318efdd71c299b6b222ed6f231972bfe2f224ebad6311f0c1" + +[[package]] +name = "futures-macro" +version = "0.3.30" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "87750cf4b7a4c0625b1529e4c543c2182106e4dedc60a2a6455e00d212c489ac" +dependencies = [ + "proc-macro2", + "quote", + "syn 2.0.65", +] + +[[package]] +name = "futures-sink" +version = "0.3.30" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "9fb8e00e87438d937621c1c6269e53f536c14d3fbd6a042bb24879e57d474fb5" + +[[package]] +name = "futures-task" +version = "0.3.30" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "38d84fa142264698cdce1a9f9172cf383a0c82de1bddcf3092901442c4097004" + +[[package]] +name = "futures-util" +version = "0.3.30" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3d6401deb83407ab3da39eba7e33987a73c3df0c82b4bb5813ee871c19c41d48" +dependencies = [ + "futures-channel", + "futures-core", + "futures-io", + "futures-macro", + "futures-sink", + "futures-task", + "memchr", + "pin-project-lite", + "pin-utils", + "slab", +] + [[package]] name = "generic-array" version = "0.14.7" @@ -187,7 +277,20 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "9f3d204af0b11c45715169c997858edb58fa8407d08f4fae78a6b415dd39a362" dependencies = [ "candid", - "ic-cdk-macros", + "ic-cdk-macros 0.8.4", + "ic0", + "serde", + "serde_bytes", +] + +[[package]] +name = "ic-cdk" +version = "0.13.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f8859bc2b863a77750acf199e1fb7e3fc403e1b475855ba13f59cb4e4036d238" +dependencies = [ + "candid", + "ic-cdk-macros 0.13.2", "ic0", "serde", "serde_bytes", @@ -207,6 +310,34 @@ dependencies = [ "syn 1.0.109", ] +[[package]] +name = "ic-cdk-macros" +version = "0.13.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "a45800053d80a6df839a71aaea5797e723188c0b992618208ca3b941350c7355" +dependencies = [ + "candid", + "proc-macro2", + "quote", + "serde", + "serde_tokenstream", + "syn 1.0.109", +] + +[[package]] +name = "ic-cdk-timers" +version = "0.7.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "054727a3a1c486528b96349817d54290ff70df6addf417def456ea708a16f7fb" +dependencies = [ + "futures", + "ic-cdk 0.13.2", + "ic0", + "serde", + "serde_bytes", + "slotmap", +] + [[package]] name = "ic0" version = "0.21.1" @@ -244,6 +375,12 @@ version = "0.2.155" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "97b3888a4aecf77e811145cadf6eef5901f4782c53886191b2f693f24761847c" +[[package]] +name = "memchr" +version = "2.7.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6c8640c5d730cb13ebd907d8d04b52f55ac9a2eec55b440c8892f40d56c76c1d" + [[package]] name = "num-bigint" version = "0.4.5" @@ -279,6 +416,18 @@ version = "1.0.15" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "57c0d7b74b563b49d38dae00a0c37d4d6de9b432382b2892f0574ddcae73fd0a" +[[package]] +name = "pin-project-lite" +version = "0.2.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bda66fc9667c18cb2758a2ac84d1167245054bcf85d5d1aaa6923f45801bdd02" + +[[package]] +name = "pin-utils" +version = "0.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8b870d8c151b6f2fb93e84a13146138f05d02ed11c7e7c54f8826aaaf7c9f184" + [[package]] name = "pretty" version = "0.12.3" @@ -374,6 +523,24 @@ dependencies = [ "digest", ] +[[package]] +name = "slab" +version = "0.4.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "8f92a496fb766b417c996b9c5e57daf2f7ad3b0bebe1ccfca4856390e3d3bb67" +dependencies = [ + "autocfg", +] + +[[package]] +name = "slotmap" +version = "1.0.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "dbff4acf519f630b3a3ddcfaea6c06b42174d9a44bc70c620e9ed1649d58b82a" +dependencies = [ + "version_check", +] + [[package]] name = "stacker" version = "0.1.15" diff --git a/rust/canister_logs/Cargo.toml b/rust/canister_logs/Cargo.toml index e824b9cf9..89cc20a2e 100644 --- a/rust/canister_logs/Cargo.toml +++ b/rust/canister_logs/Cargo.toml @@ -10,3 +10,4 @@ crate-type = ["cdylib"] candid = "0.10" ic-cdk = "0.12" ic-cdk-macros = "0.8" +ic-cdk-timers = "0.7" diff --git a/rust/canister_logs/README.md b/rust/canister_logs/README.md index 4ead862d5..7d5d7f7ad 100644 --- a/rust/canister_logs/README.md +++ b/rust/canister_logs/README.md @@ -38,13 +38,17 @@ $ cd examples/rust/canister_logs $ dfx deploy ``` -### Step 3: Check canister has no logs yet: +### Step 3: Check canister logs: ```shell # Terminal B $ dfx canister logs canister_logs +# Expect to see logs from timer traps. +[0. 2024-05-22T12:35:32.050252022Z]: right before timer trap +[1. 2024-05-22T12:35:32.050252022Z]: [TRAP]: timer trap +[2. 2024-05-22T12:35:37.680315152Z]: right before timer trap +[3. 2024-05-22T12:35:37.680315152Z]: [TRAP]: timer trap -# Expect to see no logs. ``` ### Step 4: Call `print` method and check the logs: @@ -56,7 +60,16 @@ $ dfx canister call canister_logs print hi # Expect to see new log entry. $ dfx canister logs canister_logs -[0. 2024-05-22T11:37:28.080234848Z]: hi +... +[16. 2024-05-22T12:36:15.638667167Z]: right before timer trap +[17. 2024-05-22T12:36:15.638667167Z]: [TRAP]: timer trap +[18. 2024-05-22T12:36:20.881326098Z]: right before timer trap +[19. 2024-05-22T12:36:20.881326098Z]: [TRAP]: timer trap +[20. 2024-05-22T12:36:26.305162772Z]: hi +[21. 2024-05-22T12:36:27.185879186Z]: right before timer trap +[22. 2024-05-22T12:36:27.185879186Z]: [TRAP]: timer trap +[23. 2024-05-22T12:36:33.486805581Z]: right before timer trap +[24. 2024-05-22T12:36:33.486805581Z]: [TRAP]: timer trap ``` ### Step 5: Start constantly polling logs: @@ -66,7 +79,17 @@ In order not to call `dfx canister logs canister_logs` after every canister call ```shell # Terminal C $ ./poll_logs.sh -[0. 2024-05-22T11:37:28.080234848Z]: hi +... +[16. 2024-05-22T12:36:15.638667167Z]: right before timer trap +[17. 2024-05-22T12:36:15.638667167Z]: [TRAP]: timer trap +[18. 2024-05-22T12:36:20.881326098Z]: right before timer trap +[19. 2024-05-22T12:36:20.881326098Z]: [TRAP]: timer trap +[20. 2024-05-22T12:36:26.305162772Z]: hi +[21. 2024-05-22T12:36:27.185879186Z]: right before timer trap +[22. 2024-05-22T12:36:27.185879186Z]: [TRAP]: timer trap +[23. 2024-05-22T12:36:33.486805581Z]: right before timer trap +[24. 2024-05-22T12:36:33.486805581Z]: [TRAP]: timer trap +... ``` @@ -109,17 +132,31 @@ Observe recorded logs that might look similar to this: ```shell # Terminal C -[0. 2024-05-22T11:37:28.080234848Z]: hi -[1. 2024-05-22T11:43:32.152363971Z]: hello! -[2. 2024-05-22T11:43:36.317710491Z]: yey! -[3. 2024-05-22T11:43:40.592174915Z]: right before trap -[4. 2024-05-22T11:43:40.592174915Z]: [TRAP]: oops! -[5. 2024-05-22T11:43:49.904081741Z]: right before panic -[6. 2024-05-22T11:43:49.904081741Z]: Panicked at 'aaa!', src/lib.rs:17:5 -[7. 2024-05-22T11:43:49.904081741Z]: [TRAP]: Panicked at 'aaa!', src/lib.rs:17:5 -[8. 2024-05-22T11:43:54.400015642Z]: right before memory out of bounds -[9. 2024-05-22T11:43:54.400015642Z]: [TRAP]: stable memory out of bounds -[10. 2024-05-22T11:43:59.810358166Z]: right before failed unwrap -[11. 2024-05-22T11:43:59.810358166Z]: Panicked at 'called `Result::unwrap()` on an `Err` value: FromUtf8Error { bytes: [192, 255, 238], error: Utf8Error { valid_up_to: 0, error_len: Some(1) } }', src/lib.rs:31:47 -[12. 2024-05-22T11:43:59.810358166Z]: [TRAP]: Panicked at 'called `Result::unwrap()` on an `Err` value: FromUtf8Error { bytes: [192, 255, 238], error: Utf8Error { valid_up_to: 0, error_len: Some(1) } }', src/lib.rs:31:47 +... +[45. 2024-05-22T12:37:33.0576873Z]: right before timer trap +[46. 2024-05-22T12:37:33.0576873Z]: [TRAP]: timer trap +[47. 2024-05-22T12:37:33.773343176Z]: hi! +[48. 2024-05-22T12:37:37.558075267Z]: hello! +[49. 2024-05-22T12:37:38.349121524Z]: right before timer trap +[50. 2024-05-22T12:37:38.349121524Z]: [TRAP]: timer trap +[51. 2024-05-22T12:37:41.466030479Z]: yey! +[52. 2024-05-22T12:37:43.7472275Z]: right before timer trap +[53. 2024-05-22T12:37:43.7472275Z]: [TRAP]: timer trap +[54. 2024-05-22T12:37:45.302285184Z]: right before trap +[55. 2024-05-22T12:37:45.302285184Z]: [TRAP]: oops! +[56. 2024-05-22T12:37:48.900425146Z]: right before timer trap +[57. 2024-05-22T12:37:48.900425146Z]: [TRAP]: timer trap +[58. 2024-05-22T12:37:49.736443986Z]: right before panic +[59. 2024-05-22T12:37:49.736443986Z]: Panicked at 'aaa!', src/lib.rs:37:5 +[60. 2024-05-22T12:37:49.736443986Z]: [TRAP]: Panicked at 'aaa!', src/lib.rs:37:5 +[61. 2024-05-22T12:37:54.122929037Z]: right before timer trap +[62. 2024-05-22T12:37:54.122929037Z]: [TRAP]: timer trap +[63. 2024-05-22T12:37:54.94948481Z]: right before memory out of bounds +[64. 2024-05-22T12:37:54.94948481Z]: [TRAP]: stable memory out of bounds +[65. 2024-05-22T12:37:59.693695919Z]: right before failed unwrap +[66. 2024-05-22T12:37:59.693695919Z]: Panicked at 'called `Result::unwrap()` on an `Err` value: FromUtf8Error { bytes: [192, 255, 238], error: Utf8Error { valid_up_to: 0, error_len: Some(1) } }', src/lib.rs:51:47 +[67. 2024-05-22T12:37:59.693695919Z]: [TRAP]: Panicked at 'called `Result::unwrap()` on an `Err` value: FromUtf8Error { bytes: [192, 255, 238], error: Utf8Error { valid_up_to: 0, error_len: Some(1) } }', src/lib.rs:51:47 +[68. 2024-05-22T12:38:00.621855713Z]: right before timer trap +[69. 2024-05-22T12:38:00.621855713Z]: [TRAP]: timer trap +... ``` diff --git a/rust/canister_logs/src/lib.rs b/rust/canister_logs/src/lib.rs index 983e6cff5..25b1232ec 100644 --- a/rust/canister_logs/src/lib.rs +++ b/rust/canister_logs/src/lib.rs @@ -1,4 +1,24 @@ -use ic_cdk::update; +use ic_cdk::{init, post_upgrade, update}; +use std::time::Duration; + +const TIMER_INTERVAL_SEC: u64 = 5; + +fn setup_timer() { + ic_cdk_timers::set_timer_interval(Duration::from_secs(TIMER_INTERVAL_SEC), || { + ic_cdk::print("right before timer trap"); + ic_cdk::trap("timer trap"); + }); +} + +#[init] +fn init() { + setup_timer(); +} + +#[post_upgrade] +fn post_upgrade() { + setup_timer(); +} #[update] fn print(text: String) { From a627001f77a7d6955156101b701b005ff31ee31b Mon Sep 17 00:00:00 2001 From: Maksym Arutyunyan Date: Wed, 22 May 2024 12:40:54 +0000 Subject: [PATCH 6/8] comment --- rust/canister_logs/README.md | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/rust/canister_logs/README.md b/rust/canister_logs/README.md index 7d5d7f7ad..84f9e6386 100644 --- a/rust/canister_logs/README.md +++ b/rust/canister_logs/README.md @@ -40,10 +40,11 @@ $ dfx deploy ### Step 3: Check canister logs: +Expect to see logs from timer traps. + ```shell # Terminal B $ dfx canister logs canister_logs -# Expect to see logs from timer traps. [0. 2024-05-22T12:35:32.050252022Z]: right before timer trap [1. 2024-05-22T12:35:32.050252022Z]: [TRAP]: timer trap [2. 2024-05-22T12:35:37.680315152Z]: right before timer trap From 818c40094b5a4d9d4cc668d1001531483842e057 Mon Sep 17 00:00:00 2001 From: Maksym Arutyunyan Date: Thu, 23 May 2024 08:18:45 +0000 Subject: [PATCH 7/8] add motoko timer example --- motoko/canister_logs/README.md | 51 +++++++++++++++++++++++++------- motoko/canister_logs/src/Main.mo | 16 ++++++++++ rust/canister_logs/README.md | 9 ------ 3 files changed, 56 insertions(+), 20 deletions(-) diff --git a/motoko/canister_logs/README.md b/motoko/canister_logs/README.md index 7c4d8f35f..ce9557ae0 100644 --- a/motoko/canister_logs/README.md +++ b/motoko/canister_logs/README.md @@ -38,13 +38,17 @@ $ cd examples/motoko/canister_logs $ dfx deploy ``` -### Step 3: Check canister has no logs yet: +### Step 3: Check canister logs: + +Expect to see logs from timer traps. ```shell # Terminal B $ dfx canister logs CanisterLogs - -# Expect to see no logs. +[0. 2024-05-23T08:14:40.60349175Z]: right before timer trap +[1. 2024-05-23T08:14:40.60349175Z]: [TRAP]: timer trap +[2. 2024-05-23T08:14:46.160555676Z]: right before timer trap +[3. 2024-05-23T08:14:46.160555676Z]: [TRAP]: timer trap ``` ### Step 4: Call `print` method and check the logs: @@ -56,7 +60,13 @@ $ dfx canister call CanisterLogs print hi # Expect to see new log entry. $ dfx canister logs CanisterLogs -[0. 2024-05-22T11:37:28.080234848Z]: hi +... +[14. 2024-05-23T08:15:15.829022842Z]: right before timer trap +[15. 2024-05-23T08:15:15.829022842Z]: [TRAP]: timer trap +[16. 2024-05-23T08:15:19.728382106Z]: hi +[17. 2024-05-23T08:15:21.079923035Z]: right before timer trap +[18. 2024-05-23T08:15:21.079923035Z]: [TRAP]: timer trap +... ``` ### Step 5: Start constantly polling logs: @@ -66,8 +76,13 @@ In order not to call `dfx canister logs CanisterLogs` after every canister call ```shell # Terminal C $ ./poll_logs.sh -[0. 2024-05-22T11:37:28.080234848Z]: hi - +... +[14. 2024-05-23T08:15:15.829022842Z]: right before timer trap +[15. 2024-05-23T08:15:15.829022842Z]: [TRAP]: timer trap +[16. 2024-05-23T08:15:19.728382106Z]: hi +[17. 2024-05-23T08:15:21.079923035Z]: right before timer trap +[18. 2024-05-23T08:15:21.079923035Z]: [TRAP]: timer trap +... ``` ### Step 6: Call `print`, `trap`, `panic` and other canister methods: @@ -94,10 +109,24 @@ Observe recorded logs that might look similar to this: ```shell # Terminal C -[0. 2024-05-22T12:21:52.333589617Z]: hi -[1. 2024-05-22T12:22:27.330332077Z]: hello! -[2. 2024-05-22T12:22:32.062734677Z]: yey! -[3. 2024-05-22T12:22:36.685104375Z]: right before trap -[4. 2024-05-22T12:22:36.685104375Z]: [TRAP]: oops! +... +[49. 2024-05-23T08:16:40.702368542Z]: right before timer trap +[50. 2024-05-23T08:16:40.702368542Z]: [TRAP]: timer trap +[51. 2024-05-23T08:16:42.785727368Z]: hi! +[52. 2024-05-23T08:16:45.69960063Z]: right before timer trap +[53. 2024-05-23T08:16:45.69960063Z]: [TRAP]: timer trap +[54. 2024-05-23T08:16:47.222911354Z]: hello! +[55. 2024-05-23T08:16:50.875445893Z]: right before timer trap +[56. 2024-05-23T08:16:50.875445893Z]: [TRAP]: timer trap +[57. 2024-05-23T08:16:51.570602735Z]: yey! +[58. 2024-05-23T08:16:55.783308056Z]: right before timer trap +[59. 2024-05-23T08:16:55.783308056Z]: [TRAP]: timer trap +[60. 2024-05-23T08:16:56.536701165Z]: right before trap +[61. 2024-05-23T08:16:56.536701165Z]: [TRAP]: oops! +[62. 2024-05-23T08:17:00.759041661Z]: right before timer trap +[63. 2024-05-23T08:17:00.759041661Z]: [TRAP]: timer trap +[64. 2024-05-23T08:17:05.657467481Z]: right before timer trap +[65. 2024-05-23T08:17:05.657467481Z]: [TRAP]: timer trap +... ``` diff --git a/motoko/canister_logs/src/Main.mo b/motoko/canister_logs/src/Main.mo index 3aeac1ea8..b228bdc72 100644 --- a/motoko/canister_logs/src/Main.mo +++ b/motoko/canister_logs/src/Main.mo @@ -1,7 +1,23 @@ import Debug "mo:base/Debug"; +import { abs } = "mo:base/Int"; +import { now } = "mo:base/Time"; +import { setTimer; recurringTimer } = "mo:base/Timer"; actor CanisterLogs { + let timerDelaySeconds = 5; + + private func execute_timer() : async () { + Debug.print("right before timer trap"); + Debug.trap("timer trap"); + }; + + ignore setTimer(#seconds (timerDelaySeconds - abs(now() / 1_000_000_000) % timerDelaySeconds), + func () : async () { + ignore recurringTimer(#seconds timerDelaySeconds, execute_timer); + await execute_timer(); + }); + public func print(text : Text) : async () { Debug.print(text); }; diff --git a/rust/canister_logs/README.md b/rust/canister_logs/README.md index 84f9e6386..4a1b9ab2f 100644 --- a/rust/canister_logs/README.md +++ b/rust/canister_logs/README.md @@ -62,15 +62,11 @@ $ dfx canister call canister_logs print hi # Expect to see new log entry. $ dfx canister logs canister_logs ... -[16. 2024-05-22T12:36:15.638667167Z]: right before timer trap -[17. 2024-05-22T12:36:15.638667167Z]: [TRAP]: timer trap [18. 2024-05-22T12:36:20.881326098Z]: right before timer trap [19. 2024-05-22T12:36:20.881326098Z]: [TRAP]: timer trap [20. 2024-05-22T12:36:26.305162772Z]: hi [21. 2024-05-22T12:36:27.185879186Z]: right before timer trap [22. 2024-05-22T12:36:27.185879186Z]: [TRAP]: timer trap -[23. 2024-05-22T12:36:33.486805581Z]: right before timer trap -[24. 2024-05-22T12:36:33.486805581Z]: [TRAP]: timer trap ``` ### Step 5: Start constantly polling logs: @@ -81,17 +77,12 @@ In order not to call `dfx canister logs canister_logs` after every canister call # Terminal C $ ./poll_logs.sh ... -[16. 2024-05-22T12:36:15.638667167Z]: right before timer trap -[17. 2024-05-22T12:36:15.638667167Z]: [TRAP]: timer trap [18. 2024-05-22T12:36:20.881326098Z]: right before timer trap [19. 2024-05-22T12:36:20.881326098Z]: [TRAP]: timer trap [20. 2024-05-22T12:36:26.305162772Z]: hi [21. 2024-05-22T12:36:27.185879186Z]: right before timer trap [22. 2024-05-22T12:36:27.185879186Z]: [TRAP]: timer trap -[23. 2024-05-22T12:36:33.486805581Z]: right before timer trap -[24. 2024-05-22T12:36:33.486805581Z]: [TRAP]: timer trap ... - ``` ### Step 6: Call `print`, `trap`, `panic` and other canister methods: From 79c96718a86554709d7758736aaba1d026399cd2 Mon Sep 17 00:00:00 2001 From: Maksym Arutyunyan Date: Thu, 23 May 2024 08:34:56 +0000 Subject: [PATCH 8/8] add memory_oob motoko example --- motoko/canister_logs/README.md | 71 ++++++++++++++++++-------------- motoko/canister_logs/src/Main.mo | 11 ++++- rust/canister_logs/README.md | 2 +- 3 files changed, 50 insertions(+), 34 deletions(-) diff --git a/motoko/canister_logs/README.md b/motoko/canister_logs/README.md index ce9557ae0..eb0d63104 100644 --- a/motoko/canister_logs/README.md +++ b/motoko/canister_logs/README.md @@ -45,10 +45,10 @@ Expect to see logs from timer traps. ```shell # Terminal B $ dfx canister logs CanisterLogs -[0. 2024-05-23T08:14:40.60349175Z]: right before timer trap -[1. 2024-05-23T08:14:40.60349175Z]: [TRAP]: timer trap -[2. 2024-05-23T08:14:46.160555676Z]: right before timer trap -[3. 2024-05-23T08:14:46.160555676Z]: [TRAP]: timer trap +[0. 2024-05-23T08:32:26.203980235Z]: right before timer trap +[1. 2024-05-23T08:32:26.203980235Z]: [TRAP]: timer trap +[2. 2024-05-23T08:32:31.836721763Z]: right before timer trap +[3. 2024-05-23T08:32:31.836721763Z]: [TRAP]: timer trap ``` ### Step 4: Call `print` method and check the logs: @@ -61,11 +61,11 @@ $ dfx canister call CanisterLogs print hi # Expect to see new log entry. $ dfx canister logs CanisterLogs ... -[14. 2024-05-23T08:15:15.829022842Z]: right before timer trap -[15. 2024-05-23T08:15:15.829022842Z]: [TRAP]: timer trap -[16. 2024-05-23T08:15:19.728382106Z]: hi -[17. 2024-05-23T08:15:21.079923035Z]: right before timer trap -[18. 2024-05-23T08:15:21.079923035Z]: [TRAP]: timer trap +[8. 2024-05-23T08:32:46.598972616Z]: right before timer trap +[9. 2024-05-23T08:32:46.598972616Z]: [TRAP]: timer trap +[10. 2024-05-23T08:32:48.713755238Z]: hi +[11. 2024-05-23T08:32:51.623988313Z]: right before timer trap +[12. 2024-05-23T08:32:51.623988313Z]: [TRAP]: timer trap ... ``` @@ -77,15 +77,15 @@ In order not to call `dfx canister logs CanisterLogs` after every canister call # Terminal C $ ./poll_logs.sh ... -[14. 2024-05-23T08:15:15.829022842Z]: right before timer trap -[15. 2024-05-23T08:15:15.829022842Z]: [TRAP]: timer trap -[16. 2024-05-23T08:15:19.728382106Z]: hi -[17. 2024-05-23T08:15:21.079923035Z]: right before timer trap -[18. 2024-05-23T08:15:21.079923035Z]: [TRAP]: timer trap +[8. 2024-05-23T08:32:46.598972616Z]: right before timer trap +[9. 2024-05-23T08:32:46.598972616Z]: [TRAP]: timer trap +[10. 2024-05-23T08:32:48.713755238Z]: hi +[11. 2024-05-23T08:32:51.623988313Z]: right before timer trap +[12. 2024-05-23T08:32:51.623988313Z]: [TRAP]: timer trap ... ``` -### Step 6: Call `print`, `trap`, `panic` and other canister methods: +### Step 6: Call `print`, `trap` and other canister methods: ```shell # Terminal B @@ -103,6 +103,11 @@ Error: Failed update call. Caused by: Failed update call. The replica returned a rejection error: reject code CanisterError, reject message Canister bkyz2-fmaaa-aaaaa-qaaaq-cai trapped explicitly: oops!, error code None +$ dfx canister call CanisterLogs memory_oob +Error: Failed update call. +Caused by: Failed update call. + The replica returned a rejection error: reject code CanisterError, reject message Canister bkyz2-fmaaa-aaaaa-qaaaq-cai trapped explicitly: StableMemory range out of bounds, error code None + ``` Observe recorded logs that might look similar to this: @@ -110,23 +115,25 @@ Observe recorded logs that might look similar to this: ```shell # Terminal C ... -[49. 2024-05-23T08:16:40.702368542Z]: right before timer trap -[50. 2024-05-23T08:16:40.702368542Z]: [TRAP]: timer trap -[51. 2024-05-23T08:16:42.785727368Z]: hi! -[52. 2024-05-23T08:16:45.69960063Z]: right before timer trap -[53. 2024-05-23T08:16:45.69960063Z]: [TRAP]: timer trap -[54. 2024-05-23T08:16:47.222911354Z]: hello! -[55. 2024-05-23T08:16:50.875445893Z]: right before timer trap -[56. 2024-05-23T08:16:50.875445893Z]: [TRAP]: timer trap -[57. 2024-05-23T08:16:51.570602735Z]: yey! -[58. 2024-05-23T08:16:55.783308056Z]: right before timer trap -[59. 2024-05-23T08:16:55.783308056Z]: [TRAP]: timer trap -[60. 2024-05-23T08:16:56.536701165Z]: right before trap -[61. 2024-05-23T08:16:56.536701165Z]: [TRAP]: oops! -[62. 2024-05-23T08:17:00.759041661Z]: right before timer trap -[63. 2024-05-23T08:17:00.759041661Z]: [TRAP]: timer trap -[64. 2024-05-23T08:17:05.657467481Z]: right before timer trap -[65. 2024-05-23T08:17:05.657467481Z]: [TRAP]: timer trap +[19. 2024-05-23T08:33:11.319493785Z]: right before timer trap +[20. 2024-05-23T08:33:11.319493785Z]: [TRAP]: timer trap +[21. 2024-05-23T08:33:14.229855179Z]: hi! +[22. 2024-05-23T08:33:16.413512126Z]: right before timer trap +[23. 2024-05-23T08:33:16.413512126Z]: [TRAP]: timer trap +[24. 2024-05-23T08:33:18.622686552Z]: hello! +[25. 2024-05-23T08:33:21.519088681Z]: right before timer trap +[26. 2024-05-23T08:33:21.519088681Z]: [TRAP]: timer trap +[27. 2024-05-23T08:33:22.96101893Z]: yey! +[28. 2024-05-23T08:33:26.601860526Z]: right before timer trap +[29. 2024-05-23T08:33:26.601860526Z]: [TRAP]: timer trap +[30. 2024-05-23T08:33:28.039227914Z]: right before trap +[31. 2024-05-23T08:33:28.039227914Z]: [TRAP]: oops! +[32. 2024-05-23T08:33:31.634215234Z]: right before timer trap +[33. 2024-05-23T08:33:31.634215234Z]: [TRAP]: timer trap +[34. 2024-05-23T08:33:35.96761902Z]: right before memory out of bounds +[35. 2024-05-23T08:33:35.96761902Z]: [TRAP]: StableMemory range out of bounds +[36. 2024-05-23T08:33:36.712223153Z]: right before timer trap +[37. 2024-05-23T08:33:36.712223153Z]: [TRAP]: timer trap ... ``` diff --git a/motoko/canister_logs/src/Main.mo b/motoko/canister_logs/src/Main.mo index b228bdc72..3fa87bc76 100644 --- a/motoko/canister_logs/src/Main.mo +++ b/motoko/canister_logs/src/Main.mo @@ -2,17 +2,19 @@ import Debug "mo:base/Debug"; import { abs } = "mo:base/Int"; import { now } = "mo:base/Time"; import { setTimer; recurringTimer } = "mo:base/Timer"; +import StableMemory "mo:base/ExperimentalStableMemory"; actor CanisterLogs { let timerDelaySeconds = 5; + let second = 1_000_000_000; private func execute_timer() : async () { Debug.print("right before timer trap"); Debug.trap("timer trap"); }; - ignore setTimer(#seconds (timerDelaySeconds - abs(now() / 1_000_000_000) % timerDelaySeconds), + ignore setTimer(#seconds (timerDelaySeconds - abs(now() / second) % timerDelaySeconds), func () : async () { ignore recurringTimer(#seconds timerDelaySeconds, execute_timer); await execute_timer(); @@ -27,4 +29,11 @@ actor CanisterLogs { Debug.trap(text); }; + public func memory_oob() : async () { + Debug.print("right before memory out of bounds"); + let offset : Nat64 = 10; + let value : Nat = 20; + let _blob = StableMemory.loadBlob(offset, value); // Expect reading outside of memory bounds to trap. + }; + }; diff --git a/rust/canister_logs/README.md b/rust/canister_logs/README.md index 4a1b9ab2f..5003e578f 100644 --- a/rust/canister_logs/README.md +++ b/rust/canister_logs/README.md @@ -85,7 +85,7 @@ $ ./poll_logs.sh ... ``` -### Step 6: Call `print`, `trap`, `panic` and other canister methods: +### Step 6: Call `print`, `trap` and other canister methods: ```shell # Terminal B