cint university / 201 / ced, the cint editor
201-07: debugging by comparison
This is lesson 201-07 of CU-201.2, checked against cint 0.2.0.
You will compare runs to find a bug. You will make one change at a time against a golden, read two fault reports side by side and check three ways of running one program against each other.
the method
A cint program run twice by one release prints the same bytes and, when it faults, the same fault report. So a run is a fixed thing you can compare, and a difference between two runs points at a cause. The steps run in this order:
| Step | What you do | With |
|---|---|---|
| 1 | Reproduce: run the program twice and compare. | cint run and diff |
| 2 | Keep a golden of a run you checked. | the output, and the reference's record (201-05) |
| 3 | Change one thing, run again and compare with the golden. | diff |
| 4 | Read the first difference; the ones after it often follow from it. | diff |
| 5 | Read two fault reports as data. | the fault report |
| 6 | Read the lines that identify the run: revision and fuel-consumed. |
the fault report and the record |
| 7 | Check that the ways of running the program agree. | cint run, cint debug and the reference |
| 8 | Locate the operation that faulted and keep the case. | cint debug locate --save-case |
When the code is a module, the workbench of 201-06 adds rewinding and bisection to steps 4 and 8.
the program
Adler-32 is the checksum inside every zlib stream, including the image data of PNG files. It keeps two sums, a and b, and takes both remainders by 65,521 after every byte:
// adler.ci: the Adler-32 checksum, which zlib and PNG files use.
const U32 MOD = 65_521;
U32 adler32[n](in U8[n] data) {
U32 a = 1;
U32 b = 0;
for i in 0..n {
a = (a + (data[i] as U32)) % MOD;
b = (b + a) % MOD;
}
return (b << 16) | a;
}
void main() {
U8[20_000] letters;
U8[20_000] high;
for i in 0..20_000 {
letters[i] = 97; // the letter a
high[i] = 255; // the largest byte
}
U32 w = adler32("Wikipedia");
"Wikipedia {w:x}\n";
U32 l = adler32(letters);
"20000 a {l:x}\n";
U32 h = adler32(high);
"20000 x 255 {h:x}\n";
}
$ cint run adler.ci
Wikipedia 11e60398
20000 a 62f99bd4
20000 x 255 9f51d664
Python's zlib.adler32 gives the same three values.
steps 1 and 2: reproduce, then keep a golden
$ cint run adler.ci > run1.txt
$ cint run adler.ci > run2.txt
$ diff run1.txt run2.txt
$ cint run adler.ci > golden.txt
$ python3 -m cint_ref run adler.ci > adler.expect
diff prints nothing: the two runs are the same, byte for byte. If two runs of one program by one release ever differ, that is a defect in cint. Check the three values by hand, here against zlib, and save the golden and the reference's record. In PowerShell on Windows, compare the two files with fc.exe /b run1.txt run2.txt, which says no differences encountered when they match. Save the record with cmd /c, as in 201-05. Type fc.exe in full, since fc alone is the PowerShell alias for Format-Custom. To see which lines differ, use VS Code's Select for Compare, as in 401-01.
step 3: one change
zlib does not take the remainders after every byte. It adds up a block of bytes first and takes the remainders once per block, which saves work. Replace adler32 with this version:
// Take the remainders once per block, not once per byte. zlib uses
// 5552, the largest block after which b still fits in a U32.
const I64 BLOCK = 5_552;
U32 adler32[n](in U8[n] data) {
U32 a = 1;
U32 b = 0;
I64 start = 0;
while (start < n) {
I64 end = start + BLOCK;
if (end > n) {
end = n;
}
for i in start..end {
a += data[i] as U32;
b += a;
}
a %= MOD;
b %= MOD;
start = end;
}
return (b << 16) | a;
}
Run it into a new file and compare:
$ cint run adler.ci > after.txt
$ diff golden.txt after.txt
$ python3 -m cint_ref check adler.ci adler.expect
adler.expect: line 6 differs
expected: fuel-consumed 60013
actual: fuel-consumed 60022
The output matches the golden. The record shows that the path changed, which is what the change was for. The first version takes two remainders for every byte, 80,018 in all, and the block version takes two for every block, 18 in all. Fuel is charged at each call and at each pass through a loop, not for each operation, so the block version's 9 passes through while add 9. Fuel measures the path a run takes, not its speed. Save the new record in a step of its own.
step 4: a second change, and the first difference
Now raise BLOCK to 8_192 and leave the comment as it was. Run and compare again:
$ cint run adler.ci > after.txt
fault[E_OVERFLOW]: the exact result is outside the type's range
--> adler.ci:20:15
|
20 | b += a;
| ^ add.checked.u32
|
= operation: add.checked.u32
= operand-count: 2
= operand: U32 4294283833
= operand: U32 1480021
= exact: 4295763854
= limit: U32 4294967295
= revision: 4d94cdfe0404d5729f9866a699d45a763db38646e80ce3f71a1a3132eb1b6099
= source-map: none
= address: none
= stack-depth: 1
= called from: adler.ci:40:13
= fuel-consumed: 45822 (not part of the fault record)
= state: the program stopped; stdout holds what it wrote before the fault
$ diff golden.txt after.txt
3d2
< 20000 x 255 9f51d664
The fault report appears in the terminal and not in after.txt, because cint writes it to a separate stream, standard error. The output stops after line 2, so the first difference is line 3: the third message never finished. The report says why. Adding a to b at line 20 went past the largest U32, 4294967295, while the call at line 40 computed the checksum of the third message.
The operands say where in the message. a started at 1 and grows by 255 with each byte, so a = 1480021 = 1 + 255 × 5804: the sum broke on byte 5804 of the third message, in its first block. A block of 8192 bytes of 255 is more than b can hold.
step 5: two fault reports as data
Change the third message to 20,000 bytes of 200 (high[i] = 200;) and run again. The report starts the same way:
fault[E_OVERFLOW]: the exact result is outside the type's range
--> adler.ci:20:15
|
20 | b += a;
| ^ add.checked.u32
|
= operation: add.checked.u32
= operand-count: 2
= operand: U32 4294842753
= operand: U32 1310801
= exact: 4296153554
...
The code, the operation and the position are the same, and the operands are new. Now a = 1310801 = 1 + 200 × 6554, so the smaller bytes took 6554 of them to break the sum. Read two reports this way:
| Two reports with | Mean |
|---|---|
| the same code, operation, position and operands | the same fault, reproduced |
| the same position and new operands | the same bug, reached by new data |
| a new position | a new fault, to read on its own |
Put the 255 back.
step 6: the lines that identify a run
Add a comment line at the top of adler.ci and run again:
--> adler.ci:21:15
...
= revision: 4d94cdfe0404d5729f9866a699d45a763db38646e80ce3f71a1a3132eb1b6099
...
= called from: adler.ci:41:13
= fuel-consumed: 45822 (not part of the fault record)
Every position moved down one line, and the revision stayed the same. The revision is a digest of the compiled program. A comment or a blank line does not change it, while renaming a variable or changing a value does. The module's name is part of it too, so keep editing adler.ci instead of saving copies under new names. When a report moves, the revision says whether the code changed or only moved. The fuel is the same too: the run took the same path to the same fault.
step 7: three ways to run it
cint run compiles the program to C and runs it with your C compiler. cint debug locate, in step 8, runs it in the interpreter. The reference runs it in Python. All three must agree, and here they do. This is the reference's record of the faulting run:
$ python3 -m cint_ref run adler.ci > fault.expect
$ cat fault.expect
case adler
source reference
outcome fault
stdout-bytes 46
stdout-sha256 5f8d699b8acfd3a2c790a21a2df45c68e91fab8e3482b95125864a5490a056b5
fuel-consumed 45822
fault.code E_OVERFLOW
fault.operation add.checked.u32
fault.operand U32 4294283833
fault.operand U32 1480021
fault.exact 4295763854
fault.limit U32 4294967295
fault.position adler.ci:20:15
fault.revision self
fault.address none
fault.stack-depth 1
It holds the same code, operation, operands, position and fuel as the compiled run. The reference writes self where the compiled run prints the revision's digest. If two of the three ever disagree, the program is not the problem: that is a defect in cint, and the case of step 8 is what to report.
For code you run in the workbench, cint debug diff makes the same check from the terminal. It takes a case of calls to exported functions, like one saved in a session, and refuses a case of a whole program such as overflow.case. In the session of 201-06, :checkpoint s, then :run d() 3, then :save-case three.case saves the three calls as a case. cint debug diff runs it in your C compiler's build and in the interpreter and compares the two after every entry:
$ cint debug diff three.case
case three.case 3 boundaries density entry
reference cpu-c17
candidate cpu-sir-interp
boundaries 3 of 3 compared
outcome agree
In this output, reference names the side the other is compared against, here the C build, and not the Python reference. cint debug diff exits with status 0 when the two agree and 3 when they do not.
step 8: locate the operation and keep the case
cint debug locate runs the program in the interpreter, replays it to the fault and lists the last operations before it. --save-case keeps the run. The first lines say what it searched. A whole program is one entry, so its run has one boundary, at its end, and the fault is there. The count of trace events is every operation the interpreter replayed, and the workbench's :trace lists them all.
$ cint debug locate adler.ci --save-case overflow.case
program adler.ci evaluator cpu-sir-interp, recorded as the case overflow.case
target boundary 1 of 1, the program entry: the first fault, reproduced by replay
bracket the initial state; then boundary 1
fault[E_OVERFLOW]: the exact result is outside the type's range
--> adler.ci:20:15
...
the last 20 counted operations of boundary 1, of 189084 trace events (:trace shows them all)
ord position operation operands value
...
189072 add.wrap.i64 5801, 1 5802
189073 adler.ci:19:22 index.checked.u8 5802
189074 adler.ci:19:26 as.checked.u8.u32 255 255
189075 adler.ci:19:15 add.checked.u32 1479511, 255 1479766
189076 adler.ci:20:15 add.checked.u32 4292804067, 1479766 4294283833
189077 add.wrap.i64 5802, 1 5803
189078 adler.ci:19:22 index.checked.u8 5803
189079 adler.ci:19:26 as.checked.u8.u32 255 255
189080 adler.ci:19:15 add.checked.u32 1479766, 255 1480021
189081 adler.ci:20:15 add.checked.u32 4294283833, 1480021 E_OVERFLOW
Each byte is five rows. The loop counts i up by one in the rows with no position. Then it reads data[i], widens it to U32 and adds it to a, and last it adds a to b. b climbs toward the limit, 4292804067, then 4294283833, and the next addition faults. The index is 5803, counted from 0, which is byte 5804, as step 4 worked out from the operands.
overflow.case holds the program's source and its run. Copy it to another folder and cint debug locate overflow.case reproduces the same fault from the case alone, without adler.ci. It is the file to attach to a bug report.
the fix
Put BLOCK back to 5_552, run and compare with the golden: the output matches. zlib's source gives 5_552 as the largest block length n for which 255n(n + 1)/2 + (n + 1)(65,521 - 1) is at most 232 - 1. The expression is the largest b can reach after a block of bytes of 255 when a and b start just below 65,521.
elsewhere
The same function in C, with uint32_t sums and a block of 8192, built with GCC 13.3 and -O2 -Wall -Wextra on Ubuntu 24.04 for x86-64, gives no warning and exits with status 0. It prints 9caed664 for the third message where Adler-32 is 9f51d664, because uint32_t arithmetic wraps. Clang has a check for this, -fsanitize=unsigned-integer-overflow, which is off unless a build turns it on. Built with Clang 18.1 and that check in its trapping form, the program stopped at the third message. Without such a check, only a golden or a test against a known value catches the wrong checksum. Written in Python, the same function gives the right checksum with a block of any size, because Python's integers have no fixed size.
walk-through
data[i] as U32 widens a byte to U32. Widening never fails, and the trace shows it as its own operation, as.checked.u8.u32.
(b << 16) | a puts b in the top 16 bits and a in the bottom 16. Both are below 65,521 at this point, so the shift cannot overflow.
while (start < n) walks the data a block at a time. The if shortens the last block, so end never passes n.
try this
- With
BLOCKat8_192, changeb += a;tob +%= a;, which wraps as C does. The program runs to the end. Which line of the golden differs, and which line of the record? - Find the largest
BLOCKfor which this program runs without a fault. Is it safe for every message? Compare it with 5552. - Run
cint debug locateon the version with bytes of 200 and compare its last operations with the version with 255.
reference
fault record, revision, fuel, cases, wrapping and saturating operators, golden
Next: 201-08, control flow.