lw2 final TRAIN.log (step3623)

lw2/TRAIN.log

@@ -0,0 +1,376 @@
+[11:58:06 +  3.2m] student streamed: 27.6 GB
+[11:58:06 +  3.2m] LoRA r=8 on 130 attention/GDN projections + routed experts of layers [0, 1, 2]..39 + shared experts trained fully
+[11:58:06 +  3.2m] reply-ending tokens: [248044, 248046] (hash reset on 248044)
+[11:58:11 +  3.3m] table held IN RAM: 20.0 GB (flush = full rewrite to /content/work/lw2/ngram_table.npy)
+[11:58:11 +  3.3m] PLE table: 8 heads x 4,880,000 rows x 256 = 9.99B params, injected before layer 2
+[11:58:12 +  3.3m] resumed expert LoRA
+[11:58:12 +  3.3m] resumed shared experts
+[11:58:12 +  3.3m] resumed linear LoRA on 130 projections
+[11:58:12 +  3.3m] resumed HC/PLE/gates/routers from /content/drive-local/lw2/ckpts/next_step2861.pt
+[11:58:12 +  3.3m] lm_head + embed_tokens on cuda:0 (LMHEAD_DEV)
+[11:58:12 +  3.3m] layer-wise KD: /content/work/probe/lw_train2000.npz | pairs [(35, 59), (39, 63)] | weight 0.2 | 2000 cached sequences of 512 tokens
+[11:58:12 +  3.3m] HC_LAYERS=0-39: HC trains on 40 of 40 layers (grads+Muon momentum are ~8 bytes/param)
+[11:58:12 +  3.3m] LoRA/AdamW: 331.5M adapter params at lr 1.0e-04
+[11:58:12 +  3.3m] AUX anchors: layers [35, 39] weight 0.3 each
+[11:58:12 +  3.3m] trainable: Muon 588.9M | AdamW 0.80M | table 9.99B (sparse SGD)
+[11:58:12 +  3.3m] corpus source: /content/work/train/code_corpus.npy (155,781,328 tokens)
+[11:58:17 +  3.4m] held-out extra: /content/work/train/slice_cs/held_code.npy (66,156 tokens, 16 windows)
+[11:58:17 +  3.4m] held-out extra2: /content/work/train/slice_cs/held_sci.npy (27,167 tokens, 16 windows)
+[11:58:24 +  3.5m] teacher cache: 1,840 complete replies from /content/work/tcache_new (K=128); TCACHE_FRAC=0.9 of chat rows
+[11:58:44 +  3.8m] step 0 (HC identity, PLE no-op == the checkpoint): held-out CE SFT 1.2084 | OOD 2.1164
+[11:59:00 +  4.1m]   PLE gain @ 0: SFT +0.0450 | OOD +0.3113  (CE with memory OFF minus ON on 8+8 held rows; positive = the table helps)
+[11:59:01 +  4.1m] reasoning prompts: +1315 from /content/work/onpolicy_prompts.json
+[11:59:02 +  4.1m] reasoning prompts: 1315 (1315 GSM8K + 0 code), thinking=ON, tail '```<|im_end|>\n<|im_start|>assistant\n<think>\n'; on-policy runs to EOS or 4096 tok in stages [512, 2048, 4096], batch 8, KL chunk 512
+[11:59:03 +  4.2m]   layer-wise row 958: 1022 positions, mean KL 0.1866 = S35<-T59 0.320 | S39<-T63 0.053
+/content/work/kit/code/wt/train_next36.py:1000: UserWarning: Converting a tensor with requires_grad=True to a scalar may lead to unexpected behavior.
+Consider using tensor.detach() first. (Triggered internally at /pytorch/torch/csrc/autograd/generated/python_variable_methods.cpp:836.)
+  USE_TRACE.append((float(ratio), float(use) / max(n, 1)))
+[11:59:03 +  4.2m]   use row (step 1): PLE/residual norm ratio 0.2782 (want >= 0.1) | term 0.0000
+[11:59:04 +  4.2m] step1: grad-norm 6.203e+00 | HC probe max|delta| 9.141e-05 | table rows touched 1572
+[11:59:04 +  4.2m] peak GPU 40.7 GB
+[11:59:04 +  4.2m] PoSE: target window 131,072 | 1 rows offset so far | highest position index seen 115,972
+[11:59:05 +  4.2m]   layer-wise row 779: 1022 positions, mean KL 0.4060 = S35<-T59 0.772 | S39<-T63 0.039
+[11:59:05 +  4.2m]   use row (step 2): PLE/residual norm ratio 0.2820 (want >= 0.1) | term 0.0000
+[11:59:10 +  4.3m]   layer-wise row 1374: 1022 positions, mean KL 0.3766 = S35<-T59 0.661 | S39<-T63 0.092
+[11:59:10 +  4.3m]   use row (step 4): PLE/residual norm ratio 0.2505 (want >= 0.1) | term 0.0000
+[11:59:11 +  4.3m]   layer-wise row 919: 1022 positions, mean KL 0.3159 = S35<-T59 0.573 | S39<-T63 0.059
+[11:59:11 +  4.3m]   use row (step 5): PLE/residual norm ratio 0.2666 (want >= 0.1) | term 0.0000
+[11:59:13 +  4.3m]   layer-wise row 1275: 1022 positions, mean KL 0.3995 = S35<-T59 0.672 | S39<-T63 0.127
+[11:59:13 +  4.3m]   use row (step 6): PLE/residual norm ratio 0.2703 (want >= 0.1) | term 0.0000
+[11:59:48 +  4.9m] step 20 loss 0.4835 (kd 0.2091 ce 0.2744) | 2.40s/step | table rows seen 54,088
+[12:01:00 +  6.1m] step 40 loss 0.6170 (kd 0.1211 ce 0.4960) | 3.00s/step | table rows seen 146,748
+[12:02:08 +  7.2m] step 60 loss 0.8049 (kd 0.1771 ce 0.6278) | 3.14s/step | table rows seen 227,760
+[12:03:15 +  8.4m] step 80 loss 0.6568 (kd 0.1385 ce 0.5183) | 3.19s/step | table rows seen 292,464
+[12:04:23 +  9.5m]   use row (step 100): PLE/residual norm ratio 0.2945 (want >= 0.1) | term 0.0000
+[12:04:24 +  9.5m] step 100 loss 0.6605 (kd 0.1409 ce 0.5196) | 3.24s/step | table rows seen 369,952
+[12:05:43 + 10.8m] step 120 loss 0.7789 (kd 0.0963 ce 0.6826) | 3.36s/step | table rows seen 457,680
+[12:06:48 + 11.9m] step 140 loss 0.6131 (kd 0.1684 ce 0.4447) | 3.35s/step | table rows seen 528,172
+[12:08:11 + 13.3m] step 160 loss 0.7577 (kd 0.1424 ce 0.6153) | 3.44s/step | table rows seen 601,152
+[12:09:17 + 14.4m] step 180 loss 0.7005 (kd 0.1830 ce 0.5175) | 3.43s/step | table rows seen 659,992
+[12:10:17 + 15.4m]   use row (step 200): PLE/residual norm ratio 0.2181 (want >= 0.1) | term 0.0000
+[12:10:20 + 15.4m] step 200 loss 0.7745 (kd 0.1283 ce 0.6462) | 3.40s/step | table rows seen 738,376
+[12:10:39 + 15.8m]   held-out CE @ 200: SFT 1.2111 (start 1.2084) | OOD 2.1194 (start 2.1164)
+[12:10:39 + 15.8m]   PoSE @ 200: 239 rows offset | highest position index 130,782 of 131,072
+[12:11:24 + 16.5m]   PLE gain @ 200: SFT +0.2190 | OOD +0.6842 | IN-corpus +3.9771 | extra +4.1870 (CE 1.2505) | extra2 +0.3342 (CE 0.7141) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[12:11:24 + 16.5m]   injection @ 200: 156 rows | PLE/residual ratio mean 0.2724 min 0.1803 max 0.4352 | mean use term 0.0000
+[12:11:24 + 16.5m]   dependence @ 200: 39 rows since last eval | mean gap CE_off-CE_on +1.8938 | frac meeting margin 0.95 | mean term 0.0055
+[12:11:25 + 16.5m]   HC stats @ 200: gate|dev| median 0.0263 (L0 0.0252, L39 0.0251) | inject w|dev| median 0.3646 | stream spread median 0.4590 (L39 0.4661)
+[12:12:29 + 17.6m] step 220 loss 0.6456 (kd 0.1465 ce 0.4991) | 3.68s/step | table rows seen 804,236
+[12:14:01 + 19.1m] step 240 loss 0.8784 (kd 0.1212 ce 0.7572) | 3.76s/step | table rows seen 902,536
+[12:15:14 + 20.3m] step 260 loss 0.6870 (kd 0.1798 ce 0.5071) | 3.75s/step | table rows seen 976,528
+[12:16:18 + 21.4m] step 280 loss 0.6891 (kd 0.1204 ce 0.5687) | 3.71s/step | table rows seen 1,031,852
+[12:17:17 + 22.4m]   use row (step 300): PLE/residual norm ratio 0.2458 (want >= 0.1) | term 0.0000
+[12:17:24 + 22.5m]   dep row (step 300): CE_on 1.3596 | CE_off 3.6692 | gap +2.3096 (want >= 0.3) | term 0.0000
+[12:17:24 + 22.5m] step 300 loss 0.7158 (kd 0.1423 ce 0.5734) | 3.68s/step | table rows seen 1,094,076
+[12:18:33 + 23.7m] step 320 loss 0.8529 (kd 0.2303 ce 0.6225) | 3.67s/step | table rows seen 1,167,256
+[12:19:44 + 24.8m] step 340 loss 0.6427 (kd 0.1602 ce 0.4826) | 3.66s/step | table rows seen 1,220,848
+[12:20:46 + 25.9m] step 360 loss 0.6299 (kd 0.1681 ce 0.4618) | 3.63s/step | table rows seen 1,275,748
+[12:21:35 + 26.7m] step 380 loss 0.5931 (kd 0.1864 ce 0.4067) | 3.57s/step | table rows seen 1,322,088
+[12:22:44 + 27.9m]   layer-wise row 904: 1022 positions, mean KL 0.2705 = S35<-T59 0.473 | S39<-T63 0.068
+[12:22:44 + 27.9m]   use row (step 400): PLE/residual norm ratio 0.2582 (want >= 0.1) | term 0.0000
+[12:22:45 + 27.9m] step 400 loss 0.7112 (kd 0.1289 ce 0.5824) | 3.56s/step | table rows seen 1,379,872
+[12:23:04 + 28.2m]   held-out CE @ 400: SFT 1.2131 (start 1.2084) | OOD 2.1215 (start 2.1164)
+[12:23:04 + 28.2m]   PoSE @ 400: 474 rows offset | highest position index 130,782 of 131,072
+[12:23:50 + 28.9m]   PLE gain @ 400: SFT +0.0818 | OOD +0.4402 | IN-corpus +2.3971 | extra +2.4632 (CE 1.2589) | extra2 +0.0975 (CE 0.7057) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[12:23:50 + 28.9m]   injection @ 400: 141 rows | PLE/residual ratio mean 0.2703 min 0.1623 max 0.4922 | mean use term 0.0000
+[12:23:50 + 28.9m]   dependence @ 400: 35 rows since last eval | mean gap CE_off-CE_on +1.9798 | frac meeting margin 0.97 | mean term 0.0021
+[12:23:50 + 29.0m]   HC stats @ 400: gate|dev| median 0.0264 (L0 0.0251, L39 0.0249) | inject w|dev| median 0.3679 | stream spread median 0.4602 (L39 0.4593)
+[12:24:44 + 29.9m] step 420 loss 0.5546 (kd 0.1633 ce 0.3913) | 3.68s/step | table rows seen 1,415,900
+[12:25:39 + 30.8m] step 440 loss 0.5340 (kd 0.1705 ce 0.3635) | 3.63s/step | table rows seen 1,466,500
+[12:26:48 + 31.9m] step 460 loss 0.7269 (kd 0.1510 ce 0.5759) | 3.63s/step | table rows seen 1,529,188
+[12:27:59 + 33.1m] step 480 loss 0.6897 (kd 0.1146 ce 0.5752) | 3.62s/step | table rows seen 1,587,504
+[12:29:08 + 34.2m]   use row (step 500): PLE/residual norm ratio 0.2390 (want >= 0.1) | term 0.0000
+[12:29:09 + 34.3m] step 500 loss 0.7209 (kd 0.1638 ce 0.5571) | 3.62s/step | table rows seen 1,653,648
+[12:30:05 + 35.2m] step 520 loss 0.6874 (kd 0.1812 ce 0.5062) | 3.59s/step | table rows seen 1,695,832
+[12:31:15 + 36.4m] step 540 loss 0.9233 (kd 0.1174 ce 0.8059) | 3.58s/step | table rows seen 1,764,108
+[12:32:15 + 37.4m] step 560 loss 0.6976 (kd 0.1474 ce 0.5503) | 3.56s/step | table rows seen 1,816,984
+[12:33:29 + 38.6m] step 580 loss 0.6643 (kd 0.1606 ce 0.5037) | 3.57s/step | table rows seen 1,875,028
+[12:34:26 + 39.5m]   use row (step 600): PLE/residual norm ratio 0.2892 (want >= 0.1) | term 0.0000
+[12:34:29 + 39.6m] step 600 loss 0.6143 (kd 0.1315 ce 0.4828) | 3.55s/step | table rows seen 1,929,932
+[12:34:48 + 39.9m]   held-out CE @ 600: SFT 1.2110 (start 1.2084) | OOD 2.1229 (start 2.1164)
+[12:34:48 + 39.9m]   PoSE @ 600: 707 rows offset | highest position index 130,782 of 131,072
+[12:35:33 + 40.7m]   PLE gain @ 600: SFT +0.1335 | OOD +0.6804 | IN-corpus +4.1827 | extra +4.2075 (CE 1.2550) | extra2 +0.3936 (CE 0.7509) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[12:35:33 + 40.7m]   injection @ 600: 152 rows | PLE/residual ratio mean 0.2750 min 0.1965 max 0.4519 | mean use term 0.0000
+[12:35:33 + 40.7m]   dependence @ 600: 33 rows since last eval | mean gap CE_off-CE_on +1.5146 | frac meeting margin 0.94 | mean term 0.0078
+[12:35:34 + 40.7m]   HC stats @ 600: gate|dev| median 0.0264 (L0 0.0252, L39 0.0249) | inject w|dev| median 0.3750 | stream spread median 0.4640 (L39 0.4644)
+[12:37:06 + 42.2m] step 620 loss 0.6640 (kd 0.0962 ce 0.5678) | 3.69s/step | table rows seen 1,996,780
+[12:38:03 + 43.2m] step 640 loss 0.5029 (kd 0.1591 ce 0.3438) | 3.66s/step | table rows seen 2,033,268
+[12:39:02 + 44.1m] step 660 loss 0.6393 (kd 0.1484 ce 0.4909) | 3.64s/step | table rows seen 2,085,764
+[12:40:14 + 45.3m] step 680 loss 0.5165 (kd 0.1458 ce 0.3708) | 3.64s/step | table rows seen 2,140,308
+[12:41:19 + 46.4m]   use row (step 700): PLE/residual norm ratio 0.3189 (want >= 0.1) | term 0.0000
+[12:41:20 + 46.4m] step 700 loss 0.4977 (kd 0.1449 ce 0.3528) | 3.63s/step | table rows seen 2,183,404
+[12:42:28 + 47.6m] step 720 loss 0.5911 (kd 0.1518 ce 0.4392) | 3.62s/step | table rows seen 2,230,652
+[12:43:40 + 48.8m] step 740 loss 0.6026 (kd 0.1320 ce 0.4706) | 3.62s/step | table rows seen 2,277,588
+[12:44:46 + 49.9m] step 760 loss 0.6192 (kd 0.1436 ce 0.4755) | 3.61s/step | table rows seen 2,335,140
+[12:45:54 + 51.0m] step 780 loss 0.5812 (kd 0.1643 ce 0.4169) | 3.61s/step | table rows seen 2,379,240
+[12:46:57 + 52.1m] step 800 loss 0.5239 (kd 0.1298 ce 0.3940) | 3.60s/step | table rows seen 2,419,488
+[12:47:16 + 52.4m]   held-out CE @ 800: SFT 1.2153 (start 1.2084) | OOD 2.1275 (start 2.1164)
+[12:47:16 + 52.4m]   PoSE @ 800: 953 rows offset | highest position index 130,782 of 131,072
+[12:48:01 + 53.1m]   PLE gain @ 800: SFT +0.2545 | OOD +0.8751 | IN-corpus +4.8042 | extra +4.6004 (CE 1.2581) | extra2 +0.7702 (CE 0.7819) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[12:48:01 + 53.1m]   injection @ 800: 143 rows | PLE/residual ratio mean 0.2815 min 0.1973 max 0.4649 | mean use term 0.0000
+[12:48:01 + 53.1m]   dependence @ 800: 46 rows since last eval | mean gap CE_off-CE_on +2.6822 | frac meeting margin 0.96 | mean term 0.0019
+[12:48:02 + 53.1m]   HC stats @ 800: gate|dev| median 0.0265 (L0 0.0251, L39 0.0250) | inject w|dev| median 0.3881 | stream spread median 0.4631 (L39 0.4612)
+[12:49:16 + 54.4m] step 820 loss 0.6368 (kd 0.1161 ce 0.5207) | 3.68s/step | table rows seen 2,468,084
+[12:50:15 + 55.4m] step 840 loss 0.5305 (kd 0.1520 ce 0.3784) | 3.66s/step | table rows seen 2,501,380
+[12:51:19 + 56.4m] step 860 loss 0.5942 (kd 0.1967 ce 0.3975) | 3.65s/step | table rows seen 2,536,504
+[12:52:39 + 57.8m] step 880 loss 0.7638 (kd 0.1206 ce 0.6432) | 3.66s/step | table rows seen 2,591,628
+[12:53:51 + 59.0m]   use row (step 900): PLE/residual norm ratio 0.2513 (want >= 0.1) | term 0.0000
+[12:53:53 + 59.0m]   dep row (step 900): CE_on 0.2147 | CE_off 2.0563 | gap +1.8415 (want >= 0.3) | term 0.0000
+[12:53:53 + 59.0m] step 900 loss 0.4741 (kd 0.1588 ce 0.3153) | 3.66s/step | table rows seen 2,623,252
+[12:55:08 + 60.2m] step 920 loss 0.7230 (kd 0.1449 ce 0.5781) | 3.66s/step | table rows seen 2,679,876
+[12:56:13 + 61.3m] step 940 loss 0.6052 (kd 0.1512 ce 0.4539) | 3.65s/step | table rows seen 2,729,796
+[12:57:16 + 62.4m] step 960 loss 0.5518 (kd 0.1680 ce 0.3838) | 3.64s/step | table rows seen 2,768,912
+[12:58:24 + 63.5m] step 980 loss 0.5696 (kd 0.1275 ce 0.4421) | 3.64s/step | table rows seen 2,811,604
+[12:59:28 + 64.6m]   layer-wise row 78: 1022 positions, mean KL 0.4050 = S35<-T59 0.759 | S39<-T63 0.051
+[12:59:28 + 64.6m]   use row (step 1000): PLE/residual norm ratio 0.2257 (want >= 0.1) | term 0.0000
+[12:59:29 + 64.6m] step 1000 loss 0.7537 (kd 0.1115 ce 0.6422) | 3.63s/step | table rows seen 2,863,252
+[12:59:48 + 64.9m]   held-out CE @ 1000: SFT 1.2105 (start 1.2084) | OOD 2.1260 (start 2.1164)
+[12:59:48 + 64.9m]   PoSE @ 1000: 1,196 rows offset | highest position index 130,782 of 131,072
+[13:00:33 + 65.7m]   PLE gain @ 1000: SFT +0.7220 | OOD +1.3533 | IN-corpus +4.6761 | extra +4.7799 (CE 1.2653) | extra2 +1.0335 (CE 0.7434) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[13:00:33 + 65.7m]   injection @ 1000: 151 rows | PLE/residual ratio mean 0.2786 min 0.1788 max 0.4424 | mean use term 0.0000
+[13:00:33 + 65.7m]   dependence @ 1000: 43 rows since last eval | mean gap CE_off-CE_on +3.1291 | frac meeting margin 0.95 | mean term 0.0010
+[13:00:34 + 65.7m]   HC stats @ 1000: gate|dev| median 0.0265 (L0 0.0251, L39 0.0249) | inject w|dev| median 0.3915 | stream spread median 0.4620 (L39 0.4617)
+[13:01:33 + 66.7m] step 1020 loss 0.5406 (kd 0.1682 ce 0.3724) | 3.68s/step | table rows seen 2,899,772
+[13:02:36 + 67.7m] step 1040 loss 0.6462 (kd 0.1073 ce 0.5389) | 3.67s/step | table rows seen 2,944,520
+[13:03:37 + 68.7m] step 1060 loss 0.7262 (kd 0.1506 ce 0.5756) | 3.66s/step | table rows seen 3,001,876
+[13:04:43 + 69.8m] step 1080 loss 0.7609 (kd 0.1151 ce 0.6458) | 3.65s/step | table rows seen 3,054,456
+[13:05:57 + 71.1m]   use row (step 1100): PLE/residual norm ratio 0.2823 (want >= 0.1) | term 0.0000
+[13:05:58 + 71.1m] step 1100 loss 0.6607 (kd 0.1484 ce 0.5124) | 3.65s/step | table rows seen 3,101,060
+[13:07:01 + 72.1m] step 1120 loss 0.5710 (kd 0.1503 ce 0.4207) | 3.64s/step | table rows seen 3,129,100
+[13:08:06 + 73.2m] step 1140 loss 0.6398 (kd 0.1454 ce 0.4943) | 3.64s/step | table rows seen 3,173,228
+[13:09:14 + 74.3m] step 1160 loss 0.6576 (kd 0.1252 ce 0.5324) | 3.63s/step | table rows seen 3,216,304
+[13:10:32 + 75.7m] step 1180 loss 0.6027 (kd 0.1364 ce 0.4663) | 3.64s/step | table rows seen 3,271,312
+[13:11:33 + 76.7m]   use row (step 1200): PLE/residual norm ratio 0.2925 (want >= 0.1) | term 0.0000
+[13:11:41 + 76.8m]   dep row (step 1200): CE_on 0.9109 | CE_off 4.9935 | gap +4.0826 (want >= 0.3) | term 0.0000
+[13:11:41 + 76.8m] step 1200 loss 0.4758 (kd 0.1322 ce 0.3436) | 3.63s/step | table rows seen 3,302,924
+[13:12:00 + 77.1m]   held-out CE @ 1200: SFT 1.2096 (start 1.2084) | OOD 2.1154 (start 2.1164)
+[13:12:00 + 77.1m]   PoSE @ 1200: 1,433 rows offset | highest position index 131,055 of 131,072
+[13:12:45 + 77.9m]   PLE gain @ 1200: SFT +0.1666 | OOD +0.6787 | IN-corpus +2.9487 | extra +2.8736 (CE 1.2605) | extra2 +0.5398 (CE 0.7638) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[13:12:45 + 77.9m]   injection @ 1200: 153 rows | PLE/residual ratio mean 0.2795 min 0.1756 max 0.3945 | mean use term 0.0000
+[13:12:45 + 77.9m]   dependence @ 1200: 37 rows since last eval | mean gap CE_off-CE_on +1.7105 | frac meeting margin 1.00 | mean term 0.0000
+[13:12:46 + 77.9m]   HC stats @ 1200: gate|dev| median 0.0265 (L0 0.0251, L39 0.0249) | inject w|dev| median 0.3930 | stream spread median 0.4648 (L39 0.4659)
+[13:12:53 + 78.0m]   new best by OOD CE: step 1200
+[13:14:01 + 79.1m] step 1220 loss 0.4915 (kd 0.1194 ce 0.3721) | 3.69s/step | table rows seen 3,346,972
+[13:15:18 + 80.4m] step 1240 loss 0.4860 (kd 0.1408 ce 0.3453) | 3.69s/step | table rows seen 3,378,160
+[13:16:39 + 81.8m] step 1260 loss 0.7210 (kd 0.1081 ce 0.6129) | 3.70s/step | table rows seen 3,442,364
+[13:17:48 + 82.9m] step 1280 loss 0.6131 (kd 0.1202 ce 0.4930) | 3.69s/step | table rows seen 3,493,620
+[13:18:43 + 83.8m]   use row (step 1300): PLE/residual norm ratio 0.3155 (want >= 0.1) | term 0.0000
+[13:18:45 + 83.9m]   dep row (step 1300): CE_on 0.1740 | CE_off 0.7367 | gap +0.5628 (want >= 0.3) | term 0.0000
+[13:18:46 + 83.9m] step 1300 loss 0.5904 (kd 0.1631 ce 0.4273) | 3.68s/step | table rows seen 3,528,600
+[13:19:50 + 84.9m] step 1320 loss 0.5803 (kd 0.1158 ce 0.4644) | 3.67s/step | table rows seen 3,579,640
+[13:20:59 + 86.1m] step 1340 loss 0.6454 (kd 0.1566 ce 0.4888) | 3.67s/step | table rows seen 3,623,000
+[13:22:05 + 87.2m] step 1360 loss 0.6492 (kd 0.1446 ce 0.5046) | 3.67s/step | table rows seen 3,660,168
+[13:23:04 + 88.2m] step 1380 loss 0.5788 (kd 0.1262 ce 0.4526) | 3.66s/step | table rows seen 3,690,140
+[13:24:07 + 89.2m] step 1400 loss 0.6046 (kd 0.1727 ce 0.4319) | 3.65s/step | table rows seen 3,733,392
+[13:24:26 + 89.5m]   held-out CE @ 1400: SFT 1.2129 (start 1.2084) | OOD 2.1213 (start 2.1164)
+[13:24:26 + 89.5m]   PoSE @ 1400: 1,669 rows offset | highest position index 131,055 of 131,072
+[13:25:11 + 90.3m]   PLE gain @ 1400: SFT +0.1522 | OOD +0.5939 | IN-corpus +1.5132 | extra +1.5602 (CE 1.2624) | extra2 +0.3047 (CE 0.7406) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[13:25:11 + 90.3m]   injection @ 1400: 145 rows | PLE/residual ratio mean 0.2808 min 0.1852 max 0.5089 | mean use term 0.0000
+[13:25:11 + 90.3m]   dependence @ 1400: 36 rows since last eval | mean gap CE_off-CE_on +1.4389 | frac meeting margin 0.97 | mean term 0.0008
+[13:25:12 + 90.3m]   HC stats @ 1400: gate|dev| median 0.0266 (L0 0.0251, L39 0.0250) | inject w|dev| median 0.3829 | stream spread median 0.4652 (L39 0.4679)
+[13:26:31 + 91.6m] step 1420 loss 0.4763 (kd 0.1225 ce 0.3538) | 3.70s/step | table rows seen 3,762,452
+[13:27:33 + 92.7m] step 1440 loss 0.6411 (kd 0.1322 ce 0.5089) | 3.69s/step | table rows seen 3,809,008
+[13:28:53 + 94.0m] step 1460 loss 0.5695 (kd 0.1140 ce 0.4555) | 3.69s/step | table rows seen 3,856,720
+[13:29:49 + 94.9m] step 1480 loss 0.5242 (kd 0.1513 ce 0.3729) | 3.68s/step | table rows seen 3,888,088
+[13:30:56 + 96.0m]   use row (step 1500): PLE/residual norm ratio 0.2708 (want >= 0.1) | term 0.0000
+[13:30:59 + 96.1m] step 1500 loss 0.4343 (kd 0.1058 ce 0.3285) | 3.68s/step | table rows seen 3,914,240
+[13:32:06 + 97.2m] step 1520 loss 0.5251 (kd 0.1322 ce 0.3929) | 3.68s/step | table rows seen 3,958,448
+[13:33:01 + 98.1m] step 1540 loss 0.5309 (kd 0.1347 ce 0.3962) | 3.66s/step | table rows seen 3,987,604
+[13:34:03 + 99.2m] step 1560 loss 0.6296 (kd 0.1385 ce 0.4911) | 3.66s/step | table rows seen 4,028,360
+[13:35:04 +100.2m] step 1580 loss 0.5138 (kd 0.1536 ce 0.3602) | 3.65s/step | table rows seen 4,068,240
+[13:36:10 +101.3m]   layer-wise row 1440: 1022 positions, mean KL 0.2326 = S35<-T59 0.415 | S39<-T63 0.050
+[13:36:10 +101.3m]   use row (step 1600): PLE/residual norm ratio 0.2553 (want >= 0.1) | term 0.0000
+[13:36:11 +101.3m] step 1600 loss 0.5179 (kd 0.1341 ce 0.3838) | 3.64s/step | table rows seen 4,090,528
+[13:36:30 +101.6m]   held-out CE @ 1600: SFT 1.2166 (start 1.2084) | OOD 2.1325 (start 2.1164)
+[13:36:30 +101.6m]   PoSE @ 1600: 1,903 rows offset | highest position index 131,055 of 131,072
+[13:37:15 +102.4m]   PLE gain @ 1600: SFT +0.6997 | OOD +1.2362 | IN-corpus +4.6189 | extra +4.5615 (CE 1.2659) | extra2 +0.8671 (CE 0.7430) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[13:37:15 +102.4m]   injection @ 1600: 154 rows | PLE/residual ratio mean 0.2771 min 0.1852 max 0.4076 | mean use term 0.0000
+[13:37:15 +102.4m]   dependence @ 1600: 34 rows since last eval | mean gap CE_off-CE_on +1.5604 | frac meeting margin 0.97 | mean term 0.0021
+[13:37:16 +102.4m]   HC stats @ 1600: gate|dev| median 0.0265 (L0 0.0252, L39 0.0248) | inject w|dev| median 0.3857 | stream spread median 0.4652 (L39 0.4632)
+[13:38:25 +103.5m] step 1620 loss 0.6703 (kd 0.1382 ce 0.5320) | 3.68s/step | table rows seen 4,134,904
+[13:39:38 +104.7m] step 1640 loss 0.5061 (kd 0.1346 ce 0.3716) | 3.68s/step | table rows seen 4,166,792
+[13:40:52 +106.0m] step 1660 loss 0.6360 (kd 0.1569 ce 0.4791) | 3.68s/step | table rows seen 4,201,972
+[13:41:57 +107.1m] step 1680 loss 0.5109 (kd 0.1621 ce 0.3488) | 3.68s/step | table rows seen 4,221,756
+[13:43:08 +108.3m]   use row (step 1700): PLE/residual norm ratio 0.3380 (want >= 0.1) | term 0.0000
+[13:43:11 +108.3m]   dep row (step 1700): CE_on 0.0798 | CE_off 0.9675 | gap +0.8877 (want >= 0.3) | term 0.0000
+[13:43:11 +108.3m] step 1700 loss 0.6211 (kd 0.1505 ce 0.4706) | 3.68s/step | table rows seen 4,260,384
+[13:44:23 +109.5m] step 1720 loss 0.6897 (kd 0.1336 ce 0.5560) | 3.68s/step | table rows seen 4,305,436
+[13:45:32 +110.6m] step 1740 loss 0.5994 (kd 0.1478 ce 0.4516) | 3.67s/step | table rows seen 4,353,800
+[13:46:50 +111.9m] step 1760 loss 0.6623 (kd 0.0915 ce 0.5708) | 3.68s/step | table rows seen 4,396,932
+[13:48:01 +113.1m] step 1780 loss 0.5591 (kd 0.1466 ce 0.4125) | 3.67s/step | table rows seen 4,427,876
+[13:48:59 +114.1m]   layer-wise row 935: 1022 positions, mean KL 0.3422 = S35<-T59 0.625 | S39<-T63 0.059
+[13:48:59 +114.1m]   use row (step 1800): PLE/residual norm ratio 0.2524 (want >= 0.1) | term 0.0000
+[13:49:00 +114.1m] step 1800 loss 0.4771 (kd 0.1463 ce 0.3307) | 3.67s/step | table rows seen 4,448,780
+[13:49:19 +114.4m]   held-out CE @ 1800: SFT 1.2163 (start 1.2084) | OOD 2.1310 (start 2.1164)
+[13:49:19 +114.4m]   PoSE @ 1800: 2,158 rows offset | highest position index 131,055 of 131,072
+[13:50:05 +115.2m]   PLE gain @ 1800: SFT +0.2938 | OOD +0.8546 | IN-corpus +3.5229 | extra +3.5115 (CE 1.2604) | extra2 +0.5949 (CE 0.7170) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[13:50:05 +115.2m]   injection @ 1800: 161 rows | PLE/residual ratio mean 0.2801 min 0.1940 max 0.5099 | mean use term 0.0000
+[13:50:05 +115.2m]   dependence @ 1800: 55 rows since last eval | mean gap CE_off-CE_on +1.8280 | frac meeting margin 1.00 | mean term 0.0000
+[13:50:05 +115.2m]   HC stats @ 1800: gate|dev| median 0.0266 (L0 0.0251, L39 0.0250) | inject w|dev| median 0.3901 | stream spread median 0.4701 (L39 0.4650)
+[13:51:24 +116.5m] step 1820 loss 0.5936 (kd 0.1500 ce 0.4436) | 3.71s/step | table rows seen 4,482,288
+[13:52:18 +117.4m] step 1840 loss 0.5885 (kd 0.1621 ce 0.4264) | 3.69s/step | table rows seen 4,516,400
+[13:53:20 +118.4m] step 1860 loss 0.4615 (kd 0.1521 ce 0.3094) | 3.69s/step | table rows seen 4,540,836
+[13:54:26 +119.6m] step 1880 loss 0.6770 (kd 0.1221 ce 0.5549) | 3.68s/step | table rows seen 4,588,972
+[13:55:33 +120.7m] step 1900 loss 0.4954 (kd 0.1515 ce 0.3439) | 3.68s/step | table rows seen 4,616,460
+[13:56:48 +121.9m] step 1920 loss 0.5763 (kd 0.1389 ce 0.4375) | 3.68s/step | table rows seen 4,657,572
+[13:58:04 +123.2m] step 1940 loss 0.7615 (kd 0.1239 ce 0.6376) | 3.68s/step | table rows seen 4,710,080
+[13:59:07 +124.2m] step 1960 loss 0.5923 (kd 0.1751 ce 0.4172) | 3.68s/step | table rows seen 4,747,724
+[14:00:19 +125.4m] step 1980 loss 0.5809 (kd 0.1404 ce 0.4406) | 3.68s/step | table rows seen 4,794,684
+[14:01:18 +126.4m] step 2000 loss 0.5006 (kd 0.1689 ce 0.3318) | 3.67s/step | table rows seen 4,823,380
+[14:01:37 +126.7m]   held-out CE @ 2000: SFT 1.2164 (start 1.2084) | OOD 2.1310 (start 2.1164)
+[14:01:37 +126.7m]   PoSE @ 2000: 2,394 rows offset | highest position index 131,055 of 131,072
+[14:02:22 +127.5m]   PLE gain @ 2000: SFT +0.4375 | OOD +1.0848 | IN-corpus +4.8377 | extra +4.5854 (CE 1.2580) | extra2 +0.7430 (CE 0.7646) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[14:02:22 +127.5m]   injection @ 2000: 125 rows | PLE/residual ratio mean 0.2812 min 0.1920 max 0.4736 | mean use term 0.0000
+[14:02:22 +127.5m]   dependence @ 2000: 36 rows since last eval | mean gap CE_off-CE_on +1.9497 | frac meeting margin 0.97 | mean term 0.0035
+[14:02:23 +127.5m]   HC stats @ 2000: gate|dev| median 0.0267 (L0 0.0252, L39 0.0249) | inject w|dev| median 0.3921 | stream spread median 0.4732 (L39 0.4670)
+[14:03:38 +128.7m] step 2020 loss 0.7305 (kd 0.1254 ce 0.6051) | 3.70s/step | table rows seen 4,867,516
+[14:04:44 +129.9m] step 2040 loss 0.6071 (kd 0.1582 ce 0.4489) | 3.70s/step | table rows seen 4,905,536
+[14:06:12 +131.3m] step 2060 loss 0.7088 (kd 0.1378 ce 0.5710) | 3.71s/step | table rows seen 4,950,328
+[14:07:24 +132.5m] step 2080 loss 0.6559 (kd 0.1099 ce 0.5460) | 3.70s/step | table rows seen 4,994,132
+[14:08:20 +133.4m]   use row (step 2100): PLE/residual norm ratio 0.2481 (want >= 0.1) | term 0.0000
+[14:08:21 +133.5m] step 2100 loss 0.5670 (kd 0.1862 ce 0.3807) | 3.70s/step | table rows seen 5,023,032
+[14:09:27 +134.6m] step 2120 loss 0.4724 (kd 0.1455 ce 0.3269) | 3.69s/step | table rows seen 5,044,980
+[14:10:42 +135.8m] step 2140 loss 0.6891 (kd 0.1501 ce 0.5390) | 3.69s/step | table rows seen 5,088,148
+[14:11:41 +136.8m] step 2160 loss 0.4932 (kd 0.1402 ce 0.3529) | 3.69s/step | table rows seen 5,116,664
+[14:12:48 +137.9m] step 2180 loss 0.4113 (kd 0.1056 ce 0.3057) | 3.68s/step | table rows seen 5,144,328
+[14:13:53 +139.0m]   use row (step 2200): PLE/residual norm ratio 0.2624 (want >= 0.1) | term 0.0000
+[14:13:56 +139.0m] step 2200 loss 0.5956 (kd 0.1454 ce 0.4501) | 3.68s/step | table rows seen 5,179,348
+[14:14:15 +139.4m]   held-out CE @ 2200: SFT 1.2212 (start 1.2084) | OOD 2.1309 (start 2.1164)
+[14:14:15 +139.4m]   PoSE @ 2200: 2,638 rows offset | highest position index 131,055 of 131,072
+[14:15:00 +140.1m]   PLE gain @ 2200: SFT +0.4751 | OOD +1.1387 | IN-corpus +4.8532 | extra +4.7935 (CE 1.2612) | extra2 +0.8119 (CE 0.7544) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[14:15:00 +140.1m]   injection @ 2200: 143 rows | PLE/residual ratio mean 0.2751 min 0.1776 max 0.3606 | mean use term 0.0000
+[14:15:00 +140.1m]   dependence @ 2200: 44 rows since last eval | mean gap CE_off-CE_on +2.1755 | frac meeting margin 0.98 | mean term 0.0057
+[14:15:01 +140.1m]   HC stats @ 2200: gate|dev| median 0.0266 (L0 0.0252, L39 0.0250) | inject w|dev| median 0.3873 | stream spread median 0.4724 (L39 0.4677)
+[14:16:16 +141.4m] step 2220 loss 0.6137 (kd 0.1055 ce 0.5082) | 3.71s/step | table rows seen 5,216,592
+[14:17:20 +142.5m] step 2240 loss 0.6124 (kd 0.1167 ce 0.4956) | 3.71s/step | table rows seen 5,252,900
+[14:18:12 +143.3m] step 2260 loss 0.5177 (kd 0.1644 ce 0.3533) | 3.70s/step | table rows seen 5,268,008
+[14:19:20 +144.5m] step 2280 loss 0.5869 (kd 0.1196 ce 0.4673) | 3.69s/step | table rows seen 5,302,256
+[14:20:29 +145.6m]   use row (step 2300): PLE/residual norm ratio 0.3308 (want >= 0.1) | term 0.0000
+[14:20:30 +145.6m] step 2300 loss 0.5915 (kd 0.1250 ce 0.4665) | 3.69s/step | table rows seen 5,331,344
+[14:21:40 +146.8m] step 2320 loss 0.5627 (kd 0.1268 ce 0.4358) | 3.69s/step | table rows seen 5,364,068
+[14:22:49 +147.9m] step 2340 loss 0.5840 (kd 0.1795 ce 0.4045) | 3.69s/step | table rows seen 5,398,752
+[14:23:51 +149.0m] step 2360 loss 0.5540 (kd 0.1182 ce 0.4358) | 3.68s/step | table rows seen 5,433,820
+[14:25:03 +150.2m] step 2380 loss 0.6142 (kd 0.1069 ce 0.5073) | 3.68s/step | table rows seen 5,467,692
+[14:26:06 +151.2m] step 2400 loss 0.7247 (kd 0.1291 ce 0.5956) | 3.68s/step | table rows seen 5,511,340
+[14:26:25 +151.5m]   held-out CE @ 2400: SFT 1.2189 (start 1.2084) | OOD 2.1276 (start 2.1164)
+[14:26:25 +151.5m]   PoSE @ 2400: 2,870 rows offset | highest position index 131,055 of 131,072
+[14:27:10 +152.3m]   PLE gain @ 2400: SFT +0.0233 | OOD +0.4671 | IN-corpus +2.5091 | extra +2.1825 (CE 1.2619) | extra2 +0.2611 (CE 0.7357) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[14:27:10 +152.3m]   injection @ 2400: 152 rows | PLE/residual ratio mean 0.2768 min 0.1607 max 0.3646 | mean use term 0.0000
+[14:27:10 +152.3m]   dependence @ 2400: 32 rows since last eval | mean gap CE_off-CE_on +1.6296 | frac meeting margin 1.00 | mean term 0.0000
+[14:27:11 +152.3m]   HC stats @ 2400: gate|dev| median 0.0266 (L0 0.0252, L39 0.0251) | inject w|dev| median 0.3856 | stream spread median 0.4732 (L39 0.4696)
+[14:28:19 +153.4m] step 2420 loss 0.5547 (kd 0.0791 ce 0.4756) | 3.70s/step | table rows seen 5,541,528
+[14:29:20 +154.5m] step 2440 loss 0.5100 (kd 0.1425 ce 0.3674) | 3.70s/step | table rows seen 5,565,012
+[14:30:28 +155.6m] step 2460 loss 0.6152 (kd 0.1473 ce 0.4679) | 3.69s/step | table rows seen 5,600,144
+[14:31:27 +156.6m] step 2480 loss 0.6277 (kd 0.1484 ce 0.4794) | 3.69s/step | table rows seen 5,627,352
+[14:32:46 +157.9m]   use row (step 2500): PLE/residual norm ratio 0.2977 (want >= 0.1) | term 0.0000
+[14:32:47 +157.9m] step 2500 loss 0.7372 (kd 0.0774 ce 0.6597) | 3.69s/step | table rows seen 5,674,840
+[14:34:00 +159.1m] step 2520 loss 0.6096 (kd 0.1155 ce 0.4941) | 3.69s/step | table rows seen 5,706,952
+[14:35:04 +160.2m] step 2540 loss 0.5403 (kd 0.1463 ce 0.3940) | 3.69s/step | table rows seen 5,734,412
+[14:36:33 +161.7m] step 2560 loss 0.5356 (kd 0.1111 ce 0.4245) | 3.69s/step | table rows seen 5,766,364
+[14:37:31 +162.6m] step 2580 loss 0.5805 (kd 0.1616 ce 0.4189) | 3.69s/step | table rows seen 5,789,728
+[14:38:39 +163.8m] step 2600 loss 0.5346 (kd 0.1413 ce 0.3933) | 3.68s/step | table rows seen 5,815,012
+[14:38:58 +164.1m]   held-out CE @ 2600: SFT 1.2129 (start 1.2084) | OOD 2.1260 (start 2.1164)
+[14:38:58 +164.1m]   PoSE @ 2600: 3,110 rows offset | highest position index 131,055 of 131,072
+[14:39:43 +164.8m]   PLE gain @ 2600: SFT +0.1765 | OOD +0.8717 | IN-corpus +4.2083 | extra +3.8801 (CE 1.2616) | extra2 +0.6676 (CE 0.7514) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[14:39:43 +164.8m]   injection @ 2600: 151 rows | PLE/residual ratio mean 0.2871 min 0.1891 max 0.4421 | mean use term 0.0000
+[14:39:43 +164.8m]   dependence @ 2600: 40 rows since last eval | mean gap CE_off-CE_on +2.2393 | frac meeting margin 0.97 | mean term 0.0005
+[14:39:44 +164.8m]   HC stats @ 2600: gate|dev| median 0.0267 (L0 0.0252, L39 0.0251) | inject w|dev| median 0.3893 | stream spread median 0.4739 (L39 0.4691)
+[14:41:07 +166.2m] step 2620 loss 0.7488 (kd 0.0964 ce 0.6524) | 3.71s/step | table rows seen 5,858,548
+[14:42:17 +167.4m] step 2640 loss 0.5993 (kd 0.1107 ce 0.4886) | 3.71s/step | table rows seen 5,895,152
+[14:43:24 +168.5m] step 2660 loss 0.6220 (kd 0.1314 ce 0.4906) | 3.71s/step | table rows seen 5,923,860
+[14:44:24 +169.5m] step 2680 loss 0.4933 (kd 0.1365 ce 0.3568) | 3.70s/step | table rows seen 5,945,112
+[14:45:26 +170.5m] step 2700 loss 0.5490 (kd 0.1410 ce 0.4080) | 3.70s/step | table rows seen 5,969,072
+[14:46:33 +171.7m] step 2720 loss 0.5504 (kd 0.1127 ce 0.4377) | 3.70s/step | table rows seen 6,012,528
+[14:47:38 +172.7m] step 2740 loss 0.4305 (kd 0.1482 ce 0.2823) | 3.69s/step | table rows seen 6,041,028
+[14:48:46 +173.9m] step 2760 loss 0.5860 (kd 0.1684 ce 0.4176) | 3.69s/step | table rows seen 6,066,660
+[14:49:54 +175.0m] step 2780 loss 0.5300 (kd 0.1212 ce 0.4087) | 3.69s/step | table rows seen 6,094,632
+[14:50:50 +176.0m]   layer-wise row 1216: 1022 positions, mean KL 0.1638 = S35<-T59 0.272 | S39<-T63 0.055
+[14:50:50 +176.0m]   use row (step 2800): PLE/residual norm ratio 0.2270 (want >= 0.1) | term 0.0000
+[14:50:52 +176.0m] step 2800 loss 0.5714 (kd 0.1637 ce 0.4077) | 3.68s/step | table rows seen 6,119,220
+[14:51:11 +176.3m]   held-out CE @ 2800: SFT 1.2127 (start 1.2084) | OOD 2.1278 (start 2.1164)
+[14:51:11 +176.3m]   PoSE @ 2800: 3,349 rows offset | highest position index 131,055 of 131,072
+[14:51:56 +177.0m]   PLE gain @ 2800: SFT +0.7220 | OOD +1.5833 | IN-corpus +6.4526 | extra +6.6059 (CE 1.2594) | extra2 +1.1491 (CE 0.7063) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[14:51:56 +177.0m]   injection @ 2800: 153 rows | PLE/residual ratio mean 0.2860 min 0.1981 max 0.4900 | mean use term 0.0000
+[14:51:56 +177.0m]   dependence @ 2800: 39 rows since last eval | mean gap CE_off-CE_on +1.6914 | frac meeting margin 0.97 | mean term 0.0020
+[14:51:56 +177.1m]   HC stats @ 2800: gate|dev| median 0.0267 (L0 0.0252, L39 0.0252) | inject w|dev| median 0.3909 | stream spread median 0.4752 (L39 0.4674)
+[14:53:07 +178.2m] step 2820 loss 0.5549 (kd 0.1232 ce 0.4317) | 3.70s/step | table rows seen 6,149,716
+[14:54:03 +179.2m] step 2840 loss 0.5131 (kd 0.1536 ce 0.3594) | 3.70s/step | table rows seen 6,168,640
+[14:55:05 +180.2m] step 2860 loss 0.7491 (kd 0.1275 ce 0.6216) | 3.69s/step | table rows seen 6,200,120
+[14:56:16 +181.4m] step 2880 loss 0.5532 (kd 0.0957 ce 0.4575) | 3.69s/step | table rows seen 6,240,516
+[14:57:25 +182.5m]   use row (step 2900): PLE/residual norm ratio 0.2521 (want >= 0.1) | term 0.0000
+[14:57:26 +182.5m] step 2900 loss 0.4286 (kd 0.1124 ce 0.3162) | 3.69s/step | table rows seen 6,263,996
+[14:58:33 +183.7m] step 2920 loss 0.6154 (kd 0.1236 ce 0.4917) | 3.69s/step | table rows seen 6,300,504
+[14:59:42 +184.8m] step 2940 loss 0.5037 (kd 0.1405 ce 0.3633) | 3.69s/step | table rows seen 6,320,728
+[15:00:49 +185.9m] step 2960 loss 0.5521 (kd 0.1537 ce 0.3984) | 3.69s/step | table rows seen 6,345,744
+[15:02:11 +187.3m] step 2980 loss 0.7046 (kd 0.1041 ce 0.6005) | 3.69s/step | table rows seen 6,386,904
+[15:03:31 +188.6m]   layer-wise row 1293: 1022 positions, mean KL 0.2727 = S35<-T59 0.478 | S39<-T63 0.068
+[15:03:31 +188.6m]   use row (step 3000): PLE/residual norm ratio 0.2595 (want >= 0.1) | term 0.0000
+[15:03:32 +188.7m] step 3000 loss 0.5855 (kd 0.1180 ce 0.4675) | 3.69s/step | table rows seen 6,419,240
+[15:03:51 +189.0m]   held-out CE @ 3000: SFT 1.2159 (start 1.2084) | OOD 2.1268 (start 2.1164)
+[15:03:51 +189.0m]   PoSE @ 3000: 3,588 rows offset | highest position index 131,055 of 131,072
+[15:04:37 +189.7m]   PLE gain @ 3000: SFT +0.5004 | OOD +1.2949 | IN-corpus +6.2208 | extra +6.1677 (CE 1.2615) | extra2 +0.9415 (CE 0.7647) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[15:04:37 +189.7m]   injection @ 3000: 155 rows | PLE/residual ratio mean 0.2917 min 0.2273 max 0.4421 | mean use term 0.0000
+[15:04:37 +189.7m]   dependence @ 3000: 39 rows since last eval | mean gap CE_off-CE_on +2.5073 | frac meeting margin 0.97 | mean term 0.0023
+[15:04:37 +189.7m]   HC stats @ 3000: gate|dev| median 0.0268 (L0 0.0252, L39 0.0251) | inject w|dev| median 0.3892 | stream spread median 0.4771 (L39 0.4680)
+[15:06:13 +191.3m] step 3020 loss 0.6671 (kd 0.0620 ce 0.6051) | 3.72s/step | table rows seen 6,461,840
+[15:07:12 +192.3m] step 3040 loss 0.7569 (kd 0.1413 ce 0.6156) | 3.71s/step | table rows seen 6,489,872
+[15:08:07 +193.2m] step 3060 loss 0.4832 (kd 0.1587 ce 0.3245) | 3.71s/step | table rows seen 6,512,688
+[15:09:18 +194.4m] step 3080 loss 0.6618 (kd 0.0906 ce 0.5712) | 3.71s/step | table rows seen 6,546,800
+[15:10:24 +195.5m]   use row (step 3100): PLE/residual norm ratio 0.3485 (want >= 0.1) | term 0.0000
+[15:10:25 +195.5m] step 3100 loss 0.6435 (kd 0.1293 ce 0.5142) | 3.70s/step | table rows seen 6,570,968
+[15:11:22 +196.5m] step 3120 loss 0.6405 (kd 0.1475 ce 0.4930) | 3.70s/step | table rows seen 6,597,500
+[15:12:35 +197.7m] step 3140 loss 0.5682 (kd 0.1510 ce 0.4172) | 3.70s/step | table rows seen 6,621,832
+[15:13:52 +199.0m] step 3160 loss 0.6723 (kd 0.1023 ce 0.5700) | 3.70s/step | table rows seen 6,660,368
+[15:14:57 +200.1m] step 3180 loss 0.4695 (kd 0.1531 ce 0.3164) | 3.70s/step | table rows seen 6,680,940
+[15:16:00 +201.1m]   layer-wise row 1963: 1022 positions, mean KL 0.2004 = S35<-T59 0.359 | S39<-T63 0.042
+[15:16:00 +201.1m]   use row (step 3200): PLE/residual norm ratio 0.3296 (want >= 0.1) | term 0.0000
+[15:16:01 +201.1m] step 3200 loss 0.5418 (kd 0.1411 ce 0.4007) | 3.69s/step | table rows seen 6,705,468
+[15:16:20 +201.4m]   held-out CE @ 3200: SFT 1.2161 (start 1.2084) | OOD 2.1255 (start 2.1164)
+[15:16:20 +201.4m]   PoSE @ 3200: 3,820 rows offset | highest position index 131,055 of 131,072
+[15:17:05 +202.2m]   PLE gain @ 3200: SFT +0.5834 | OOD +1.2123 | IN-corpus +5.6053 | extra +5.4086 (CE 1.2566) | extra2 +0.9419 (CE 0.7365) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[15:17:05 +202.2m]   injection @ 3200: 153 rows | PLE/residual ratio mean 0.2904 min 0.2291 max 0.4955 | mean use term 0.0000
+[15:17:05 +202.2m]   dependence @ 3200: 32 rows since last eval | mean gap CE_off-CE_on +2.9826 | frac meeting margin 0.97 | mean term 0.0049
+[15:17:06 +202.2m]   HC stats @ 3200: gate|dev| median 0.0268 (L0 0.0252, L39 0.0251) | inject w|dev| median 0.3873 | stream spread median 0.4737 (L39 0.4687)
+[15:18:14 +203.3m] step 3220 loss 0.5387 (kd 0.1526 ce 0.3861) | 3.71s/step | table rows seen 6,731,056
+[15:19:21 +204.5m] step 3240 loss 0.5955 (kd 0.1313 ce 0.4642) | 3.71s/step | table rows seen 6,757,824
+[15:20:34 +205.7m] step 3260 loss 0.6480 (kd 0.1108 ce 0.5373) | 3.71s/step | table rows seen 6,792,868
+[15:22:08 +207.3m] step 3280 loss 0.7497 (kd 0.0636 ce 0.6861) | 3.72s/step | table rows seen 6,831,888
+[15:23:25 +208.5m]   use row (step 3300): PLE/residual norm ratio 0.3240 (want >= 0.1) | term 0.0000
+[15:23:28 +208.6m] step 3300 loss 0.5725 (kd 0.0776 ce 0.4949) | 3.72s/step | table rows seen 6,868,532
+[15:24:34 +209.7m] step 3320 loss 0.5602 (kd 0.2221 ce 0.3381) | 3.72s/step | table rows seen 6,889,456
+[15:25:43 +210.8m] step 3340 loss 0.6655 (kd 0.1462 ce 0.5192) | 3.71s/step | table rows seen 6,911,728
+[15:26:48 +211.9m] step 3360 loss 0.4653 (kd 0.0927 ce 0.3725) | 3.71s/step | table rows seen 6,937,344
+[15:28:09 +213.3m] step 3380 loss 0.6604 (kd 0.1127 ce 0.5477) | 3.71s/step | table rows seen 6,972,488
+[15:29:19 +214.4m]   use row (step 3400): PLE/residual norm ratio 0.2759 (want >= 0.1) | term 0.0000
+[15:29:22 +214.5m] step 3400 loss 0.5220 (kd 0.0700 ce 0.4520) | 3.71s/step | table rows seen 7,002,204
+[15:29:41 +214.8m]   held-out CE @ 3400: SFT 1.2136 (start 1.2084) | OOD 2.1268 (start 2.1164)
+[15:29:41 +214.8m]   PoSE @ 3400: 4,060 rows offset | highest position index 131,055 of 131,072
+[15:30:26 +215.5m]   PLE gain @ 3400: SFT +0.5874 | OOD +1.1649 | IN-corpus +5.2261 | extra +5.1047 (CE 1.2544) | extra2 +0.8313 (CE 0.7556) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[15:30:26 +215.5m]   injection @ 3400: 148 rows | PLE/residual ratio mean 0.2926 min 0.2108 max 0.4339 | mean use term 0.0000
+[15:30:26 +215.5m]   dependence @ 3400: 40 rows since last eval | mean gap CE_off-CE_on +3.2833 | frac meeting margin 1.00 | mean term 0.0000
+[15:30:26 +215.6m]   HC stats @ 3400: gate|dev| median 0.0268 (L0 0.0253, L39 0.0252) | inject w|dev| median 0.3904 | stream spread median 0.4754 (L39 0.4696)
+[15:31:50 +216.9m] step 3420 loss 0.6008 (kd 0.1255 ce 0.4754) | 3.73s/step | table rows seen 7,032,812
+[15:33:00 +218.1m] step 3440 loss 0.7039 (kd 0.1342 ce 0.5697) | 3.73s/step | table rows seen 7,066,412
+[15:34:07 +219.2m] step 3460 loss 0.5277 (kd 0.1484 ce 0.3794) | 3.73s/step | table rows seen 7,090,056
+[15:35:26 +220.6m] step 3480 loss 0.5301 (kd 0.1005 ce 0.4296) | 3.73s/step | table rows seen 7,119,448
+[15:36:23 +221.5m]   use row (step 3500): PLE/residual norm ratio 0.2519 (want >= 0.1) | term 0.0000
+[15:36:26 +221.5m]   dep row (step 3500): CE_on 0.5097 | CE_off 2.3421 | gap +1.8324 (want >= 0.3) | term 0.0000
+[15:36:26 +221.5m] step 3500 loss 0.6548 (kd 0.1220 ce 0.5328) | 3.73s/step | table rows seen 7,148,140
+[15:37:30 +222.6m] step 3520 loss 0.4527 (kd 0.1510 ce 0.3017) | 3.72s/step | table rows seen 7,167,692
+[15:38:39 +223.8m] step 3540 loss 0.5786 (kd 0.1413 ce 0.4372) | 3.72s/step | table rows seen 7,194,524
+[15:39:53 +225.0m] step 3560 loss 0.4804 (kd 0.1469 ce 0.3335) | 3.72s/step | table rows seen 7,216,428
+[15:41:10 +226.3m] step 3580 loss 0.4723 (kd 0.1445 ce 0.3277) | 3.72s/step | table rows seen 7,234,996
+[15:42:10 +227.3m]   layer-wise row 297: 1022 positions, mean KL 0.2909 = S35<-T59 0.534 | S39<-T63 0.048
+[15:42:10 +227.3m]   use row (step 3600): PLE/residual norm ratio 0.3131 (want >= 0.1) | term 0.0000
+[15:42:11 +227.3m] step 3600 loss 0.4907 (kd 0.1186 ce 0.3721) | 3.72s/step | table rows seen 7,255,720
+[15:42:30 +227.6m]   held-out CE @ 3600: SFT 1.2131 (start 1.2084) | OOD 2.1304 (start 2.1164)
+[15:42:30 +227.6m]   PoSE @ 3600: 4,309 rows offset | highest position index 131,055 of 131,072
+[15:43:16 +228.4m]   PLE gain @ 3600: SFT +0.0802 | OOD +0.6732 | IN-corpus +3.2974 | extra +2.8363 (CE 1.2568) | extra2 +0.4058 (CE 0.7564) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[15:43:16 +228.4m]   injection @ 3600: 154 rows | PLE/residual ratio mean 0.3008 min 0.2151 max 0.5419 | mean use term 0.0000
+[15:43:16 +228.4m]   dependence @ 3600: 49 rows since last eval | mean gap CE_off-CE_on +1.7723 | frac meeting margin 1.00 | mean term 0.0000
+[15:43:16 +228.4m]   HC stats @ 3600: gate|dev| median 0.0268 (L0 0.0253, L39 0.0251) | inject w|dev| median 0.3985 | stream spread median 0.4731 (L39 0.4650)
+[15:44:38 +229.7m] step 3620 loss 0.5383 (kd 0.1272 ce 0.4112) | 3.74s/step | table rows seen 7,285,804
+[15:44:56 +230.1m] TIME BUDGET: stopping at step 3624
+[15:45:00 +230.1m]   saved the final state as next_step3623 (4 Sep: a run must never end without a checkpoint)
+[15:45:58 +231.1m] table flushed to disk at run end (in-RAM table rewritten)
+[15:45:58 +231.1m] DONE best step 1200 OOD 2.1154 (start 2.1164) | checkpoints in /content/work/lw2/ckpts | table /content/work/lw2/ngram_table.npy