Add print snapshot tests
WIP add snapshot tests for decoding print output using log frames and compiled elf files
WIP for #876
This looks great - just a clippy lint to fix about not waiting on a spawned process. That seems like it might be important.
In terms of the differences between defmt-print and the qemu-run decoded output, I have a few findings.
With the log format set to "{L:4} {s}"
Almost all the tests work, with the exceptions of: hints, hints_inner, assert_eq, timestamp.
hints and hints_inner are missing initial timestamp information, like this:
-0.000000 INFO no hint 42
-0.000001 INFO hex 2a
+INFO no hint 42
+INFO hex 2a
or
-0.000000 INFO S1 { x: "hi", y: 0x2a }
-0.000001 INFO S2 { x: 0x2a }
+INFO S1 { x: "hi", y: 0x2a }
+INFO S2 { x: 0x2a }
and timestamp misses a more formatted timestamp:
-It is 10:20:30 true false INFO test true
-It is 10:20:30 true false Hello World!
+INFO test true
+Hello World!
The assertion has a totally different format, like so
- left: `41`
-right: `43`
+diff < left / right >
+<41
+>43
Adding a timestamp argument to the log format "{t} {L:4} {s}"
The info log in timestamp is fixed, but not the println, as that isn't affected by the log format argument,
-It is 10:20:30 true false Hello World!
+Hello World!
The hints snapshot gets the wrong order on timestamps seemingly:
-0.000005 INFO octal 52
-0.000006 INFO octal alt 0o52
+0.000005 INFO octal 42
+0.000006 INFO octal alt 42
but hints_inner passes correctly with this format.
This isn't a good fix to add to all tests however, as all other snapshots fail, due to a missing timestamp being added like so:
-TRACE a = 127.0.0.1
-TRACE b = 127.0.0.1
+<time> TRACE a = 127.0.0.1
+<time> TRACE b = 127.0.0.1
Full diff of outputs:
timestamp
-It is 10:20:30 true false INFO test true
-It is 10:20:30 true false Hello World!
+INFO test true
+Hello World!
assert-eq
- left: `41`
-right: `43`
+diff < left / right >
+<41
+>43
hints
-0.000000 INFO no hint 42
-0.000001 INFO hex 2a
-0.000002 INFO hex alt 0x2a
-0.000003 INFO HEX 2A
-0.000004 INFO HEX alt 0x2A
-0.000005 INFO octal 52
-0.000006 INFO octal alt 0o52
-0.000007 INFO binary 101010
-0.000008 INFO binary alt 0b101010
-0.000009 INFO ASCII 42
-0.000010 INFO Debug 42
-0.000011 INFO ----
-0.000012 INFO no-hint 42
-0.000013 INFO hex 2a
-0.000014 INFO hex alt 0x2a
-0.000015 INFO HEX 2A
-0.000016 INFO HEX alt 0x2A
-0.000017 INFO octal 52
-0.000018 INFO octal alt 0o52
-0.000019 INFO binary 101010
-0.000020 INFO binary alt 0b101010
-0.000021 INFO ASCII 42
-0.000022 INFO Debug 42
-0.000023 INFO ----
-0.000024 INFO no hint 42
-0.000025 INFO hex 2a
-0.000026 INFO hex alt 0x2a
-0.000027 INFO HEX 2A
-0.000028 INFO HEX alt 0x2A
-0.000029 INFO octal 52
-0.000030 INFO octal alt 0o52
-0.000031 INFO binary 101010
-0.000032 INFO binary alt 0b101010
-0.000033 INFO ASCII 42
-0.000034 INFO Debug 42
-0.000035 INFO ----
-0.000036 INFO S1 > S2 101010
-0.000037 INFO ----
-0.000038 INFO no hint [72, 101, 127, 108, 108, 111]
-0.000039 INFO hex [48, 65, 7f, 6c, 6c, 6f]
-0.000040 INFO hex alt [0x48, 0x65, 0x7f, 0x6c, 0x6c, 0x6f]
-0.000041 INFO HEX [48, 65, 7F, 6C, 6C, 6F]
-0.000042 INFO HEX alt [0x48, 0x65, 0x7F, 0x6C, 0x6C, 0x6F]
-0.000043 INFO octal [110, 145, 177, 154, 154, 157]
-0.000044 INFO octal alt [0o110, 0o145, 0o177, 0o154, 0o154, 0o157]
-0.000045 INFO binary [1001000, 1100101, 1111111, 1101100, 1101100, 1101111]
-0.000046 INFO binary alt [0b1001000, 0b1100101, 0b1111111, 0b1101100, 0b1101100, 0b1101111]
-0.000047 INFO ASCII b"He\x7fllo"
-0.000048 INFO Debug [72, 101, 127, 108, 108, 111]
-0.000049 INFO ----
-0.000050 INFO b"\x00\x01\x02\x03\x04\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11\x12\x13\x14\x15\x16\x17\x18\x19\x1a\x1b\x1c\x1d\x1e\x1f !\"#$%&'()*+,-./0123456789:;<=>?@ABCDEFGHIJKLMNOPQRSTUVWXYZ[\\]^_`abcdefghijklmnopqrstuvwxyz{|}~\x7f\x80\x81\x82\x83\x84\x85\x86\x87\x88\x89\x8a\x8b\x8c\x8d\x8e\x8f\x90\x91\x92\x93\x94\x95\x96\x97\x98\x99\x9a\x9b\x9c\x9d\x9e\x9f\xa0\xa1\xa2\xa3\xa4\xa5\xa6\xa7\xa8\xa9\xaa\xab\xac\xad\xae\xaf\xb0\xb1\xb2\xb3\xb4\xb5\xb6\xb7\xb8\xb9\xba\xbb\xbc\xbd\xbe\xbf\xc0\xc1\xc2\xc3\xc4\xc5\xc6\xc7\xc8\xc9\xca\xcb\xcc\xcd\xce\xcf\xd0\xd1\xd2\xd3\xd4\xd5\xd6\xd7\xd8\xd9\xda\xdb\xdc\xdd\xde\xdf\xe0\xe1\xe2\xe3\xe4\xe5\xe6\xe7\xe8\xe9\xea\xeb\xec\xed\xee\xef\xf0\xf1\xf2\xf3\xf4\xf5\xf6\xf7\xf8\xf9\xfa\xfb\xfc\xfd\xfe\xff"
-0.000051 INFO b"\x00\x01\x02\x03\x04\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11\x12\x13\x14\x15\x16\x17\x18\x19\x1a\x1b\x1c\x1d\x1e\x1f !\"#$%&'()*+,-./0123456789:;<=>?@ABCDEFGHIJKLMNOPQRSTUVWXYZ[\\]^_`abcdefghijklmnopqrstuvwxyz{|}~\x7f\x80\x81\x82\x83\x84\x85\x86\x87\x88\x89\x8a\x8b\x8c\x8d\x8e\x8f\x90\x91\x92\x93\x94\x95\x96\x97\x98\x99\x9a\x9b\x9c\x9d\x9e\x9f\xa0\xa1\xa2\xa3\xa4\xa5\xa6\xa7\xa8\xa9\xaa\xab\xac\xad\xae\xaf\xb0\xb1\xb2\xb3\xb4\xb5\xb6\xb7\xb8\xb9\xba\xbb\xbc\xbd\xbe\xbf\xc0\xc1\xc2\xc3\xc4\xc5\xc6\xc7\xc8\xc9\xca\xcb\xcc\xcd\xce\xcf\xd0\xd1\xd2\xd3\xd4\xd5\xd6\xd7\xd8\xd9\xda\xdb\xdc\xdd\xde\xdf\xe0\xe1\xe2\xe3\xe4\xe5\xe6\xe7\xe8\xe9\xea\xeb\xec\xed\xee\xef\xf0\xf1\xf2\xf3\xf4\xf5\xf6\xf7\xf8\xf9\xfa\xfb\xfc\xfd\xfe\xff"
-0.000052 INFO ----
-0.000053 INFO no hint Hello
-0.000054 INFO Debug "Hello"
-0.000055 INFO no hint world
-0.000056 INFO Debug "world"
-0.000057 INFO ----
-0.000058 INFO no hint 10
-0.000059 INFO hex a
-0.000060 INFO hex 0xa
-0.000061 INFO HEX A
-0.000062 INFO HEX 0xA
-0.000063 INFO octal 12
-0.000064 INFO octal 0o12
-0.000065 INFO binary 1010
-0.000066 INFO binary 0b1010
-0.000067 INFO ASCII b"\n"
-0.000068 INFO Debug 10
-0.000069 INFO ISO8601 2021-04-20T09:23:44.804Z
-0.000070 INFO ISO8601 +53271-03-27T11:46:44Z
-0.000071 INFO Sec ms 1234.567
-0.000072 INFO Sec us 1.234567
-0.000073 INFO Time s 14:06:56:07
-0.000074 INFO Time ms 00:20:34.567
-0.000075 INFO Time us 00:00:01.234567
+INFO no hint 42
+INFO hex 2a
+INFO hex alt 0x2a
+INFO HEX 2A
+INFO HEX alt 0x2A
+INFO octal 42
+INFO octal alt 42
+INFO binary 101010
+INFO binary alt 0b101010
+INFO ASCII 42
+INFO Debug 42
+INFO ----
+INFO no-hint 42
+INFO hex 2a
+INFO hex alt 0x2a
+INFO HEX 2A
+INFO HEX alt 0x2A
+INFO octal 42
+INFO octal alt 42
+INFO binary 101010
+INFO binary alt 0b101010
+INFO ASCII 42
+INFO Debug 42
+INFO ----
+INFO no hint 42
+INFO hex 2a
+INFO hex alt 0x2a
+INFO HEX 2A
+INFO HEX alt 0x2A
+INFO octal 42
+INFO octal alt 42
+INFO binary 101010
+INFO binary alt 0b101010
+INFO ASCII 42
+INFO Debug 42
+INFO ----
+INFO S1 > S2 101010
+INFO ----
+INFO no hint [72, 101, 127, 108, 108, 111]
+INFO hex [48, 65, 7f, 6c, 6c, 6f]
+INFO hex alt [0x48, 0x65, 0x7f, 0x6c, 0x6c, 0x6f]
+INFO HEX [48, 65, 7F, 6C, 6C, 6F]
+INFO HEX alt [0x48, 0x65, 0x7F, 0x6C, 0x6C, 0x6F]
+INFO octal [72, 101, 127, 108, 108, 111]
+INFO octal alt [72, 101, 127, 108, 108, 111]
+INFO binary [1001000, 1100101, 1111111, 1101100, 1101100, 1101111]
+INFO binary alt [0b1001000, 0b1100101, 0b1111111, 0b1101100, 0b1101100, 0b1101111]
+INFO ASCII b"He\x7fllo"
+INFO Debug [72, 101, 127, 108, 108, 111]
+INFO ----
+INFO b"\x00\x01\x02\x03\x04\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11\x12\x13\x14\x15\x16\x17\x18\x19\x1a\x1b\x1c\x1d\x1e\x1f !\"#$%&'()*+,-./0123456789:;<=>?@ABCDEFGHIJKLMNOPQRSTUVWXYZ[\\]^_`abcdefghijklmnopqrstuvwxyz{|}~\x7f\x80\x81\x82\x83\x84\x85\x86\x87\x88\x89\x8a\x8b\x8c\x8d\x8e\x8f\x90\x91\x92\x93\x94\x95\x96\x97\x98\x99\x9a\x9b\x9c\x9d\x9e\x9f\xa0\xa1\xa2\xa3\xa4\xa5\xa6\xa7\xa8\xa9\xaa\xab\xac\xad\xae\xaf\xb0\xb1\xb2\xb3\xb4\xb5\xb6\xb7\xb8\xb9\xba\xbb\xbc\xbd\xbe\xbf\xc0\xc1\xc2\xc3\xc4\xc5\xc6\xc7\xc8\xc9\xca\xcb\xcc\xcd\xce\xcf\xd0\xd1\xd2\xd3\xd4\xd5\xd6\xd7\xd8\xd9\xda\xdb\xdc\xdd\xde\xdf\xe0\xe1\xe2\xe3\xe4\xe5\xe6\xe7\xe8\xe9\xea\xeb\xec\xed\xee\xef\xf0\xf1\xf2\xf3\xf4\xf5\xf6\xf7\xf8\xf9\xfa\xfb\xfc\xfd\xfe\xff"
+INFO b"\x00\x01\x02\x03\x04\x05\x06\x07\x08\t\n\x0b\x0c\r\x0e\x0f\x10\x11\x12\x13\x14\x15\x16\x17\x18\x19\x1a\x1b\x1c\x1d\x1e\x1f !\"#$%&'()*+,-./0123456789:;<=>?@ABCDEFGHIJKLMNOPQRSTUVWXYZ[\\]^_`abcdefghijklmnopqrstuvwxyz{|}~\x7f\x80\x81\x82\x83\x84\x85\x86\x87\x88\x89\x8a\x8b\x8c\x8d\x8e\x8f\x90\x91\x92\x93\x94\x95\x96\x97\x98\x99\x9a\x9b\x9c\x9d\x9e\x9f\xa0\xa1\xa2\xa3\xa4\xa5\xa6\xa7\xa8\xa9\xaa\xab\xac\xad\xae\xaf\xb0\xb1\xb2\xb3\xb4\xb5\xb6\xb7\xb8\xb9\xba\xbb\xbc\xbd\xbe\xbf\xc0\xc1\xc2\xc3\xc4\xc5\xc6\xc7\xc8\xc9\xca\xcb\xcc\xcd\xce\xcf\xd0\xd1\xd2\xd3\xd4\xd5\xd6\xd7\xd8\xd9\xda\xdb\xdc\xdd\xde\xdf\xe0\xe1\xe2\xe3\xe4\xe5\xe6\xe7\xe8\xe9\xea\xeb\xec\xed\xee\xef\xf0\xf1\xf2\xf3\xf4\xf5\xf6\xf7\xf8\xf9\xfa\xfb\xfc\xfd\xfe\xff"
+INFO ----
+INFO no hint Hello
+INFO Debug "Hello"
+INFO no hint world
+INFO Debug "world"
+INFO ----
+INFO no hint 10
+INFO hex a
+INFO hex 0xa
+INFO HEX A
+INFO HEX 0xA
+INFO octal 10
+INFO octal 10
+INFO binary 1010
+INFO binary 0b1010
+INFO ASCII b"\n"
+INFO Debug 10
+INFO ISO8601 2021-04-20T09:23:44.804Z
+INFO ISO8601 +53271-03-27T11:46:44Z
+INFO Sec ms 1234.567
+INFO Sec us 1.234567
+INFO Time s 14:06:56:07
+INFO Time ms 00:20:34.567
+INFO Time us 00:00:01.234567
hints-inner
-0.000000 INFO S1 { x: "hi", y: 0x2a }
-0.000001 INFO S2 { x: 0x2a }
-0.000002 WARN Debug hint: S { x: "hello", y: 512 }
-0.000003 WARN no hint: S { x: "hello", y: 1024 }
-0.000004 INFO S2 { s: S1 { x: 0b100, y: 12 }, z: 20 }
-0.000005 INFO S2 { s: S1 { x: 0b100, y: 12 }, z: 20 }
-0.000006 INFO S2 { s: S1 { x: 0b100, y: 12 }, z: 0x14 }
-0.000007 INFO S2 { s: S1 { x: 0b100, y: 12 }, z: 0b10100 }
-0.000008 INFO S1 { x: "hi", y: 42 }
-0.000009 INFO S1 { x: "hi", y: 0x2a }
+INFO S1 { x: "hi", y: 0x2a }
+INFO S2 { x: 0x2a }
+WARN Debug hint: S { x: "hello", y: 512 }
+WARN no hint: S { x: "hello", y: 1024 }
+INFO S2 { s: S1 { x: 0b100, y: 12 }, z: 20 }
+INFO S2 { s: S1 { x: 0b100, y: 12 }, z: 20 }
+INFO S2 { s: S1 { x: 0b100, y: 12 }, z: 0x14 }
+INFO S2 { s: S1 { x: 0b100, y: 12 }, z: 0b10100 }
+INFO S1 { x: "hi", y: 42 }
+INFO S1 { x: "hi", y: 0x2a }