feat: Improve 'dfx canister logs' with several options

CHANGELOG.md

@@ -22,6 +22,13 @@ Use the `account_balance` rather than the legacy `account_balance_dfx` on the IC
 
 Extend `dfx ledger transfer` and `dfx ledger balance` to support [ICRC-1 standard](https://github.com/dfinity/ICRC-1/tree/main/standards/ICRC-1).
 
+### feat: Improve 'dfx canister logs' with several options
+
+Improve `dfx canister logs` with several options
+- `--tail <n>` to show the last `n` log entries
+- `--since` to show the logs newer than a relative duration
+- `--since-time` to show the logs newer than a specific timestamp
+
 ## Dependencies
 
 ### Motoko

docs/cli-reference/dfx-canister.mdx

@@ -622,9 +622,27 @@ Use the `dfx canister logs` command to display the logs from a canister.
 ### Basic usage
 
 ``` bash
-dfx canister logs <canister-name>
+dfx canister logs [options] <canister-name>
 ```
 
+### Arguments
+
+You must specify the following arguments for the `dfx canister logs` command.
+
+| Argument              | Description                                                      |
+|-----------------------|------------------------------------------------------------------|
+| `<canister>`          | Specifies the name or id of the canister to get the logs of.     |
+
+### Options
+
+You can specify the following options for the `dfx canister logs` command.
+
+| Option                      | Description                                                                                         |
+|-----------------------------|-----------------------------------------------------------------------------------------------------|
+| `--tail <tail>`             | Specifies to show the last number of the logs.                                                      |
+| `--since <since>`           | Specifies to show the logs newer than a relative duration, with the valid units `s`, `m`, `h`, `d`. |
+| `--since-time <since-time>` | Specifies to show the logs newer than a specific timestamp. Required either `nanoseconds` since Unix epoch or `RFC3339` format (e.g. `2021-05-06T19:17:10.000000002Z`). |
+
 ### Examples
 
 To display the logs from the `hello_world` canister, you can run the following command:
@@ -638,6 +656,46 @@ The command displays output similar to the following:
 ``` log
 [42. 2021-05-06T19:17:10.000000001Z]: Some text message
 [43. 2021-05-06T19:17:10.000000002Z]: (bytes) 0xc0ffee
+[44. 2021-05-06T19:17:15.000000001Z]: Five seconds later
+[45. 2021-05-06T19:17:15.000000002Z]: (bytes) 0xc0ffee
+```
+
+To display the latest one log, you can run the following command:
+
+``` bash
+dfx canister logs hello_world --tail 1
+```
+
+The command displays output similar to the following:
+
+``` log
+[45. 2021-05-06T19:17:15.000000002Z]: (bytes) 0xc0ffee
+```
+
+To display the logs for the past 3 seconds, you can run the following command:
+
+``` bash
+dfx canister logs hello_world --since=3s
+```
+
+The command displays output similar to the following:
+
+``` log
+[44. 2021-05-06T19:17:15.000000001Z]: Five seconds later
+[45. 2021-05-06T19:17:15.000000002Z]: (bytes) 0xc0ffee
+```
+
+To display the logs since a given time, you can run the following command:
+
+``` bash
+dfx canister logs hello_world --since-time=2021-05-06T19:17:13.000000001Z
+```
+
+The command displays output similar to the following:
+
+``` log
+[44. 2021-05-06T19:17:15.000000001Z]: Five seconds later
+[45. 2021-05-06T19:17:15.000000002Z]: (bytes) 0xc0ffee
 ```
 
 ## dfx canister metadata

e2e/tests-dfx/canister_logs.bash

@@ -66,6 +66,54 @@ dfx_canister_logs_tail_n_1() {
   assert_contains "Bob"
 }
 
+@test "canister logs tail" {
+  install_asset logs
+  dfx_start
+  dfx canister create --all
+  dfx build
+  dfx canister install e2e_project
+  dfx canister call e2e_project hello Alice
+  dfx canister call e2e_project hello Bob
+  sleep 2
+  assert_command dfx canister logs e2e_project --tail 1
+  assert_not_contains "Alice"
+  assert_contains "Bob"
+}
+
+@test "canister logs since" {
+  install_asset logs
+  dfx_start
+  dfx canister create --all
+  dfx build
+  dfx canister install e2e_project
+  dfx canister call e2e_project hello Alice
+  sleep 3
+  dfx canister call e2e_project hello Bob
+  assert_command dfx canister logs e2e_project --since 2s
+  assert_not_contains "Alice"
+  assert_contains "Bob"
+}
+
+current_time_nanoseconds() {
+  echo "$(date +%s)"000000000
+}
+
+@test "canister logs since_time" {
+  install_asset logs
+  dfx_start
+  dfx canister create --all
+  dfx build
+  dfx canister install e2e_project
+  dfx canister call e2e_project hello Alice
+  sleep 1
+  timestamp=$(current_time_nanoseconds)
+  sleep 1
+  dfx canister call e2e_project hello Bob
+  assert_command dfx canister logs e2e_project --since-time "$timestamp"
+  assert_not_contains "Alice"
+  assert_contains "Bob"
+}
+
 @test "canister logs only visible to allowed viewers." {
   install_asset logs
   dfx_start

src/dfx/src/commands/canister/logs.rs

@@ -2,27 +2,71 @@ use crate::lib::environment::Environment;
 use crate::lib::error::DfxResult;
 use crate::lib::operations::canister;
 use crate::lib::root_key::fetch_root_key_if_needed;
+use crate::util::clap::parsers::{duration_parser, timestamp_parser};
 use candid::Principal;
 use clap::Parser;
 use dfx_core::identity::CallSender;
 use ic_utils::interfaces::management_canister::FetchCanisterLogsResponse;
+use std::time::{SystemTime, UNIX_EPOCH};
 use time::format_description::well_known::Rfc3339;
 use time::OffsetDateTime;
 
 /// Get the canister logs.
 #[derive(Parser)]
 pub struct LogsOpts {
-    /// Specifies the name or id of the canister to get its canister information.
+    /// Specifies the name or id of the canister to get the logs of.
     canister: String,
+
+    /// Specifies to show the last number of the logs.
+    #[arg(long)]
+    tail: Option<u64>,
+
+    /// Specifies to show the logs newer than a relative duration, with the valid units 's', 'm', 'h', 'd'.
+    #[arg(long, conflicts_with("tail"), conflicts_with("since_time"), value_parser = duration_parser)]
+    since: Option<u64>,
+
+    /// Specifies to show the logs newer than a specific timestamp.
+    /// Required either nanoseconds since Unix epoch or RFC3339 format (e.g. '2021-05-06T19:17:10.000000002Z').
+    #[arg(long, conflicts_with("tail"), conflicts_with("since"), value_parser = timestamp_parser)]
+    since_time: Option<u64>,
 }
 
 fn format_bytes(bytes: &[u8]) -> String {
     format!("(bytes) 0x{}", hex::encode(bytes))
 }
 
-fn format_canister_logs(logs: FetchCanisterLogsResponse) -> Vec<String> {
-    logs.canister_log_records
-        .into_iter()
+fn format_canister_logs(logs: FetchCanisterLogsResponse, opts: &LogsOpts) -> Vec<String> {
+    let filtered_logs = if let Some(number) = opts.tail {
+        &logs.canister_log_records[logs
+            .canister_log_records
+            .len()
+            .saturating_sub(number as usize)..]
+    } else if let Some(since) = opts.since {
+        let timestamp_nanos = SystemTime::now()
+            .duration_since(UNIX_EPOCH)
+            .unwrap()
+            .as_nanos() as u64
+            - since * 1_000_000_000;
+
+        let index = logs
+            .canister_log_records
+            .partition_point(|r| r.timestamp_nanos <= timestamp_nanos);
+        &logs.canister_log_records[index..]
+    } else if let Some(since_time) = opts.since_time {
+        let index = logs
+            .canister_log_records
+            .partition_point(|r| r.timestamp_nanos <= since_time);
+        &logs.canister_log_records[index..]
+    } else {
+        &logs.canister_log_records
+    };
+
+    if filtered_logs.is_empty() {
+        return vec!["No logs".to_string()];
+    }
+
+    filtered_logs
+        .iter()
         .map(|r| {
             let time = OffsetDateTime::from_unix_timestamp_nanos(r.timestamp_nanos as i128)
                 .expect("Invalid canister log record timestamp");
@@ -63,14 +107,107 @@ fn test_format_canister_logs() {
                 timestamp_nanos: 1_620_328_630_000_000_002,
                 content: vec![192, 255, 238],
             },
+            CanisterLogRecord {
+                idx: 44,
+                timestamp_nanos: 1_620_328_630_000_000_003,
+                content: vec![192, 255, 238],
+            },
+            CanisterLogRecord {
+                idx: 45,
+                timestamp_nanos: 1_620_328_635_000_000_001,
+                content: b"Five seconds later".to_vec(),
+            },
+            CanisterLogRecord {
+                idx: 46,
+                timestamp_nanos: 1_620_328_635_000_000_002,
+                content: vec![192, 255, 238],
+            },
+            CanisterLogRecord {
+                idx: 47,
+                timestamp_nanos: 1_620_328_635_000_000_003,
+                content: vec![192, 255, 238],
+            },
         ],
     };
+
     assert_eq!(
-        format_canister_logs(logs),
+        format_canister_logs(
+            logs.clone(),
+            &LogsOpts {
+                canister: "2vxsx-fae".to_string(),
+                tail: None,
+                since: None,
+                since_time: None,
+            }
+        ),
         vec![
             "[42. 2021-05-06T19:17:10.000000001Z]: Some text message".to_string(),
             "[43. 2021-05-06T19:17:10.000000002Z]: (bytes) 0xc0ffee".to_string(),
-        ],
+            "[44. 2021-05-06T19:17:10.000000003Z]: (bytes) 0xc0ffee".to_string(),
+            "[45. 2021-05-06T19:17:15.000000001Z]: Five seconds later".to_string(),
+            "[46. 2021-05-06T19:17:15.000000002Z]: (bytes) 0xc0ffee".to_string(),
+            "[47. 2021-05-06T19:17:15.000000003Z]: (bytes) 0xc0ffee".to_string(),
+        ]
+    );
+
+    // Test tail
+    assert_eq!(
+        format_canister_logs(
+            logs.clone(),
+            &LogsOpts {
+                canister: "2vxsx-fae".to_string(),
+                tail: Some(4),
+                since: None,
+                since_time: None,
+            }
+        ),
+        vec![
+            "[44. 2021-05-06T19:17:10.000000003Z]: (bytes) 0xc0ffee".to_string(),
+            "[45. 2021-05-06T19:17:15.000000001Z]: Five seconds later".to_string(),
+            "[46. 2021-05-06T19:17:15.000000002Z]: (bytes) 0xc0ffee".to_string(),
+            "[47. 2021-05-06T19:17:15.000000003Z]: (bytes) 0xc0ffee".to_string(),
+        ]
+    );
+
+    // Test since
+    let duration_seconds = SystemTime::now()
+        .duration_since(UNIX_EPOCH)
+        .unwrap()
+        .as_secs()
+        - 1620328631; // 1 second after the first log with idx 42.
+    assert_eq!(
+        format_canister_logs(
+            logs.clone(),
+            &LogsOpts {
+                canister: "2vxsx-fae".to_string(),
+                tail: None,
+                since: Some(duration_seconds),
+                since_time: None,
+            }
+        ),
+        vec![
+            "[45. 2021-05-06T19:17:15.000000001Z]: Five seconds later".to_string(),
+            "[46. 2021-05-06T19:17:15.000000002Z]: (bytes) 0xc0ffee".to_string(),
+            "[47. 2021-05-06T19:17:15.000000003Z]: (bytes) 0xc0ffee".to_string(),
+        ]
+    );
+
+    // Test since_time
+    assert_eq!(
+        format_canister_logs(
+            logs,
+            &LogsOpts {
+                canister: "2vxsx-fae".to_string(),
+                tail: None,
+                since: None,
+                since_time: Some(1_620_328_635_000_000_000),
+            }
+        ),
+        vec![
+            "[45. 2021-05-06T19:17:15.000000001Z]: Five seconds later".to_string(),
+            "[46. 2021-05-06T19:17:15.000000002Z]: (bytes) 0xc0ffee".to_string(),
+            "[47. 2021-05-06T19:17:15.000000003Z]: (bytes) 0xc0ffee".to_string(),
+        ]
     );
 }
 
@@ -84,8 +221,7 @@ pub async fn exec(env: &dyn Environment, opts: LogsOpts, call_sender: &CallSende
     fetch_root_key_if_needed(env).await?;
 
     let logs = canister::get_canister_logs(env, canister_id, call_sender).await?;
-
-    println!("{}", format_canister_logs(logs).join("\n"));
+    println!("{}", format_canister_logs(logs, &opts).join("\n"));
 
     Ok(())
 }