Multiple line matches in test do not work

[michalkucharczyk]

Multiple line matches in test does not work. Only first line match works correctly, the second one times out.

It maybe reproduced with the 0001-small-network.zndsl example.

zombienet-linux test --provider podman 0001-small-network.zndsl

The error is:

┌──────────────────────────────┬────────────────────────────────────────────────────────────────────────────────────────────────────┐                                                                                                          
│ 11/11/2022, 8:47:18 AM       │ ✅ alice: reports histogram polkadot_pvf_execution_time has at least 2 samples in buckets ["0.1",… │                                                                                                          
└──────────────────────────────┴────────────────────────────────────────────────────────────────────────────────────────────────────┘                                                                                                          
┌──────────────────────────────┬────────────────────────────────────────────────────────────────────────────────────────────────────┐                                                                                                          
│ 11/11/2022, 8:47:18 AM       │ ✅ bob: log line matches glob "*rted #1*" within 10 seconds (172ms)                                │                                                                                                          
└──────────────────────────────┴────────────────────────────────────────────────────────────────────────────────────────────────────┘                                                                                                          

         Error:                                            
                 Timeout(10), "getting log pattern Imported #[0-9]+ within 10 secs".                                                                                                                                                           

┌──────────────────────────────┬────────────────────────────────────────────────────────────────────────────────────────────────────┐                                                                                                          
│ 11/11/2022, 8:47:28 AM       │ ❌ bob: log line matches "Imported #[0-9]+" within 10 seconds (10162ms)                            │                                                                                                          
└──────────────────────────────┴────────────────────────────────────────────────────────────────────────────────────────────────────┘ 

bob.log contains Imported #[0-9] pattern:

$ cat /tmp/zombie-1753d204_-754983-5DF8mNV09fWZ/logs/bob.log | grep "Imported #"
2022-11-11 07:46:06.016  INFO tokio-runtime-worker substrate: ✨ Imported #1 (0xfb52…0f8f)    
2022-11-11 07:46:12.013  INFO tokio-runtime-worker substrate: ✨ Imported #2 (0x81d9…690c)    
2022-11-11 07:46:18.010  INFO tokio-runtime-worker substrate: ✨ Imported #3 (0xcb13…bbf7)    
2022-11-11 07:46:24.017  INFO tokio-runtime-worker substrate: ✨ Imported #4 (0x99de…540c)    
2022-11-11 07:46:30.016  INFO tokio-runtime-worker substrate: ✨ Imported #5 (0x372a…846d)   

[pepoviola]

I think the issue is with the generated RegEx, @michalkucharczyk can you switch the order on the test lines con check my hint?
Thanks!

Update: @michalkucharczyk confirm that the second assertions always fails.

[michalkucharczyk]

Changing the order does not help.

# logs
bob: log line matches "Imported #[0-9]+" within 10 seconds
bob: log line matches glob "*rted #1*" within 10 seconds

Only first reg-ex is matched. The second one fails:

┌──────────────────────────────┬────────────────────────────────────────────────────────────────────────────────────────────────────┐
│ 11/11/2022, 11:06:12 AM      │ ✅ alice: reports histogram polkadot_pvf_execution_time has at least 2 samples in buckets ["0.1",… │
└──────────────────────────────┴────────────────────────────────────────────────────────────────────────────────────────────────────┘
┌──────────────────────────────┬────────────────────────────────────────────────────────────────────────────────────────────────────┐
│ 11/11/2022, 11:06:12 AM      │ ✅ bob: log line matches "Imported #[0-9]+" within 10 seconds (270ms)                              │
└──────────────────────────────┴────────────────────────────────────────────────────────────────────────────────────────────────────┘

         Error:  
                 Timeout(10), "getting log pattern *rted #1* within 10 secs".

┌──────────────────────────────┬────────────────────────────────────────────────────────────────────────────────────────────────────┐
│ 11/11/2022, 11:06:22 AM      │ ❌ bob: log line matches glob "*rted #1*" within 10 seconds (10279ms)                              │
└──────────────────────────────┴────────────────────────────────────────────────────────────────────────────────────────────────────┘

[pepoviola]

Fixed in main now, thanks @michalkucharczyk!