Skip to content

Commit

Permalink
fix: handle multiple strings that look like they might be JSON (#361)
Browse files Browse the repository at this point in the history 
The test output can have occurrences of `{` that aren't the string we are looking for, eg:

```
dialer-1    | test browser
dialer-1    | [JavaScript Error: "Clear-Site-Data header found. Unknown value “"cache"”." {file: "http://127.0.0.1:34451/" line: 0}]
dialer-1    | [JavaScript Error: "Clear-Site-Data header forced the clean up of “cookies” data." {file: "http://127.0.0.1:34451/" line: 0}]
dialer-1    | [JavaScript Error: "Clear-Site-Data header forced the clean up of “storage” data." {file: "http://127.0.0.1:34451/" line: 0}]
```

These fail to parse so improve the results parsing by:

1. Try parsing every instance of `{...}` in the output, not just the first
2. Test the output for the `handshakePlusOneRTTMillis` and `pingRTTMilllis` keys
  • Loading branch information
@achingbrain
achingbrain committed May 7, 2024
1 parent 0518ca6 commit fd59ed7
Showing 1 changed file with 80 additions and 13 deletions.
93 changes: 80 additions & 13 deletions transport-interop/src/compose-stdout-helper.ts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -13,11 +13,21 @@ export function dialerStdout(composeStdout: string): string {
}

export function dialerTimings(dialerStdout: string): Object {
const openBracket = dialerStdout.indexOf("{")
if (openBracket === -1) throw new Error("Invalid JSON. No opening curly bracket found")
const closeBracket = dialerStdout.indexOf("}", openBracket)
if (closeBracket === -1) throw new Error("Invalid JSON. No closing curly bracket found")
return JSON.parse(dialerStdout.substring(openBracket, closeBracket + 1))
let openBracket = dialerStdout.indexOf("{")
let error
while (true) {
if (openBracket === -1) break
const closeBracket = dialerStdout.indexOf("}", openBracket)
if (closeBracket === -1) throw new Error("Invalid JSON. No closing curly bracket found")
try {
const result = JSON.parse(dialerStdout.substring(openBracket, closeBracket + 1))
if (result.handshakePlusOneRTTMillis != null && result.pingRTTMilllis != null) return result
} catch (err) {
error = err
}
openBracket = dialerStdout.indexOf("{", openBracket + 1)
}
throw error ?? new Error("Invalid JSON. No opening curly bracket found")
}

// simple test case - avoids bringing in a whole test framework
Expand Down Expand Up @@ -57,9 +67,9 @@ function test() {
2023-07-05T22:41:18.8186846Z zig-v0_0_1_x_zig-v0_0_1__quic-v1_-redis-1 | 1:M 05 Jul 2023 22:41:17.439 # Server initialized
2023-07-05T22:41:18.8188914Z zig-v0_0_1_x_zig-v0_0_1__quic-v1_-redis-1 | 1:M 05 Jul 2023 22:41:17.439 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
2023-07-05T22:41:18.8190173Z zig-v0_0_1_x_zig-v0_0_1__quic-v1_-redis-1 | 1:M 05 Jul 2023 22:41:17.439 * Ready to accept connections
2023-07-05T22:41:18.8190833Z zig-v0_0_1_x_zig-v0_0_1__quic-v1_-dialer-1 | {"handshakePlusOneRTTMillis":
2023-07-05T22:41:18.8190833Z zig-v0_0_1_x_zig-v0_0_1__quic-v1_-dialer-1 | {"handshakePlusOneRTTMillis":
2023-07-05T22:41:18.8191389Z zig-v0_0_1_x_zig-v0_0_1__quic-v1_-dialer-1 | 8.849
2023-07-05T22:41:18.8191930Z zig-v0_0_1_x_zig-v0_0_1__quic-v1_-dialer-1 | , "pingRTTMilllis":
2023-07-05T22:41:18.8191930Z zig-v0_0_1_x_zig-v0_0_1__quic-v1_-dialer-1 | , "pingRTTMilllis":
2023-07-05T22:41:18.8192455Z zig-v0_0_1_x_zig-v0_0_1__quic-v1_-dialer-1 | 7.897}
2023-07-05T22:41:18.8192987Z zig-v0_0_1_x_zig-v0_0_1__quic-v1_-dialer-1 exited with code 0`

Expand All @@ -71,16 +81,16 @@ function test() {
{
const exampleComposeStdout = `
2023-07-06T00:36:52.6198781Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-redis-1 | 1:M 06 Jul 2023 00:36:19.136 * Ready to accept connections
2023-07-06T00:36:52.6199494Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-listener-1 |
2023-07-06T00:36:52.6199494Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-listener-1 |
2023-07-06T00:36:52.6200270Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-listener-1 | > multidim-interop@1.0.0 test
2023-07-06T00:36:52.6201247Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-listener-1 | > aegir test --build false --types false -t browser -- --browser firefox
2023-07-06T00:36:52.6202009Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-listener-1 |
2023-07-06T00:36:52.6202659Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-listener-1 |
2023-07-06T00:36:52.6203296Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-dialer-1 |
2023-07-06T00:36:52.6202009Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-listener-1 |
2023-07-06T00:36:52.6202659Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-listener-1 |
2023-07-06T00:36:52.6203296Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-dialer-1 |
2023-07-06T00:36:52.6204045Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-dialer-1 | > multidim-interop@1.0.0 test
2023-07-06T00:36:52.6205016Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-dialer-1 | > aegir test --build false --types false -t browser -- --browser firefox
2023-07-06T00:36:52.6205760Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-dialer-1 |
2023-07-06T00:36:52.6206397Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-dialer-1 |
2023-07-06T00:36:52.6205760Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-dialer-1 |
2023-07-06T00:36:52.6206397Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-dialer-1 |
2023-07-06T00:36:52.6207074Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-listener-1 | test browser
2023-07-06T00:36:52.6207782Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-dialer-1 | test browser
2023-07-06T00:36:52.6208473Z firefox-js-v0_45_x_firefox-js-v0_45__webrtc__noise__yamux_-dialer-1 | 
Expand All @@ -96,6 +106,63 @@ function test() {

const expectedParsed = JSON.stringify({ "handshakePlusOneRTTMillis": 4155, "pingRTTMilllis": 781 })
assert(JSON.stringify(dialerTimings(dialerStdout(exampleComposeStdout))) === expectedParsed)

}

{
const exampleComposeStdout = `
Attaching to dialer-1, listener-1, redis-1
redis-1 | 1:C 05 May 2024 12:33:40.595 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
redis-1 | 1:C 05 May 2024 12:33:40.595 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
redis-1 | 1:C 05 May 2024 12:33:40.595 * Redis version=7.2.4, bits=64, commit=00000000, modified=0, pid=1, just started
redis-1 | 1:C 05 May 2024 12:33:40.595 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
redis-1 | 1:M 05 May 2024 12:33:40.596 * monotonic clock: POSIX clock_gettime
redis-1 | 1:M 05 May 2024 12:33:40.596 * Running mode=standalone, port=6379.
redis-1 | 1:M 05 May 2024 12:33:40.597 * Server initialized
redis-1 | 1:M 05 May 2024 12:33:40.597 * Ready to accept connections tcp
listener-1 | [2024-05-05T12:33:41Z INFO interop_tests] Running ping test: 12D3KooWT3dMe8wpuqmztR3syYzni4vVk3TSCGujMGBeGN3qR4Cn
listener-1 | [2024-05-05T12:33:41Z INFO interop_tests] Test instance, listening for incoming connections on: "/ip4/0.0.0.0/udp/0/webrtc-direct".
dialer-1 |
dialer-1 | > @libp2p/multidim-interop@2.0.31 test:interop:multidim
dialer-1 | > aegir test --build false --types false -t browser -- --browser firefox
dialer-1 |
dialer-1 | test browser
dialer-1 | [JavaScript Error: "Clear-Site-Data header found. Unknown value “"cache"”." {file: "http://127.0.0.1:34451/" line: 0}]
dialer-1 | [JavaScript Error: "Clear-Site-Data header forced the clean up of “cookies” data." {file: "http://127.0.0.1:34451/" line: 0}]
dialer-1 | [JavaScript Error: "Clear-Site-Data header forced the clean up of “storage” data." {file: "http://127.0.0.1:34451/" line: 0}]
dialer-1 |
dialer-1 | ping test
dialer-1 | - should listen for ping
listener-1 | [2024-05-05T12:33:55Z INFO webrtc::peer_connection] signaling state changed to have-remote-offer
listener-1 | [2024-05-05T12:33:55Z INFO webrtc_ice::mdns] mDNS is using 224.0.0.251:5353 as dest_addr
listener-1 | [2024-05-05T12:33:55Z INFO webrtc_ice::agent::agent_internal] [controlled]: Setting new connection state: Checking
listener-1 | [2024-05-05T12:33:55Z INFO webrtc_mdns::conn] Looping and listening Ok(224.0.0.251:5353)
listener-1 | [2024-05-05T12:33:55Z INFO webrtc::peer_connection] ICE connection state changed: checking
listener-1 | [2024-05-05T12:33:55Z INFO webrtc::peer_connection] signaling state changed to stable
listener-1 | [2024-05-05T12:33:55Z INFO webrtc_ice::agent::agent_internal] [controlled]: Setting new connection state: Connected
listener-1 | [2024-05-05T12:33:55Z INFO webrtc::peer_connection] ICE connection state changed: connected
listener-1 | [2024-05-05T12:33:55Z WARN webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 16
listener-1 | [2024-05-05T12:33:55Z WARN webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 28
listener-1 | [2024-05-05T12:33:55Z WARN webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 16
listener-1 | [2024-05-05T12:33:55Z WARN webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 28
listener-1 | [2024-05-05T12:33:55Z WARN webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 16
listener-1 | [2024-05-05T12:33:55Z WARN webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 28
listener-1 | [2024-05-05T12:33:55Z WARN webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 16
listener-1 | [2024-05-05T12:33:55Z WARN webrtc_dtls::handshake::handshake_message_client_hello] Unsupported Extension Type 0 28
listener-1 | [2024-05-05T12:33:55Z INFO webrtc::peer_connection] peer connection state changed: connected
listener-1 | [2024-05-05T12:33:55Z INFO libp2p_webrtc_utils::stream::drop_listener] Stream dropped without graceful close, sending Reset
listener-1 | [2024-05-05T12:33:56Z INFO libp2p_webrtc_utils::stream::drop_listener] Stream dropped without graceful close, sending Reset
dialer-1 | {"handshakePlusOneRTTMillis":1384,"pingRTTMilllis":39}
dialer-1 | ✅ should dial and ping (1405ms)
listener-1 | [2024-05-05T12:33:57Z WARN webrtc_sctp::association] [] failed to read packets on net_conn: Alert is Fatal or Close Notify
dialer-1 | 1 passing (2s)
dialer-1 | 1 pending
listener-1 | [2024-05-05T12:33:57Z INFO libp2p_webrtc_utils::stream::drop_listener] Stream dropped without graceful close, sending Reset
dialer-1 exited with code 0
`

const expectedParsed = JSON.stringify({ "handshakePlusOneRTTMillis": 1384, "pingRTTMilllis": 39 })
assert(JSON.stringify(dialerTimings(dialerStdout(exampleComposeStdout))) === expectedParsed)
}
}

Expand Down

0 comments on commit fd59ed7

Please sign in to comment.