lw5 final TRAIN.log (step1642)

lw5/TRAIN.log

@@ -0,0 +1,179 @@
+[10:17:47 +  1.2m] student streamed: 27.6 GB
+[10:17:47 +  1.2m] LoRA r=8 on 130 attention/GDN projections + routed experts of layers [0, 1, 2]..39 + shared experts trained fully
+[10:17:48 +  1.2m] reply-ending tokens: [248044, 248046] (hash reset on 248044)
+[10:18:45 +  2.2m] table held IN RAM: 20.0 GB (flush = full rewrite to /content/work/lw5/ngram_table.npy)
+[10:18:45 +  2.2m] PLE table: 8 heads x 4,880,000 rows x 256 = 9.99B params, injected before layer 2
+[10:18:46 +  2.2m] resumed expert LoRA
+[10:18:46 +  2.2m] resumed shared experts
+[10:18:46 +  2.2m] resumed linear LoRA on 130 projections
+[10:18:46 +  2.2m] resumed HC/PLE/gates/routers from /content/drive-local/lw5/ckpts/next_step3623.pt
+[10:18:46 +  2.2m] lm_head + embed_tokens on cuda:0 (LMHEAD_DEV)
+[10:18:46 +  2.2m] layer-wise KD: /content/work/probe/lw_maths2000.npz | pairs [(35, 59), (39, 63)] | weight 0.1 | 2000 cached sequences of 512 tokens
+[10:18:46 +  2.2m] HC_LAYERS=0-39: HC trains on 40 of 40 layers (grads+Muon momentum are ~8 bytes/param)
+[10:18:46 +  2.2m] LoRA/AdamW: 331.5M adapter params at lr 1.0e-04
+[10:18:46 +  2.2m] AUX anchors: layers [35, 39] weight 0.3 each
+[10:18:46 +  2.2m] trainable: Muon 588.9M | AdamW 0.80M | table 9.99B (sparse SGD)
+[10:18:46 +  2.2m] corpus source: /content/work/train/code_corpus.npy (155,781,328 tokens)
+[10:18:51 +  2.3m] held-out extra: /content/work/train/slice_cs/held_code.npy (66,156 tokens, 16 windows)
+[10:18:51 +  2.3m] held-out extra2: /content/work/train/slice_cs/held_sci.npy (27,167 tokens, 16 windows)
+[10:18:52 +  2.3m] teacher cache: 1,840 complete replies from /content/work/tcache_new (K=128); TCACHE_FRAC=0.9 of chat rows
+[10:19:12 +  2.6m] step 0 (HC identity, PLE no-op == the checkpoint): held-out CE SFT 1.2144 | OOD 2.1320
+[10:19:27 +  2.9m]   PLE gain @ 0: SFT +0.0066 | OOD +0.3424  (CE with memory OFF minus ON on 8+8 held rows; positive = the table helps)
+[10:19:29 +  2.9m] reasoning prompts: +1315 from /content/work/onpolicy_prompts.json
+[10:19:29 +  2.9m] 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
+/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)))
+[10:19:31 +  2.9m]   use row (step 1): PLE/residual norm ratio 0.2687 (want >= 0.1) | term 0.0000
+[10:19:34 +  3.0m] step1: grad-norm 2.638e+00 | HC probe max|delta| 4.990e-05 | table rows touched 9420
+[10:19:34 +  3.0m] peak GPU 45.1 GB
+[10:19:34 +  3.0m] PoSE: target window 131,072 | 1 rows offset so far | highest position index seen 111,856
+[10:19:41 +  3.1m]   layer-wise row 800: 1022 positions, mean KL 0.1506 = S35<-T59 0.241 | S39<-T63 0.061
+[10:19:41 +  3.1m]   use row (step 4): PLE/residual norm ratio 0.2944 (want >= 0.1) | term 0.0000
+[10:20:22 +  3.8m] step 20 loss 0.5041 (kd 0.0965 ce 0.4076) | 2.71s/step | table rows seen 84,528
+[10:21:31 +  4.9m] step 40 loss 0.4887 (kd 0.1182 ce 0.3705) | 3.09s/step | table rows seen 164,428
+[10:22:44 +  6.2m] step 60 loss 0.5502 (kd 0.1217 ce 0.4285) | 3.28s/step | table rows seen 250,032
+[10:23:46 +  7.2m] step 80 loss 0.5089 (kd 0.0737 ce 0.4352) | 3.24s/step | table rows seen 318,780
+[10:25:08 +  8.6m] step 100 loss 0.6905 (kd 0.0539 ce 0.6366) | 3.40s/step | table rows seen 409,256
+[10:26:15 +  9.7m] step 120 loss 0.4524 (kd 0.1296 ce 0.3228) | 3.39s/step | table rows seen 474,188
+[10:27:17 + 10.7m] step 140 loss 0.4206 (kd 0.1224 ce 0.2982) | 3.35s/step | table rows seen 533,584
+[10:28:21 + 11.8m] step 160 loss 0.4680 (kd 0.1126 ce 0.3554) | 3.34s/step | table rows seen 595,112
+[10:29:29 + 12.9m] step 180 loss 0.6424 (kd 0.0933 ce 0.5491) | 3.34s/step | table rows seen 658,496
+[10:30:34 + 14.0m] step 200 loss 0.5511 (kd 0.0959 ce 0.4552) | 3.34s/step | table rows seen 725,424
+[10:30:53 + 14.3m]   held-out CE @ 200: SFT 1.2139 (start 1.2144) | OOD 2.1312 (start 2.1320)
+[10:30:53 + 14.3m]   PoSE @ 200: 240 rows offset | highest position index 130,633 of 131,072
+[10:31:38 + 15.1m]   PLE gain @ 200: SFT +3.3540 | OOD +3.9652 | IN-corpus +11.2230 | extra +12.4708 (CE 1.2529) | extra2 +3.0735 (CE 0.7602) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[10:31:38 + 15.1m]   injection @ 200: 80 rows | PLE/residual ratio mean 0.2986 min 0.2198 max 0.3998 | mean use term 0.0000
+[10:31:38 + 15.1m]   dependence @ 200: 40 rows since last eval | mean gap CE_off-CE_on +4.2412 | frac meeting margin 0.90 | mean term 0.0361
+[10:31:39 + 15.1m]   HC stats @ 200: gate|dev| median 0.0269 (L0 0.0252, L39 0.0253) | inject w|dev| median 0.4034 | stream spread median 0.4747 (L39 0.4667)
+[10:31:45 + 15.2m]   new best by OOD CE: step 200
+[10:33:01 + 16.4m] step 220 loss 0.6720 (kd 0.0709 ce 0.6011) | 3.70s/step | table rows seen 801,016
+[10:34:31 + 17.9m] step 240 loss 0.5843 (kd 0.0971 ce 0.4871) | 3.77s/step | table rows seen 870,592
+[10:35:35 + 19.0m] step 260 loss 0.5258 (kd 0.0722 ce 0.4536) | 3.72s/step | table rows seen 929,412
+[10:36:56 + 20.4m] step 280 loss 0.4630 (kd 0.0647 ce 0.3982) | 3.74s/step | table rows seen 995,540
+[10:38:17 + 21.7m]   use row (step 300): PLE/residual norm ratio 0.3066 (want >= 0.1) | term 0.0000
+[10:38:18 + 21.7m] step 300 loss 0.5472 (kd 0.0766 ce 0.4706) | 3.77s/step | table rows seen 1,063,880
+[10:39:30 + 22.9m] step 320 loss 0.6581 (kd 0.1462 ce 0.5119) | 3.76s/step | table rows seen 1,123,820
+[10:40:40 + 24.1m] step 340 loss 0.5877 (kd 0.0775 ce 0.5103) | 3.74s/step | table rows seen 1,182,764
+[10:41:54 + 25.3m] step 360 loss 0.5201 (kd 0.0895 ce 0.4306) | 3.74s/step | table rows seen 1,249,556
+[10:43:09 + 26.6m] step 380 loss 0.5050 (kd 0.1262 ce 0.3788) | 3.74s/step | table rows seen 1,303,948
+[10:44:38 + 28.1m] step 400 loss 0.5025 (kd 0.0930 ce 0.4095) | 3.78s/step | table rows seen 1,367,052
+[10:44:57 + 28.4m]   held-out CE @ 400: SFT 1.2116 (start 1.2144) | OOD 2.1284 (start 2.1320)
+[10:44:57 + 28.4m]   PoSE @ 400: 493 rows offset | highest position index 131,025 of 131,072
+[10:45:42 + 29.1m]   PLE gain @ 400: SFT +3.0849 | OOD +4.7276 | IN-corpus +12.7540 | extra +14.2183 (CE 1.2551) | extra2 +2.2868 (CE 0.7321) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[10:45:42 + 29.1m]   injection @ 400: 90 rows | PLE/residual ratio mean 0.2875 min 0.2076 max 0.4420 | mean use term 0.0000
+[10:45:42 + 29.1m]   dependence @ 400: 53 rows since last eval | mean gap CE_off-CE_on +8.5142 | frac meeting margin 0.98 | mean term 0.0005
+[10:45:42 + 29.1m]   HC stats @ 400: gate|dev| median 0.0269 (L0 0.0253, L39 0.0253) | inject w|dev| median 0.4062 | stream spread median 0.4706 (L39 0.4678)
+[10:45:49 + 29.3m]   new best by OOD CE: step 400
+[10:46:48 + 30.2m] step 420 loss 0.4353 (kd 0.1153 ce 0.3200) | 3.91s/step | table rows seen 1,417,784
+[10:47:52 + 31.3m] step 440 loss 0.7236 (kd 0.0777 ce 0.6459) | 3.87s/step | table rows seen 1,467,512
+[10:49:07 + 32.6m] step 460 loss 0.5618 (kd 0.1113 ce 0.4504) | 3.87s/step | table rows seen 1,530,592
+[10:50:42 + 34.1m] step 480 loss 0.6287 (kd 0.0859 ce 0.5429) | 3.91s/step | table rows seen 1,594,128
+[10:51:39 + 35.1m]   use row (step 500): PLE/residual norm ratio 0.2780 (want >= 0.1) | term 0.0000
+[10:51:42 + 35.1m] step 500 loss 0.7065 (kd 0.0810 ce 0.6255) | 3.87s/step | table rows seen 1,652,016
+[10:52:52 + 36.3m] step 520 loss 0.6180 (kd 0.0974 ce 0.5206) | 3.85s/step | table rows seen 1,704,840
+[10:54:03 + 37.5m] step 540 loss 0.4763 (kd 0.1187 ce 0.3576) | 3.84s/step | table rows seen 1,760,172
+[10:55:21 + 38.8m] step 560 loss 0.5263 (kd 0.0816 ce 0.4446) | 3.85s/step | table rows seen 1,820,648
+[10:56:27 + 39.9m] step 580 loss 0.3653 (kd 0.0836 ce 0.2817) | 3.83s/step | table rows seen 1,866,696
+[10:57:41 + 41.1m]   layer-wise row 1749: 1022 positions, mean KL 0.2133 = S35<-T59 0.333 | S39<-T63 0.093
+[10:57:41 + 41.1m]   use row (step 600): PLE/residual norm ratio 0.2882 (want >= 0.1) | term 0.0000
+[10:57:43 + 41.2m]   dep row (step 600): CE_on 0.3482 | CE_off 3.7816 | gap +3.4334 (want >= 1.0) | term 0.0000
+[10:57:43 + 41.2m] step 600 loss 0.6267 (kd 0.1344 ce 0.4923) | 3.83s/step | table rows seen 1,932,188
+[10:58:02 + 41.5m]   held-out CE @ 600: SFT 1.2065 (start 1.2144) | OOD 2.1251 (start 2.1320)
+[10:58:02 + 41.5m]   PoSE @ 600: 738 rows offset | highest position index 131,025 of 131,072
+[10:58:47 + 42.2m]   PLE gain @ 600: SFT +2.3054 | OOD +3.5673 | IN-corpus +10.3617 | extra +11.9346 (CE 1.2545) | extra2 +1.6659 (CE 0.7508) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[10:58:47 + 42.2m]   injection @ 600: 76 rows | PLE/residual ratio mean 0.2984 min 0.2054 max 0.5249 | mean use term 0.0000
+[10:58:47 + 42.2m]   dependence @ 600: 45 rows since last eval | mean gap CE_off-CE_on +5.5111 | frac meeting margin 1.00 | mean term 0.0000
+[10:58:48 + 42.2m]   HC stats @ 600: gate|dev| median 0.0269 (L0 0.0253, L39 0.0252) | inject w|dev| median 0.4027 | stream spread median 0.4748 (L39 0.4681)
+[10:58:53 + 42.3m]   new best by OOD CE: step 600
+[10:59:53 + 43.3m] step 620 loss 0.5030 (kd 0.1138 ce 0.3892) | 3.91s/step | table rows seen 1,982,588
+[11:00:58 + 44.4m] step 640 loss 0.5020 (kd 0.0923 ce 0.4097) | 3.89s/step | table rows seen 2,026,892
+[11:02:00 + 45.4m] step 660 loss 0.5494 (kd 0.0890 ce 0.4604) | 3.87s/step | table rows seen 2,069,952
+[11:03:15 + 46.7m] step 680 loss 0.5190 (kd 0.1201 ce 0.3989) | 3.86s/step | table rows seen 2,119,924
+[11:04:27 + 47.9m] step 700 loss 0.4040 (kd 0.1162 ce 0.2878) | 3.86s/step | table rows seen 2,169,344
+[11:05:47 + 49.2m] step 720 loss 0.6590 (kd 0.0802 ce 0.5788) | 3.86s/step | table rows seen 2,219,840
+[11:06:51 + 50.3m] step 740 loss 0.4830 (kd 0.1023 ce 0.3807) | 3.84s/step | table rows seen 2,258,604
+[11:08:02 + 51.5m] step 760 loss 0.6660 (kd 0.1143 ce 0.5517) | 3.84s/step | table rows seen 2,306,932
+[11:09:13 + 52.6m] step 780 loss 0.6387 (kd 0.1000 ce 0.5387) | 3.83s/step | table rows seen 2,355,260
+[11:10:27 + 53.9m]   layer-wise row 1974: 1022 positions, mean KL 0.1070 = S35<-T59 0.190 | S39<-T63 0.024
+[11:10:27 + 53.9m]   use row (step 800): PLE/residual norm ratio 0.2731 (want >= 0.1) | term 0.0000
+[11:10:30 + 53.9m]   dep row (step 800): CE_on 0.0971 | CE_off 1.8263 | gap +1.7292 (want >= 1.0) | term 0.0000
+[11:10:30 + 53.9m] step 800 loss 0.6560 (kd 0.0655 ce 0.5905) | 3.83s/step | table rows seen 2,409,536
+[11:10:49 + 54.2m]   held-out CE @ 800: SFT 1.2052 (start 1.2144) | OOD 2.1297 (start 2.1320)
+[11:10:49 + 54.2m]   PoSE @ 800: 984 rows offset | highest position index 131,025 of 131,072
+[11:11:34 + 55.0m]   PLE gain @ 800: SFT +2.2802 | OOD +3.2870 | IN-corpus +8.6690 | extra +10.4940 (CE 1.2582) | extra2 +1.2679 (CE 0.7618) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[11:11:34 + 55.0m]   injection @ 800: 84 rows | PLE/residual ratio mean 0.2870 min 0.1626 max 0.4513 | mean use term 0.0000
+[11:11:34 + 55.0m]   dependence @ 800: 46 rows since last eval | mean gap CE_off-CE_on +3.8568 | frac meeting margin 0.98 | mean term 0.0073
+[11:11:34 + 55.0m]   HC stats @ 800: gate|dev| median 0.0269 (L0 0.0253, L39 0.0251) | inject w|dev| median 0.3995 | stream spread median 0.4750 (L39 0.4679)
+[11:12:37 + 56.0m] step 820 loss 0.4807 (kd 0.1396 ce 0.3411) | 3.89s/step | table rows seen 2,447,084
+[11:13:51 + 57.3m] step 840 loss 0.5405 (kd 0.1411 ce 0.3994) | 3.89s/step | table rows seen 2,495,240
+[11:15:03 + 58.5m] step 860 loss 0.5276 (kd 0.1046 ce 0.4230) | 3.88s/step | table rows seen 2,549,944
+[11:16:05 + 59.5m] step 880 loss 0.6773 (kd 0.0844 ce 0.5929) | 3.86s/step | table rows seen 2,576,388
+[11:17:18 + 60.7m] step 900 loss 0.5866 (kd 0.1267 ce 0.4599) | 3.86s/step | table rows seen 2,624,456
+[11:18:20 + 61.8m] step 920 loss 0.3290 (kd 0.1042 ce 0.2248) | 3.84s/step | table rows seen 2,657,628
+[11:19:12 + 62.6m] step 940 loss 0.5288 (kd 0.1341 ce 0.3947) | 3.81s/step | table rows seen 2,692,856
+[11:20:25 + 63.9m] step 960 loss 0.4872 (kd 0.0573 ce 0.4298) | 3.81s/step | table rows seen 2,739,428
+[11:21:45 + 65.2m] step 980 loss 0.6728 (kd 0.0610 ce 0.6118) | 3.81s/step | table rows seen 2,792,564
+[11:22:47 + 66.2m] step 1000 loss 0.5749 (kd 0.1260 ce 0.4488) | 3.80s/step | table rows seen 2,840,860
+[11:23:05 + 66.5m]   held-out CE @ 1000: SFT 1.2022 (start 1.2144) | OOD 2.1339 (start 2.1320)
+[11:23:05 + 66.5m]   PoSE @ 1000: 1,216 rows offset | highest position index 131,025 of 131,072
+[11:23:51 + 67.3m]   PLE gain @ 1000: SFT +1.8558 | OOD +3.0573 | IN-corpus +8.1644 | extra +9.9091 (CE 1.2570) | extra2 +0.9752 (CE 0.7807) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[11:23:51 + 67.3m]   injection @ 1000: 75 rows | PLE/residual ratio mean 0.2839 min 0.2247 max 0.4424 | mean use term 0.0000
+[11:23:51 + 67.3m]   dependence @ 1000: 32 rows since last eval | mean gap CE_off-CE_on +4.0904 | frac meeting margin 1.00 | mean term 0.0000
+[11:23:51 + 67.3m]   HC stats @ 1000: gate|dev| median 0.0269 (L0 0.0254, L39 0.0251) | inject w|dev| median 0.4050 | stream spread median 0.4772 (L39 0.4677)
+[11:25:00 + 68.4m] step 1020 loss 0.5696 (kd 0.1118 ce 0.4577) | 3.86s/step | table rows seen 2,878,832
+[11:26:07 + 69.5m] step 1040 loss 0.4398 (kd 0.0585 ce 0.3812) | 3.85s/step | table rows seen 2,918,916
+[11:27:23 + 70.8m] step 1060 loss 0.4259 (kd 0.1130 ce 0.3129) | 3.85s/step | table rows seen 2,960,076
+[11:28:43 + 72.2m] step 1080 loss 0.5046 (kd 0.0935 ce 0.4112) | 3.85s/step | table rows seen 3,003,352
+[11:30:14 + 73.7m] step 1100 loss 0.5712 (kd 0.1291 ce 0.4421) | 3.86s/step | table rows seen 3,067,388
+[11:31:20 + 74.8m] step 1120 loss 0.3742 (kd 0.1329 ce 0.2413) | 3.85s/step | table rows seen 3,099,368
+[11:32:33 + 76.0m] step 1140 loss 0.5226 (kd 0.1230 ce 0.3996) | 3.85s/step | table rows seen 3,143,780
+[11:33:39 + 77.1m] step 1160 loss 0.3756 (kd 0.1168 ce 0.2587) | 3.84s/step | table rows seen 3,170,740
+[11:34:59 + 78.4m] step 1180 loss 0.4696 (kd 0.0920 ce 0.3776) | 3.84s/step | table rows seen 3,219,216
+[11:36:17 + 79.7m] step 1200 loss 0.3692 (kd 0.0949 ce 0.2743) | 3.84s/step | table rows seen 3,254,844
+[11:36:36 + 80.0m]   held-out CE @ 1200: SFT 1.2059 (start 1.2144) | OOD 2.1289 (start 2.1320)
+[11:36:36 + 80.0m]   PoSE @ 1200: 1,467 rows offset | highest position index 131,025 of 131,072
+[11:37:21 + 80.8m]   PLE gain @ 1200: SFT +1.6350 | OOD +2.5600 | IN-corpus +5.5254 | extra +7.0162 (CE 1.2495) | extra2 +0.2386 (CE 0.8021) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[11:37:21 + 80.8m]   injection @ 1200: 81 rows | PLE/residual ratio mean 0.2733 min 0.2059 max 0.3497 | mean use term 0.0000
+[11:37:21 + 80.8m]   dependence @ 1200: 51 rows since last eval | mean gap CE_off-CE_on +4.4319 | frac meeting margin 0.98 | mean term 0.0024
+[11:37:22 + 80.8m]   HC stats @ 1200: gate|dev| median 0.0268 (L0 0.0254, L39 0.0251) | inject w|dev| median 0.4006 | stream spread median 0.4774 (L39 0.4663)
+[11:38:37 + 82.1m] step 1220 loss 0.6126 (kd 0.0792 ce 0.5334) | 3.89s/step | table rows seen 3,294,984
+[11:39:46 + 83.2m] step 1240 loss 0.4378 (kd 0.0688 ce 0.3690) | 3.89s/step | table rows seen 3,330,840
+[11:41:00 + 84.4m] step 1260 loss 0.5787 (kd 0.0770 ce 0.5018) | 3.88s/step | table rows seen 3,362,980
+[11:42:06 + 85.5m] step 1280 loss 0.4199 (kd 0.0807 ce 0.3392) | 3.87s/step | table rows seen 3,397,444
+[11:43:23 + 86.8m] step 1300 loss 0.6153 (kd 0.0975 ce 0.5179) | 3.87s/step | table rows seen 3,432,916
+[11:44:40 + 88.1m] step 1320 loss 0.5428 (kd 0.1512 ce 0.3916) | 3.87s/step | table rows seen 3,469,684
+[11:45:51 + 89.3m] step 1340 loss 0.4571 (kd 0.1196 ce 0.3374) | 3.87s/step | table rows seen 3,499,836
+[11:47:03 + 90.5m] step 1360 loss 0.4484 (kd 0.0717 ce 0.3767) | 3.86s/step | table rows seen 3,534,552
+[11:48:06 + 91.5m] step 1380 loss 0.5499 (kd 0.0813 ce 0.4685) | 3.85s/step | table rows seen 3,574,732
+[11:49:23 + 92.8m] step 1400 loss 0.5531 (kd 0.0966 ce 0.4565) | 3.85s/step | table rows seen 3,624,600
+[11:49:42 + 93.1m]   held-out CE @ 1400: SFT 1.2039 (start 1.2144) | OOD 2.1309 (start 2.1320)
+[11:49:42 + 93.1m]   PoSE @ 1400: 1,713 rows offset | highest position index 131,025 of 131,072
+[11:50:27 + 93.9m]   PLE gain @ 1400: SFT +2.9396 | OOD +3.8990 | IN-corpus +8.7007 | extra +11.1144 (CE 1.2478) | extra2 +0.7373 (CE 0.8054) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[11:50:27 + 93.9m]   injection @ 1400: 86 rows | PLE/residual ratio mean 0.2718 min 0.2241 max 0.4252 | mean use term 0.0000
+[11:50:27 + 93.9m]   dependence @ 1400: 46 rows since last eval | mean gap CE_off-CE_on +3.7728 | frac meeting margin 0.98 | mean term 0.0076
+[11:50:27 + 93.9m]   HC stats @ 1400: gate|dev| median 0.0269 (L0 0.0253, L39 0.0252) | inject w|dev| median 0.4000 | stream spread median 0.4731 (L39 0.4659)
+[11:51:43 + 95.2m] step 1420 loss 0.4129 (kd 0.0906 ce 0.3223) | 3.90s/step | table rows seen 3,664,344
+[11:52:58 + 96.4m] step 1440 loss 0.5574 (kd 0.1042 ce 0.4533) | 3.90s/step | table rows seen 3,702,316
+[11:54:05 + 97.5m] step 1460 loss 0.6878 (kd 0.0870 ce 0.6007) | 3.89s/step | table rows seen 3,747,824
+[11:55:12 + 98.6m] step 1480 loss 0.4352 (kd 0.1180 ce 0.3172) | 3.88s/step | table rows seen 3,785,536
+[11:56:42 +100.1m]   use row (step 1500): PLE/residual norm ratio 0.2651 (want >= 0.1) | term 0.0000
+[11:56:45 +100.2m] step 1500 loss 0.5689 (kd 0.0745 ce 0.4943) | 3.89s/step | table rows seen 3,833,936
+[11:58:00 +101.4m] step 1520 loss 0.3755 (kd 0.0819 ce 0.2936) | 3.89s/step | table rows seen 3,862,208
+[11:59:03 +102.5m] step 1540 loss 0.2600 (kd 0.0977 ce 0.1622) | 3.88s/step | table rows seen 3,880,172
+[12:00:13 +103.6m] step 1560 loss 0.5281 (kd 0.1261 ce 0.4019) | 3.88s/step | table rows seen 3,910,656
+[12:01:29 +104.9m] step 1580 loss 0.4047 (kd 0.0898 ce 0.3149) | 3.87s/step | table rows seen 3,938,304
+[12:02:30 +105.9m]   use row (step 1600): PLE/residual norm ratio 0.2369 (want >= 0.1) | term 0.0000
+[12:02:33 +106.0m] step 1600 loss 0.5710 (kd 0.1157 ce 0.4553) | 3.87s/step | table rows seen 3,977,016
+[12:02:52 +106.3m]   held-out CE @ 1600: SFT 1.2055 (start 1.2144) | OOD 2.1299 (start 2.1320)
+[12:02:52 +106.3m]   PoSE @ 1600: 1,949 rows offset | highest position index 131,025 of 131,072
+[12:03:37 +107.1m]   PLE gain @ 1600: SFT +2.9867 | OOD +3.9038 | IN-corpus +8.2404 | extra +10.7882 (CE 1.2511) | extra2 +1.4362 (CE 0.7955) (CE off minus on; IN = training text the table may have seen) | live rows -1
+[12:03:37 +107.1m]   injection @ 1600: 80 rows | PLE/residual ratio mean 0.2673 min 0.1988 max 0.3578 | mean use term 0.0000
+[12:03:37 +107.1m]   dependence @ 1600: 36 rows since last eval | mean gap CE_off-CE_on +5.3818 | frac meeting margin 0.94 | mean term 0.0393
+[12:03:38 +107.1m]   HC stats @ 1600: gate|dev| median 0.0269 (L0 0.0253, L39 0.0252) | inject w|dev| median 0.3972 | stream spread median 0.4676 (L39 0.4628)
+[12:04:48 +108.2m] step 1620 loss 0.6055 (kd 0.1171 ce 0.4884) | 3.90s/step | table rows seen 4,008,400
+[12:06:30 +109.9m] step 1640 loss 0.6089 (kd 0.0725 ce 0.5364) | 3.92s/step | table rows seen 4,057,488
+[12:06:35 +110.0m] TIME BUDGET: stopping at step 1643
+[12:06:38 +110.1m]   saved the final state as next_step1642 (4 Sep: a run must never end without a checkpoint)
+[12:07:36 +111.0m] table flushed to disk at run end (in-RAM table rewritten)
+[12:07:36 +111.0m] DONE best step 600 OOD 2.1251 (start 2.1320) | checkpoints in /content/work/lw5/ckpts | table /content/work/lw5/ngram_table.npy