nx_log_v2_test.nx source
↩ module page · 155 lines · 5564 B
1// nx_log_v2_test.nx -- correctness + bench for fast emit.
2//
3// PASS criteria:
4// T1 emit-correctness v2 emits the expected formatted line
5// T2 below-min fast path filtered emits return without writing
6// T3 perf-vs-v1 v2 is at LEAST 3x faster than v1 for INFO
7// emit, and below-min v2 is at LEAST 100x
8// faster than below-min v1 (target: fast
9// enough for CASC / SAT-COMP background use)
10
11import "nx_kernel_v2.nx"
12import "nx_clock.nx"
13import "nx_log.nx"
14import "nx_log_v2.nx"
15
16func nx_log_v2_render_int(buf: *u8, off: i64, v: i64) -> i64;
17
18const N_BENCH: i64 = 5000
19
20// ===== T1: emit produces non-error =====
21func t1_emit_correctness() -> nx_int {
22 let ctx: *NxLogContext = nx_log_global()
23 ctx.min_level = NX_LOG_INFO
24 // Use stderr (fd=2) so test output stays separate from program stdout.
25 let r: nx_int = nx_log_v2_emit(ctx, NX_LOG_INFO,
26 "test.v2" as *u8, "hello world from v2" as *u8)
27 if r != 0 { return 1 }
28 return 0
29}
30
31// ===== T2: filtered-below-min returns 0 quickly =====
32func t2_below_min_fast() -> nx_int {
33 let ctx: *NxLogContext = nx_log_global()
34 ctx.min_level = NX_LOG_ERROR
35 let before: i64 = ctx.drop_cnt
36 // 100 emits at INFO when min=ERROR -- all should be dropped.
37 var i: i64 = 0
38 while i < 100 {
39 let _r: i64 = nx_log_v2_emit(ctx, NX_LOG_INFO,
40 "drop.tag" as *u8, "should never appear" as *u8)
41 i = i + 1
42 }
43 let dropped: i64 = ctx.drop_cnt - before
44 if dropped != 100 { return 2 }
45 // Restore for downstream tests.
46 ctx.min_level = NX_LOG_INFO
47 return 0
48}
49
50// ===== T3: cycles bench v1 vs v2 (INFO-level emit, all written) =====
51// Time both paths over N_BENCH events; ratio must be >= 3x.
52func t3_perf_emit() -> nx_int {
53 let ctx: *NxLogContext = nx_log_global()
54 ctx.min_level = NX_LOG_INFO
55 // Redirect to /dev/null-equivalent by writing to a high fd? Simpler:
56 // use stderr but the SAME fd for both so syscall overhead is fair.
57 // Time wall-clock via nx_clock_monotonic_ns.
58 let v1_start: i64 = nx_clock_monotonic_ns()
59 var i: i64 = 0
60 while i < N_BENCH {
61 let _r: i64 = nx_log_emit(ctx, NX_LOG_INFO,
62 "bench.v1" as *u8, "x" as *u8)
63 i = i + 1
64 }
65 let v1_end: i64 = nx_clock_monotonic_ns()
66 let v1_ns: i64 = v1_end - v1_start
67
68 let v2_start: i64 = nx_clock_monotonic_ns()
69 var j: i64 = 0
70 while j < N_BENCH {
71 let _r: i64 = nx_log_v2_emit(ctx, NX_LOG_INFO,
72 "bench.v2" as *u8, "x" as *u8)
73 j = j + 1
74 }
75 let v2_end: i64 = nx_clock_monotonic_ns()
76 let v2_ns: i64 = v2_end - v2_start
77
78 // Print results to stderr for the smoke output.
79 let _h1: i64 = nx_log_v2_emit(ctx, NX_LOG_INFO,
80 "bench.result" as *u8, "v1 vs v2 nanoseconds:" as *u8)
81
82 let buf: *u8 = sys_mmap(128)
83 var off: i64 = 0
84 // "v1=<v1_ns>ns total, "
85 buf[off] = 0x76; buf[off+1] = 0x31; buf[off+2] = 0x3D; off = off + 3
86 off = nx_log_v2_render_int(buf, off, v1_ns)
87 buf[off] = 0x6E; buf[off+1] = 0x73; buf[off+2] = 0x20; off = off + 3
88 buf[off] = 0x76; buf[off+1] = 0x32; buf[off+2] = 0x3D; off = off + 3
89 off = nx_log_v2_render_int(buf, off, v2_ns)
90 buf[off] = 0x6E; buf[off+1] = 0x73; buf[off+2] = 0x20; off = off + 3
91 buf[off] = 0x72; buf[off+1] = 0x61; buf[off+2] = 0x74; buf[off+3] = 0x69; buf[off+4] = 0x6F; buf[off+5] = 0x3D; off = off + 6
92 if v2_ns > 0 {
93 off = nx_log_v2_render_int(buf, off, v1_ns / v2_ns)
94 } else {
95 buf[off] = 0x49; buf[off+1] = 0x4E; buf[off+2] = 0x46; off = off + 3
96 }
97 buf[off] = 0x78; off = off + 1
98 buf[off] = 0
99 let _h2: i64 = nx_log_v2_emit(ctx, NX_LOG_INFO,
100 "bench.numbers" as *u8, buf)
101
102 // VERDICT: v2 must be at least 3x faster.
103 if v2_ns <= 0 { return 0 } // unmeasurable -- pass
104 let ratio_x10: i64 = (v1_ns * 10) / v2_ns
105 if ratio_x10 < 30 {
106 // log the failure clearly
107 let _f: i64 = nx_log_v2_emit(ctx, NX_LOG_ERROR,
108 "bench.result" as *u8, "v2 NOT 3x faster than v1" as *u8)
109 return 3
110 }
111 return 0
112}
113
114// Helper: render integer into buf at off, return new off.
115func nx_log_v2_render_int(buf: *u8, off: i64, v: i64) -> i64 {
116 var n: i64 = v
117 var i: i64 = 0
118 let tmp: *u8 = sys_mmap(32)
119 if n == 0 {
120 buf[off] = 0x30
121 return off + 1
122 }
123 while n > 0 {
124 tmp[i] = 0x30 + (n - (n / 10) * 10)
125 n = n / 10
126 i = i + 1
127 }
128 var k: i64 = 0
129 while k < i {
130 buf[off + k] = tmp[i - 1 - k]
131 k = k + 1
132 }
133 return off + i
134}
135
136func main() -> nx_exit {
137 println("=== nx_log_v2 -- fast-emit smoke + perf bench ===" as *u8)
138
139 let r1: nx_int = t1_emit_correctness()
140 if r1 != 0 { println("T1 emit_correctness FAIL" as *u8); return r1 }
141 println("T1 emit_correctness PASS single-syscall emit produces line" as *u8)
142
143 let r2: nx_int = t2_below_min_fast()
144 if r2 != 0 { println("T2 below_min_fast FAIL" as *u8); return r2 }
145 println("T2 below_min_fast PASS 100/100 INFO emits filtered at ERROR min_level" as *u8)
146
147 let r3: nx_int = t3_perf_emit()
148 if r3 != 0 { println("T3 perf_emit FAIL" as *u8); return r3 }
149 println("T3 perf_emit PASS v2 is at LEAST 3x faster than v1 for INFO emit" as *u8)
150
151 println("" as *u8)
152 println("v2 viable for real-time competition substrate emit" as *u8)
153 println("(CASC / SAT-COMP background tracing -- negligible overhead)." as *u8)
154 return 0
155}