Added assertion for matching lines count (#603)

* rs: count of matching lines added

* cargo fmt

* docs: count of matching lines added

* ts: count of matching lines added

* fix

* prettier

* test: count of matching lines added

* bump versions

Co-authored-by: Javier Viola <javier@parity.io>

Author: michalkucharczyk

Cargo.lock

@@ -1,6 +1,6 @@
 [package]
 name = "dsl-parser-wrapper"
-version = "0.1.6"
+version = "0.1.7"
 edition = "2021"
 description = "Zombienet DSL parser: produces a test definition, in json format, that can be used with the ZombieNet's test-runnner."
 license = "GPL-3.0-or-later"

crates/parser-wrapper/Cargo.toml

@@ -80,6 +80,15 @@ pub enum AssertionKind {
         #[serde(with = "optional_timeout")]
         timeout: Option<Duration>,
     },
+    CountLogMatch {
+        node_name: NodeName,
+        match_type: String,
+        pattern: String,
+        op: Operator,
+        target_value: u64,
+        #[serde(with = "optional_timeout")]
+        timeout: Option<Duration>,
+    },
     Trace {
         node_name: NodeName,
         span_id: String,

crates/parser/src/ast.rs

@@ -110,6 +110,51 @@ fn parse_match_pattern_rule(
     Ok((name, match_type, pattern, timeout))
 }
 
+fn parse_lines_count_match_pattern_rule(
+    record: Pair<Rule>,
+) -> Result<(String, String, String, ast::Comparison, Option<Duration>), ParserError> {
+    let mut pairs = record.into_inner();
+    let name = parse_name(get_pair(&mut pairs, "name")?)?;
+
+    let mut explicit_match_type = false;
+
+    let pair = get_pair(&mut pairs, "match_type")?;
+    let match_type = if let Rule::match_type = pair.as_rule() {
+        explicit_match_type = true;
+        pair.as_str().to_owned()
+    } else {
+        String::from("regex")
+    };
+
+    let pattern_pair = if explicit_match_type {
+        get_pair(&mut pairs, "pattern")?
+    } else {
+        pair
+    };
+
+    let pattern = pattern_pair.as_str().trim_matches('"').to_owned();
+
+    let cmp_rule = get_pair(&mut pairs, "cmp_rule")?;
+    let comparison: ast::Comparison = match cmp_rule.as_rule() {
+        Rule::int => ast::Comparison {
+            op: ast::Operator::Equal,
+            target_value: parse_taget_value(cmp_rule)?,
+        },
+        Rule::comparison => parse_comparison(cmp_rule)?,
+        _ => {
+            return Err(ParserError::UnreachableRule(pairs.as_str().to_string()));
+        }
+    };
+
+    let timeout: Option<Duration> = if let Some(within_rule) = pairs.next() {
+        Some(parse_within(within_rule)?)
+    } else {
+        None
+    };
+
+    Ok((name, match_type, pattern, comparison, timeout))
+}
+
 fn parse_custom_script_rule(record: Pair<Rule>, is_js: bool) -> Result<AssertionKind, ParserError> {
     let mut pairs = record.into_inner();
     let node_name = parse_name(get_pair(&mut pairs, "name")?)?;
@@ -405,6 +450,24 @@ pub fn parse(unparsed_file: &str) -> Result<ast::TestDefinition, errors::ParserE
 
                 assertions.push(assertion);
             }
+            Rule::count_log_match => {
+                let (name, match_type, pattern, comparison, timeout) =
+                    parse_lines_count_match_pattern_rule(record)?;
+
+                let assertion = Assertion {
+                    parsed: AssertionKind::CountLogMatch {
+                        node_name: name,
+                        match_type,
+                        pattern,
+                        target_value: comparison.target_value,
+                        op: comparison.op,
+                        timeout,
+                    },
+                    original_line,
+                };
+
+                assertions.push(assertion);
+            }
             Rule::trace => {
                 // Pairs should be in order:
                 // name, span_id, pattern, [timeout]

crates/parser/src/lib.rs

@@ -307,6 +307,130 @@ fn log_match_glob_parse_ok() {
     assert_eq!(result, t);
 }
 
+#[test]
+fn count_log_match_equal_parse_ok() {
+    let line: &str =
+        r#"alice: count of log lines containing "Imported #12" is 0 within 20 seconds"#;
+    let data = r#"{
+        "description": null,
+        "network": "./a.toml",
+        "creds": "config",
+        "assertions": [
+            {
+                "original_line": "alice: count of log lines containing \"Imported #12\" is 0 within 20 seconds",
+                "parsed": {
+                  "fn": "CountLogMatch",
+                  "args": {
+                    "node_name": "alice",
+                    "match_type": "regex",
+                    "pattern": "Imported #12",
+                    "op": "Equal",
+                    "target_value": 0,
+                    "timeout": 20
+                  }
+                }
+            }
+        ]
+    }"#;
+    let t: TestDefinition = serde_json::from_str(data).unwrap();
+
+    let result = parse(&[NETWORK, CREDS, line].join("\n")).unwrap();
+    assert_eq!(result, t);
+}
+
+#[test]
+fn count_log_match_is_at_least_parse_ok() {
+    let line: &str =
+        r#"alice: count of log lines containing "Imported #12" is at least 12 within 20 seconds"#;
+    let data = r#"{
+        "description": null,
+        "network": "./a.toml",
+        "creds": "config",
+        "assertions": [
+            {
+                "original_line": "alice: count of log lines containing \"Imported #12\" is at least 12 within 20 seconds",
+                "parsed": {
+                  "fn": "CountLogMatch",
+                  "args": {
+                    "node_name": "alice",
+                    "match_type": "regex",
+                    "pattern": "Imported #12",
+                    "op": "IsAtLeast",
+                    "target_value": 12,
+                    "timeout": 20
+                  }
+                }
+            }
+        ]
+    }"#;
+    let t: TestDefinition = serde_json::from_str(data).unwrap();
+
+    let result = parse(&[NETWORK, CREDS, line].join("\n")).unwrap();
+    assert_eq!(result, t);
+}
+
+#[test]
+fn count_log_match_glob_equal_parse_ok() {
+    let line: &str =
+        r#"alice: count of log lines containing glob "Imported #12" is 10 within 20 seconds"#;
+    let data = r#"{
+        "description": null,
+        "network": "./a.toml",
+        "creds": "config",
+        "assertions": [
+            {
+                "original_line": "alice: count of log lines containing glob \"Imported #12\" is 10 within 20 seconds",
+                "parsed": {
+                  "fn": "CountLogMatch",
+                  "args": {
+                    "node_name": "alice",
+                    "match_type": "glob",
+                    "pattern": "Imported #12",
+                    "op": "Equal",
+                    "target_value": 10,
+                    "timeout": 20
+                  }
+                }
+            }
+        ]
+    }"#;
+    let t: TestDefinition = serde_json::from_str(data).unwrap();
+
+    let result = parse(&[NETWORK, CREDS, line].join("\n")).unwrap();
+    assert_eq!(result, t);
+}
+
+#[test]
+fn count_log_match_glob_is_at_least_parse_ok() {
+    let line: &str =
+        r#"alice: count of log lines matching glob "*rted #1*" is at least 5 within 10 seconds"#;
+    let data = r#"{
+        "description": null,
+        "network": "./a.toml",
+        "creds": "config",
+        "assertions": [
+            {
+                "original_line": "alice: count of log lines matching glob \"*rted #1*\" is at least 5 within 10 seconds",
+                "parsed": {
+                  "fn": "CountLogMatch",
+                  "args": {
+                    "node_name": "alice",
+                    "match_type": "glob",
+                    "pattern": "*rted #1*",
+                    "op": "IsAtLeast",
+                    "target_value": 5,
+                    "timeout": 10
+                  }
+                }
+            }
+        ]
+    }"#;
+    let t: TestDefinition = serde_json::from_str(data).unwrap();
+
+    let result = parse(&[NETWORK, CREDS, line].join("\n")).unwrap();
+    assert_eq!(result, t);
+}
+
 #[test]
 fn trace_parse_ok() {
     let line: &str = r#"alice: trace with traceID 94c1501a78a0d83c498cc92deec264d9 contains ["answer-chunk-request", "answer-chunk-request"]"#;

crates/parser/src/tests.rs

@@ -64,6 +64,7 @@ para_runtime_dummy_upgrade = { node_name ~ parachain ~ "perform dummy upgrade" ~
 histogram = { node_name ~ "reports histogram" ~ metric_name ~ "has" ~ (comparison | int+) ~ "samples in buckets" ~ square_brackets_strings ~ within? }
 report = { node_name ~ "reports" ~ metric_name ~ comparison ~ within? }
 log_match = { node_name ~ "log line" ~ ("contains"|"matches") ~ match_type? ~ double_quoted_string ~ within? }
+count_log_match = { node_name ~ "count of log lines" ~ ("containing"|"matching") ~ match_type? ~ double_quoted_string ~ "is" ~ (comparison | int+) ~ within? }
 trace = { node_name ~ "trace with traceID" ~ span_id ~ "contains" ~ square_brackets_strings ~ within? }
 system_event = { node_name ~ "system event" ~ ("contains"|"matches") ~ match_type? ~ double_quoted_string ~ within? }
 custom_js = { node_name ~ "js-script" ~ file_path ~ ("with" ~ double_quoted_string)? ~ ( "return" ~ comparison )? ~ within? }
@@ -93,6 +94,7 @@ file = { SOI ~ (
     histogram |
     report |
     log_match |
+    count_log_match |
     trace |
     system_event |
     custom_js |
@@ -101,4 +103,4 @@ file = { SOI ~ (
     pause |
     resume |
     restart
-    )* ~ NEWLINE* ~ EOI }
+    )* ~ NEWLINE* ~ EOI }

crates/parser/src/zombienet.pest

@@ -55,6 +55,11 @@ The first lines are used to define the **header fields**:
   - `node-name`: log line (contains|matches) ( regex|glob) "pattern" [within x seconds]
     - alice: log line matches glob "_rted #1_" within 10 seconds
 
+- Logs assertions: Get logs from nodes and assert on the number of lines matching pattern (support `regex` and `glob`).
+
+  - `node-name`: count of log lines (containing|matcheing) ( regex|glob) "pattern" [within x seconds]
+    - alice: count of log lines matching glob "_rted #1_" within 10 seconds
+
 - System events assertion: Find a `system event` from subscription by matching a `pattern`. _NOTE_ the subscription is made when we start this particular test, so we **can not** match on event in the past.
 
   - `node-name`: system event (contains|matches)( regex| glob) "pattern" [within x seconds]

docs/src/cli/test-dsl-definition-spec.md

@@ -75,6 +75,7 @@ alice: reports histogram polkadot_pvf_execution_time has at least 2 samples in b
 # logs
 bob: log line matches glob "*rted #1*" within 10 seconds
 bob: log line matches "Imported #[0-9]+" within 10 seconds
+bob: count of log lines maching "Error" is 0 within 10 seconds
 
 # system events
 bob: system event contains "A candidate was included" within 20 seconds

docs/src/guide.md

@@ -49,7 +49,7 @@
     "url": "https://github.com/paritytech/zombienet/issues"
   },
   "dependencies": {
-    "@zombienet/dsl-parser-wrapper": "^0.1.6",
+    "@zombienet/dsl-parser-wrapper": "^0.1.7",
     "@zombienet/orchestrator": "^0.0.11",
     "@zombienet/utils": "^0.0.6",
     "axios": "^0.27.2",

javascript/packages/cli/package.json

@@ -372,6 +372,57 @@ export class NetworkNode implements NetworkNodeInterface {
     }
   }
 
+  async countPatternLines(
+    pattern: string,
+    isGlob: boolean,
+    timeout: number = DEFAULT_INDIVIDUAL_TEST_TIMEOUT,
+  ): Promise<number> {
+    try {
+      let total_count = 0;
+      const re = isGlob ? minimatch.makeRe(pattern) : new RegExp(pattern, "ig");
+      if (!re) throw new Error(`Invalid glob pattern: ${pattern} `);
+      const client = getClient();
+      const getValue = async (): Promise<number> => {
+        await new Promise((resolve) => setTimeout(resolve, timeout * 1000));
+        let logs = await client.getNodeLogs(this.name, undefined, true);
+
+        for (let line of logs.split("\n")) {
+          if (client.providerName !== "native") {
+            // remove the extra timestamp
+            line = line.split(" ").slice(1).join(" ");
+          }
+          if (re.test(line)) {
+            total_count += 1;
+          }
+        }
+        return total_count;
+      };
+
+      const resp = await Promise.race([
+        getValue(),
+        new Promise(
+          (resolve) =>
+            setTimeout(() => {
+              const err = new Error(
+                `Timeout(${timeout}), "getting log pattern ${pattern} within ${timeout} secs".`,
+              );
+              return resolve(err);
+            }, (timeout + 2) * 1000), //extra 2s for processing log
+        ),
+      ]);
+      if (resp instanceof Error) throw resp;
+
+      return total_count;
+    } catch (err: any) {
+      console.log(
+        `\n\t ${decorators.red("Error: ")} \n\t\t ${decorators.red(
+          err.message,
+        )}\n`,
+      );
+      return 0;
+    }
+  }
+
   async findPattern(
     pattern: string,
     isGlob: boolean,

javascript/packages/orchestrator/src/networkNode.ts

@@ -135,6 +135,31 @@ const LogMatch = ({ node_name, pattern, match_type, timeout }: FnArgs) => {
   };
 };
 
+const CountLogMatch = ({
+  node_name,
+  pattern,
+  match_type,
+  op,
+  target_value,
+  timeout,
+}: FnArgs) => {
+  const comparatorFn = comparators[op!];
+  const isGlob = (match_type && match_type.trim() === "glob") || false;
+
+  return async (network: Network) => {
+    const nodes = network.getNodes(node_name!);
+    const results = await Promise.all(
+      nodes.map((node: any) =>
+        node.countPatternLines(pattern!, isGlob, timeout),
+      ),
+    );
+
+    for (const value of results) {
+      comparatorFn(value as number, target_value as number);
+    }
+  };
+};
+
 const SystemEvent = ({ node_name, pattern, match_type, timeout }: FnArgs) => {
   const isGlob = (match_type && match_type.trim() === "glob") || false;
 
@@ -412,6 +437,7 @@ export default {
   Histogram,
   Trace,
   LogMatch,
+  CountLogMatch,
   SystemEvent,
   CustomJs,
   CustomSh,