E2E testing: Make `node_log_contains` more robust

[cmichi]

Follow-up to #1395.

The E2E testing framework contains a function node_log_contains that basically does a full text search on a node log:

assert!(client.node_log_contains("requested value: 100000000000000\n"));

The issue with this function is that it returns true as soon as the supplied String is found in the log file. This is a bit unfortunate, if one executes multiple tests in parallel (as cargo test does by default) then it could be that

• Test A calls a contract that outputs the String to the log
• Test B calls the same contract that should output the String as well, but it actually fails to do so.

Both tests would show up as succeed though, as Test B still finds the String in the log currently.

I don't have a good idea how to fix this yet, maybe someone else has?

[cmichi]

The proper solution would be to have each E2E #[ink::e2e_test] spawn its own node executable with a unique port (to not have nodes for individual tests collide). Then each test would have its own log file.

Not particularly fond of this solution, as it would have much more overhead than the current solution of just running one node for all the tests. If projects have a more complex node setup (e.g relay chain + parachain), spawning it for every test is quite inefficient.

[cmichi]

I don't see a proper solution for this that doesn't lead to bugs in tests due to ambivalence in behavior of node_log_contains.

We could execute tests in a sequential order as soon as node_log_contains is used anywhere in the test suite. lf node_log_contains is invoked and finds something we would persist the line number where the finding occurred and ignore that line for the next invocations of node_log_contains. Then it would not be possible to execute the command for the same line though. E.g. something like this would not be possible:

assert!(node_log_contains("value: 123") && node_log_contains("receiver: 5D…"));

It'll be hard to make sure that users are aware of this distinct behavior and I think it'll rather lead to confusion and bugs in tests.

I think the best course forward is to close this issue and remove the existing functionality.

The better alternative is to throw an event and detect the emission of that in the test. It's also possible to throw events only for contracts not compiled in release mode by adding a [cfg(features = "…")] before the self.env().emit_event(…).

[ascjones]

Was this feature primarily to detect debug_println! output from contracts? If so these can be read as results from RPC dry runs.

[cmichi]

Was this feature primarily to detect debug_println! output from contracts? If so these can be read as results from RPC dry runs.

Yes that's possible and we're already doing that for an E2E test in master. We can't check for debug printlns in e.g. chain extensions that way though.