diff --git a/docs/测试说明/boot_log_data/20261027_bench42_reset_only_boots_r1_r4.txt b/docs/测试说明/boot_log_data/20261027_bench42_reset_only_boots_r1_r4.txt new file mode 100644 index 00000000..f7f462f0 --- /dev/null +++ b/docs/测试说明/boot_log_data/20261027_bench42_reset_only_boots_r1_r4.txt @@ -0,0 +1,606 @@ +2026-10-27 bench task-42 -- reset-only boot captures, 4 counted circles (HEAD image) +identity: "fw build: Oct 26 2026 22:52:09 suite=NONE dstr=off" (suite=NONE product build, dstr=off non-destructive) +coordinate: HEAD b24b2b5f; firmware sources identical to b623a406 (no commit after it touched .c/.h; the only source + newer than the .hex is test/host/console_log/console_log_test.c, a host unit test not in the uvprojx). +provenance: flashed + readback-verified at 00:25:06 (@test rc=0) -- that flash boot is reported separately and is + NOT part of this consecutive-reset-only sequence (task-32 rule: a circle preceded by a flash does not + join the count). Lines below are raw serial-assistant daemon output, verbatim, no rewrite/reorder; + "gen" monotonic bumps prove the four windows do not overlap. Each circle: open+clear -> stlink reset + (-c SWD -Rst -Run, zero flash writes) -> wait-idle -> log. +excluded: the 01:34 attempt (serial gen=272) is DELIBERATELY absent: it captured 0 payload lines because the + serial-assistant daemon had died (see 20261027_bench42_verdicts.txt incident 1). Nothing is counted + from it -- there is no data to count. +line-ending note: pasted tool output was normalised CRLF -> LF for this archive; payload bytes themselves untouched. + + +===== boot_r1_gen273 (serial gen=273, 137 raw lines, reset-only) ===== +[RX] 2026-10-27T01:50:01.965+08:00 [----/--/-- --:--:--][APP] boot: syslog init OK +[RX] 2026-10-27T01:50:01.965+08:00 [----/--/-- --:--:--][APP] fw build: Oct 26 2026 22:52:09 suite=NONE dstr=off +[RX] 2026-10-27T01:50:01.976+08:00 [----/--/-- --:--:--][APP] reset cause: software (NVIC_SystemReset) (CSR=0x14000000) +[RX] 2026-10-27T01:50:01.987+08:00 PREVRUN seg=2 seq=2160895301 t=952852 +[RX] 2026-10-27T01:50:01.987+08:00 TICKRUN uw=952860 n=952860 duw=8 +[RX] 2026-10-27T01:50:01.987+08:00 [----/--/-- --:--:--][RTC] sd2506_init: OK +[RX] 2026-10-27T01:50:01.997+08:00 [----/--/-- --:--:--][APP] SD2506 init: OK (ret=0) +[RX] 2026-10-27T01:50:01.997+08:00 [2026-10-26 17:50:01][CLK] sys_clock_init: RTC initial time 2026-10-26 17:50:01 +[RX] 2026-10-27T01:50:02.008+08:00 [2026-10-26 17:50:01][CLK] sys_clock_init: wall clock base = unix 1793037001, base_tick=139 +[RX] 2026-10-27T01:50:02.019+08:00 [2026-10-26 17:50:01][APP] RS485 init: OK (UART4, DE=PA15) +[RX] 2026-10-27T01:50:02.030+08:00 [2026-10-26 17:50:01][NAND] Resetting NAND... +[RX] 2026-10-27T01:50:02.052+08:00 [2026-10-26 17:50:01][NAND] Reading NAND ID... +[RX] 2026-10-27T01:50:02.052+08:00 [2026-10-26 17:50:01][NAND] NAND ID: MID=0xC8, DID=0x52 +[RX] 2026-10-27T01:50:02.062+08:00 [2026-10-26 17:50:01][NAND] Scanning bad blocks... +[RX] 2026-10-27T01:50:02.189+08:00 [2026-10-26 17:50:01][NAND] BBT scan: 0 bad blocks found +[RX] 2026-10-27T01:50:02.199+08:00 [2026-10-26 17:50:01][NAND] Enabling ECC... +[RX] 2026-10-27T01:50:02.199+08:00 [2026-10-26 17:50:01][NAND] Unlocking block protection... +[RX] 2026-10-27T01:50:02.210+08:00 [2026-10-26 17:50:01][NAND] Locating BBT pool... +[RX] 2026-10-27T01:50:02.210+08:00 [2026-10-26 17:50:01][NAND] Loading persisted BBT... +[RX] 2026-10-27T01:50:02.221+08:00 [2026-10-26 17:50:01][NAND] NAND init OK +[RX] 2026-10-27T01:50:02.221+08:00 [2026-10-26 17:50:01][APP] NAND init: OK +[RX] 2026-10-27T01:50:02.221+08:00 [2026-10-26 17:50:01][ADC] Init OK +[RX] 2026-10-27T01:50:02.231+08:00 [2026-10-26 17:50:01][APP] ADC init: OK +[RX] 2026-10-27T01:50:02.231+08:00 [2026-10-26 17:50:01][APP] ADC input layer init: OK +[RX] 2026-10-27T01:50:02.231+08:00 [2026-10-26 17:50:01][APP] phasor layer init: OK (inst=5) +[RX] 2026-10-27T01:50:02.242+08:00 [2026-10-26 17:50:01][APP] freq layer init: OK +[RX] 2026-10-27T01:50:02.242+08:00 [2026-10-26 17:50:01][CFG] register: section 'adc_cal' (9 keys) +[RX] 2026-10-27T01:50:02.253+08:00 [2026-10-26 17:50:01][CFG] register: section 'adc_cal_ofs' (8 keys) +[RX] 2026-10-27T01:50:02.263+08:00 [2026-10-26 17:50:01][APP] adc cal init: OK (k_q16 tpafe=10000000 stm32=52800000) +[RX] 2026-10-27T01:50:02.263+08:00 [2026-10-26 17:50:01][CFG] register: section 'run_par' (9 keys) +[RX] 2026-10-27T01:50:02.274+08:00 [2026-10-26 17:50:01][APP] run par init: OK (db9 k/b via adc_cal, evt=1<<8) +[RX] 2026-10-27T01:50:02.274+08:00 [2026-10-26 17:50:01][CFG] register: section 'comm' (2 keys) +[RX] 2026-10-27T01:50:02.284+08:00 [2026-10-26 17:50:01][APP] comm init: OK (ca=1 port=2404) +[RX] 2026-10-27T01:50:02.295+08:00 [2026-10-26 17:50:01][APP] protection init: OK (set=40 elm=9) +[RX] 2026-10-27T01:50:02.295+08:00 [2026-10-26 17:50:01][APP] SD2506 ID: 2512153425482405 +[RX] 2026-10-27T01:50:02.306+08:00 [2026-10-26 17:50:01][APP] SD2506 time: 2026-10-26 17:50:01 (week 1) +[RX] 2026-10-27T01:50:02.306+08:00 [2026-10-26 17:50:01][APP] SD2506 temp: 25 C +[RX] 2026-10-27T01:50:02.317+08:00 [2026-10-26 17:50:01][APP] SD2506 battery: 3.12 V +[RX] 2026-10-27T01:50:02.317+08:00 [2026-10-26 17:50:01][APP] App init OK +[RX] 2026-10-27T01:50:02.327+08:00 [2026-10-26 17:50:01][NAND_FTL] Initializing NAND FTL... +[RX] 2026-10-27T01:50:02.348+08:00 [2026-10-26 17:50:01][PROT] uncalibrated -> protection blocked (UA/UN/IA VALID not all set) +[RX] 2026-10-27T01:50:02.420+08:00 [2026-10-26 17:50:01][NAND_FTL] Map resumed: 14094/97504 sectors used +[RX] 2026-10-27T01:50:02.431+08:00 [2026-10-26 17:50:01][NAND_FTL] Map head=50288 tail=3547 epoch=7 +[RX] 2026-10-27T01:50:02.431+08:00 [2026-10-26 17:50:01][NAND_FTL] NAND FTL ready (capacity: 97504 pages = 190 MB) +[RX] 2026-10-27T01:50:02.524+08:00 [2026-10-26 17:50:01] [FS] FATFS mounted +[RX] 2026-10-27T01:50:02.575+08:00 [2026-10-26 17:50:01][SYSLOG] runlog boot entry: power on +[RX] 2026-10-27T01:50:02.575+08:00 [2026-10-26 17:50:01][CFG] register: section 'network' (4 keys) +[RX] 2026-10-27T01:50:02.586+08:00 [2026-10-26 17:50:01][CFG] register: section 'ftp' (3 keys) +[RX] 2026-10-27T01:50:02.596+08:00 [2026-10-26 17:50:01][CFG] load: OK (957B, heap free 16552B) +[RX] 2026-10-27T01:50:02.596+08:00 [2026-10-26 17:50:01][NET_CFG] load: OK ip=192.168.1.100 +[RX] 2026-10-27T01:50:02.607+08:00 [2026-10-26 17:50:01] [CFG] prot set loaded (/prot_set.bin) +[RX] 2026-10-27T01:50:02.628+08:00 [2026-10-26 17:50:01][ADC_TASK] first: UA=11429 UB=1073 UC=952 UN=11454 IA=11451 IB=1014 IC=1007 IN=984 T=974 +[RX] 2026-10-27T01:50:02.638+08:00 [2026-10-26 17:50:01][ADC_TASK] phasor(first) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:02.648+08:00 [2026-10-26 17:50:01][ADC_TASK] phasor(first) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:02.648+08:00 [2026-10-26 17:50:01][ADC_TASK] phasor(first) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:02.658+08:00 [2026-10-26 17:50:01][ADC_TASK] phasor(first) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:02.669+08:00 [2026-10-26 17:50:01][ADC_TASK] phasor(first) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:02.679+08:00 [2026-10-26 17:50:01][ADC_TASK] freq(first): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:50:02.679+08:00 [2026-10-26 17:50:01][PROT] protect task start: cycle=20ms elm=9 +[RX] 2026-10-27T01:50:02.690+08:00 [2026-10-26 17:50:01][NET_TASK] === Network Init === +[RX] 2026-10-27T01:50:02.690+08:00 [2026-10-26 17:50:01][NET] ch395f ver=0x4A fun_para=0x08 +[RX] 2026-10-27T01:50:02.690+08:00 MISS start snap=0x000001E7 req=0x000001F7 t=832 +[RX] 2026-10-27T01:50:02.700+08:00 [2026-10-26 17:50:01][WD] [WD] armed: timeout ~2498ms (worst ~1701ms), miss_tol=800ms +[RX] 2026-10-27T01:50:02.710+08:00 [2026-10-26 17:50:01][NET_TASK] net init: OK +[RX] 2026-10-27T01:50:02.751+08:00 [2026-10-26 17:50:01][NET_TASK] MAC: 3C:AB:72:53:2B:12 +[RX] 2026-10-27T01:50:02.751+08:00 [2026-10-26 17:50:01][NET_TASK] IP_INF: IP=192.168.1.100 GW=192.168.1.1 MASK=255.255.255.0 +[RX] 2026-10-27T01:50:02.762+08:00 [2026-10-26 17:50:01][UI_TASK] UI task: started, wait net ready +[RX] 2026-10-27T01:50:04.701+08:00 [2026-10-26 17:50:03][NET_TASK] PHY: 100M FULL +[RX] 2026-10-27T01:50:04.721+08:00 [2026-10-26 17:50:03][NET_TASK] netTask: started (single-socket mode) +[RX] 2026-10-27T01:50:04.753+08:00 [2026-10-26 17:50:03] [FTP] using factory default password +[RX] 2026-10-27T01:50:04.784+08:00 [2026-10-26 17:50:03][TIME_SYNC] time_sync: TCP listen on :8888 (sock=0) +[RX] 2026-10-27T01:50:04.815+08:00 [2026-10-26 17:50:03][I104] i104: listening on 2404 +[RX] 2026-10-27T01:50:04.826+08:00 [2026-10-26 17:50:03] [FTP] waiting for connection... +[RX] 2026-10-27T01:50:04.826+08:00 [2026-10-26 17:50:03][UI_TASK] UI task: net ready, init port +[RX] 2026-10-27T01:50:04.836+08:00 [2026-10-26 17:50:03][UI_TASK] UI task: ui_port_init enter +[RX] 2026-10-27T01:50:04.836+08:00 [2026-10-26 17:50:03][UI_PORT] theme: mono dark_bg=true applied +[RX] 2026-10-27T01:50:04.846+08:00 [2026-10-26 17:50:03][UI_TASK] UI port init: OK +[RX] 2026-10-27T01:50:04.846+08:00 [2026-10-26 17:50:03][UI_TASK] UI task: ui_menu_init enter +[RX] 2026-10-27T01:50:04.857+08:00 [2026-10-26 17:50:03][UI_MENU] menu build start: total=15136 free=12692 big=12692 +[RX] 2026-10-27T01:50:04.867+08:00 [2026-10-26 17:50:03][UI_MENU_VIEW] view init: root frame w=66 h=107 +[RX] 2026-10-27T01:50:04.878+08:00 [2026-10-26 17:50:03][UI_MENU] menu build done: total=15020 free=11828 big=11816 used=3192 +[RX] 2026-10-27T01:50:04.878+08:00 [2026-10-26 17:50:03][UI_TASK] UI menu init: OK +[RX] 2026-10-27T01:50:04.888+08:00 [2026-10-26 17:50:03][UI_STANDBY] standby: ready (idle=60000ms) +[RX] 2026-10-27T01:50:04.888+08:00 [2026-10-26 17:50:03][UI_TASK] UI standby: ready (idle=60s) +[RX] 2026-10-27T01:50:04.940+08:00 [2026-10-26 17:50:03][UI_TASK] UI net sink: started (port 7003) +[RX] 2026-10-27T01:50:04.950+08:00 MISS start snap=0x000001E7 req=0x000001F7 t=3085 +[RX] 2026-10-27T01:50:04.950+08:00 [PROF] t=3089 uic=0 uip=0 uipn=0 uil=0 uiw=0 uis=0 uisn=0 adc=2629 adcm=2158 adcn=0 gl=0 +[RX] 2026-10-27T01:50:04.961+08:00 [PROF2] t=3089 defd=131042 defs=35862 netp=2016 netn=586 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:06.866+08:00 [PROF] t=5004 uic=171 uip=22486 uipn=6839 uil=10998 uiw=12578 uis=1272 uisn=0 adc=4543 adcm=2158 adcn=0 gl=0 +[RX] 2026-10-27T01:50:06.881+08:00 [PROF2] t=5004 defd=131042 defs=35862 netp=2982 netn=0 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:07.340+08:00 [2026-10-26 17:50:06] [STACK] default peak_used=2172/5120 free_min=2948 (57%) +[RX] 2026-10-27T01:50:07.340+08:00 [2026-10-26 17:50:06] [STACK] net peak_used=1116/3840 free_min=2724 (70%) +[RX] 2026-10-27T01:50:07.351+08:00 [2026-10-26 17:50:06] [STACK] ftp peak_used=740/4096 free_min=3356 (81%) +[RX] 2026-10-27T01:50:07.361+08:00 [2026-10-26 17:50:06] [STACK] ui peak_used=4188/16384 free_min=12196 (74%) +[RX] 2026-10-27T01:50:07.361+08:00 [2026-10-26 17:50:06] [STACK] timesync peak_used=616/2560 free_min=1944 (75%) +[RX] 2026-10-27T01:50:07.372+08:00 [2026-10-26 17:50:06] [STACK] adc peak_used=1000/2560 free_min=1560 (60%) +[RX] 2026-10-27T01:50:07.382+08:00 [2026-10-26 17:50:06] [STACK] iec104 peak_used=540/2560 free_min=2020 (78%) +[RX] 2026-10-27T01:50:07.382+08:00 [2026-10-26 17:50:06] [STACK] protect peak_used=492/2048 free_min=1556 (75%) +[RX] 2026-10-27T01:50:07.393+08:00 [2026-10-26 17:50:06] [STACK] heap free=15624 min_ever=8464 +[RX] 2026-10-27T01:50:08.900+08:00 [PROF] t=7034 uic=349 uip=73623 uipn=2837 uil=11000 uiw=12578 uis=1272 uisn=0 adc=6573 adcm=2158 adcn=0 gl=0 +[RX] 2026-10-27T01:50:08.910+08:00 [PROF2] t=7034 defd=131042 defs=35862 netp=2984 netn=0 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:10.912+08:00 [PROF] t=9052 uic=531 uip=73623 uipn=9838 uil=10998 uiw=12578 uis=1272 uisn=0 adc=8591 adcm=2158 adcn=0 gl=0 +[RX] 2026-10-27T01:50:10.923+08:00 [PROF2] t=9052 defd=131042 defs=35862 netp=2984 netn=0 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:12.325+08:00 [2026-10-26 17:50:11][ADC_TASK] frames=10001 idle=0 skip=38 seq=10006 frst_err=0 ring=9963 adc1_rc=0 adc1_err=0 adc1_seq=10004 adc1_gap=40 adc1_hw=0 tgap=1 +[RX] 2026-10-27T01:50:12.335+08:00 [2026-10-26 17:50:11][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:12.345+08:00 [2026-10-26 17:50:11][ADC_TASK] phasor(hb) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:12.356+08:00 [2026-10-26 17:50:11][ADC_TASK] phasor(hb) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:12.356+08:00 [2026-10-26 17:50:11][ADC_TASK] phasor(hb) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:12.366+08:00 [2026-10-26 17:50:11][ADC_TASK] phasor(hb) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:12.376+08:00 [2026-10-26 17:50:11][ADC_TASK] freq(hb): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:50:12.376+08:00 [2026-10-26 17:50:11][ADC_TASK] cal: ua_mv=1743 un_mv=1747 ia_mv=1747 vl=0x00 cl=0xe6 rail=0x000 edge=0x000 +[RX] 2026-10-27T01:50:12.387+08:00 [2026-10-26 17:50:11][ADC_TASK] meas: seq=50 v=1 ua_mv=0 un_mv=0 ia_mv=0 f=0 fv=0 +[RX] 2026-10-27T01:50:12.946+08:00 [PROF] t=11083 uic=708 uip=78645 uipn=10838 uil=10940 uiw=12578 uis=1272 uisn=0 adc=10621 adcm=2879 adcn=0 gl=0 +[RX] 2026-10-27T01:50:12.956+08:00 [PROF2] t=11083 defd=131042 defs=35862 netp=4016 netn=0 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:14.968+08:00 [PROF] t=13101 uic=890 uip=78645 uipn=9838 uil=10999 uiw=12578 uis=1272 uisn=0 adc=12639 adcm=2879 adcn=0 gl=0 +[RX] 2026-10-27T01:50:14.978+08:00 [PROF2] t=13101 defd=131042 defs=35862 netp=4016 netn=0 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:16.982+08:00 [PROF] t=15119 uic=1072 uip=78645 uipn=9838 uil=10897 uiw=12578 uis=1272 uisn=0 adc=14657 adcm=2879 adcn=0 gl=0 +[RX] 2026-10-27T01:50:16.992+08:00 [PROF2] t=15119 defd=131042 defs=35862 netp=4016 netn=0 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:19.002+08:00 [PROF] t=17137 uic=1254 uip=78645 uipn=9838 uil=10998 uiw=12578 uis=1272 uisn=0 adc=16675 adcm=2879 adcn=0 gl=0 +[RX] 2026-10-27T01:50:19.013+08:00 [PROF2] t=17137 defd=131042 defs=35862 netp=4016 netn=0 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:21.024+08:00 [PROF] t=19155 uic=1436 uip=78645 uipn=9838 uil=11000 uiw=12578 uis=1272 uisn=0 adc=18693 adcm=2879 adcn=0 gl=0 +[RX] 2026-10-27T01:50:21.024+08:00 [PROF2] t=19155 defd=131042 defs=35862 netp=4016 netn=0 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:22.332+08:00 [2026-10-26 17:50:21][ADC_TASK] frames=20000 idle=0 skip=39 seq=20006 frst_err=0 ring=19961 adc1_rc=0 adc1_err=0 adc1_seq=20004 adc1_gap=42 adc1_hw=0 tgap=2 +[RX] 2026-10-27T01:50:22.342+08:00 [2026-10-26 17:50:21][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:22.342+08:00 [2026-10-26 17:50:21][ADC_TASK] phasor(hb) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:22.352+08:00 [2026-10-26 17:50:21][ADC_TASK] phasor(hb) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:22.363+08:00 [2026-10-26 17:50:21][ADC_TASK] phasor(hb) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:22.363+08:00 [2026-10-26 17:50:21][ADC_TASK] phasor(hb) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:50:22.373+08:00 [2026-10-26 17:50:21][ADC_TASK] freq(hb): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:50:22.383+08:00 [2026-10-26 17:50:21][ADC_TASK] cal: ua_mv=1743 un_mv=1747 ia_mv=1747 vl=0x00 cl=0xe6 rail=0x000 edge=0x000 +[RX] 2026-10-27T01:50:22.393+08:00 [2026-10-26 17:50:21][ADC_TASK] meas: seq=100 v=1 ua_mv=0 un_mv=0 ia_mv=0 f=0 fv=0 +[RX] 2026-10-27T01:50:23.045+08:00 [PROF] t=21184 uic=1614 uip=78645 uipn=838 uil=11000 uiw=12578 uis=1272 uisn=575 adc=20721 adcm=2899 adcn=0 gl=0 +[RX] 2026-10-27T01:50:23.055+08:00 [PROF2] t=21184 defd=131042 defs=35862 netp=4016 netn=0 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:25.066+08:00 [PROF] t=23202 uic=1795 uip=78645 uipn=9846 uil=10999 uiw=18703 uis=18441 uisn=0 adc=22739 adcm=2899 adcn=0 gl=0 +[RX] 2026-10-27T01:50:25.077+08:00 [PROF2] t=23202 defd=131042 defs=35862 netp=4016 netn=0 adcp=11 adcq=0 gl=0 +[RX] 2026-10-27T01:50:27.079+08:00 [PROF] t=25220 uic=1977 uip=78645 uipn=9839 uil=10998 uiw=18703 uis=18441 uisn=0 adc=24757 adcm=2899 adcn=0 gl=0 +[RX] 2026-10-27T01:50:27.089+08:00 [PROF2] t=25220 defd=131042 defs=35862 netp=4016 netn=0 adcp=11 adcq=0 gl=0 + +===== boot_r2_gen274 (serial gen=274, 155 raw lines, reset-only) ===== +[RX] 2026-10-27T01:55:41.740+08:00 [----/--/-- --:--:--][APP] boot: syslog init OK +[RX] 2026-10-27T01:55:41.750+08:00 [----/--/-- --:--:--][APP] fw build: Oct 26 2026 22:52:09 suite=NONE dstr=off +[RX] 2026-10-27T01:55:41.750+08:00 [----/--/-- --:--:--][APP] reset cause: software (NVIC_SystemReset) (CSR=0x14000000) +[RX] 2026-10-27T01:55:41.761+08:00 PREVRUN seg=2 seq=2160943657 t=339511 +[RX] 2026-10-27T01:55:41.761+08:00 TICKRUN uw=8 n=8 duw=4294627793 +[RX] 2026-10-27T01:55:41.771+08:00 [----/--/-- --:--:--][RTC] sd2506_init: OK +[RX] 2026-10-27T01:55:41.771+08:00 [----/--/-- --:--:--][APP] SD2506 init: OK (ret=0) +[RX] 2026-10-27T01:55:41.782+08:00 [2026-10-26 17:55:40][CLK] sys_clock_init: RTC initial time 2026-10-26 17:55:40 +[RX] 2026-10-27T01:55:41.782+08:00 [2026-10-26 17:55:40][CLK] sys_clock_init: wall clock base = unix 1793037340, base_tick=138 +[RX] 2026-10-27T01:55:41.793+08:00 [2026-10-26 17:55:40][APP] RS485 init: OK (UART4, DE=PA15) +[RX] 2026-10-27T01:55:41.815+08:00 [2026-10-26 17:55:40][NAND] Resetting NAND... +[RX] 2026-10-27T01:55:41.825+08:00 [2026-10-26 17:55:40][NAND] Reading NAND ID... +[RX] 2026-10-27T01:55:41.836+08:00 [2026-10-26 17:55:40][NAND] NAND ID: MID=0xC8, DID=0x52 +[RX] 2026-10-27T01:55:41.836+08:00 [2026-10-26 17:55:40][NAND] Scanning bad blocks... +[RX] 2026-10-27T01:55:41.973+08:00 [2026-10-26 17:55:40][NAND] BBT scan: 0 bad blocks found +[RX] 2026-10-27T01:55:41.973+08:00 [2026-10-26 17:55:40][NAND] Enabling ECC... +[RX] 2026-10-27T01:55:41.984+08:00 [2026-10-26 17:55:40][NAND] Unlocking block protection... +[RX] 2026-10-27T01:55:41.984+08:00 [2026-10-26 17:55:40][NAND] Locating BBT pool... +[RX] 2026-10-27T01:55:41.984+08:00 [2026-10-26 17:55:40][NAND] Loading persisted BBT... +[RX] 2026-10-27T01:55:41.994+08:00 [2026-10-26 17:55:40][NAND] NAND init OK +[RX] 2026-10-27T01:55:41.994+08:00 [2026-10-26 17:55:40][APP] NAND init: OK +[RX] 2026-10-27T01:55:42.005+08:00 [2026-10-26 17:55:40][ADC] Init OK +[RX] 2026-10-27T01:55:42.005+08:00 [2026-10-26 17:55:40][APP] ADC init: OK +[RX] 2026-10-27T01:55:42.015+08:00 [2026-10-26 17:55:40][APP] ADC input layer init: OK +[RX] 2026-10-27T01:55:42.015+08:00 [2026-10-26 17:55:40][APP] phasor layer init: OK (inst=5) +[RX] 2026-10-27T01:55:42.015+08:00 [2026-10-26 17:55:40][APP] freq layer init: OK +[RX] 2026-10-27T01:55:42.026+08:00 [2026-10-26 17:55:40][CFG] register: section 'adc_cal' (9 keys) +[RX] 2026-10-27T01:55:42.036+08:00 [2026-10-26 17:55:40][CFG] register: section 'adc_cal_ofs' (8 keys) +[RX] 2026-10-27T01:55:42.036+08:00 [2026-10-26 17:55:40][APP] adc cal init: OK (k_q16 tpafe=10000000 stm32=52800000) +[RX] 2026-10-27T01:55:42.047+08:00 [2026-10-26 17:55:40][CFG] register: section 'run_par' (9 keys) +[RX] 2026-10-27T01:55:42.047+08:00 [2026-10-26 17:55:40][APP] run par init: OK (db9 k/b via adc_cal, evt=1<<8) +[RX] 2026-10-27T01:55:42.057+08:00 [2026-10-26 17:55:40][CFG] register: section 'comm' (2 keys) +[RX] 2026-10-27T01:55:42.068+08:00 [2026-10-26 17:55:40][APP] comm init: OK (ca=1 port=2404) +[RX] 2026-10-27T01:55:42.068+08:00 [2026-10-26 17:55:40][APP] protection init: OK (set=40 elm=9) +[RX] 2026-10-27T01:55:42.078+08:00 [2026-10-26 17:55:40][APP] SD2506 ID: 2512153425482405 +[RX] 2026-10-27T01:55:42.078+08:00 [2026-10-26 17:55:40][APP] SD2506 time: 2026-10-26 17:55:41 (week 1) +[RX] 2026-10-27T01:55:42.090+08:00 [2026-10-26 17:55:40][APP] SD2506 temp: 25 C +[RX] 2026-10-27T01:55:42.090+08:00 [2026-10-26 17:55:40][APP] SD2506 battery: 3.12 V +[RX] 2026-10-27T01:55:42.100+08:00 [2026-10-26 17:55:40][APP] App init OK +[RX] 2026-10-27T01:55:42.100+08:00 [2026-10-26 17:55:40][NAND_FTL] Initializing NAND FTL... +[RX] 2026-10-27T01:55:42.132+08:00 [2026-10-26 17:55:40][PROT] uncalibrated -> protection blocked (UA/UN/IA VALID not all set) +[RX] 2026-10-27T01:55:42.204+08:00 [2026-10-26 17:55:40][NAND_FTL] Map resumed: 14094/97504 sectors used +[RX] 2026-10-27T01:55:42.204+08:00 [2026-10-26 17:55:40][NAND_FTL] Map head=50352 tail=3607 epoch=7 +[RX] 2026-10-27T01:55:42.215+08:00 [2026-10-26 17:55:40][NAND_FTL] NAND FTL ready (capacity: 97504 pages = 190 MB) +[RX] 2026-10-27T01:55:42.298+08:00 [2026-10-26 17:55:40] [FS] FATFS mounted +[RX] 2026-10-27T01:55:42.350+08:00 [2026-10-26 17:55:40][SYSLOG] runlog boot entry: reboot +[RX] 2026-10-27T01:55:42.350+08:00 [2026-10-26 17:55:40][CFG] register: section 'network' (4 keys) +[RX] 2026-10-27T01:55:42.360+08:00 [2026-10-26 17:55:40][CFG] register: section 'ftp' (3 keys) +[RX] 2026-10-27T01:55:42.371+08:00 [2026-10-26 17:55:40][CFG] load: OK (957B, heap free 16552B) +[RX] 2026-10-27T01:55:42.371+08:00 [2026-10-26 17:55:40][NET_CFG] load: OK ip=192.168.1.100 +[RX] 2026-10-27T01:55:42.381+08:00 [2026-10-26 17:55:40] [CFG] prot set loaded (/prot_set.bin) +[RX] 2026-10-27T01:55:42.402+08:00 [2026-10-26 17:55:40][ADC_TASK] first: UA=11427 UB=1076 UC=940 UN=11454 IA=11451 IB=1050 IC=1044 IN=960 T=1010 +[RX] 2026-10-27T01:55:42.412+08:00 [2026-10-26 17:55:40][ADC_TASK] phasor(first) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:55:42.422+08:00 [2026-10-26 17:55:40][ADC_TASK] phasor(first) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:55:42.433+08:00 [2026-10-26 17:55:40][ADC_TASK] phasor(first) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:55:42.433+08:00 [2026-10-26 17:55:40][ADC_TASK] phasor(first) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:55:42.443+08:00 [2026-10-26 17:55:40][ADC_TASK] phasor(first) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:55:42.454+08:00 [2026-10-26 17:55:40][ADC_TASK] freq(first): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:55:42.454+08:00 [2026-10-26 17:55:40][NET_TASK] === Network Init === +[RX] 2026-10-27T01:55:42.464+08:00 [2026-10-26 17:55:40][PROT] protect task start: cycle=20ms elm=9 +[RX] 2026-10-27T01:55:42.464+08:00 [2026-10-26 17:55:40][NET] ch395f ver=0x4A fun_para=0x08 +[RX] 2026-10-27T01:55:42.474+08:00 MISS start snap=0x000001E7 req=0x000001F7 t=830 +[RX] 2026-10-27T01:55:42.474+08:00 [2026-10-26 17:55:40][WD] [WD] armed: timeout ~2498ms (worst ~1701ms), miss_tol=800ms +[RX] 2026-10-27T01:55:42.526+08:00 [2026-10-26 17:55:40][NET_TASK] net init: OK +[RX] 2026-10-27T01:55:42.526+08:00 [2026-10-26 17:55:40][NET_TASK] MAC: 3C:AB:72:53:2B:12 +[RX] 2026-10-27T01:55:42.526+08:00 [2026-10-26 17:55:40][NET_TASK] IP_INF: IP=192.168.1.100 GW=192.168.1.1 MASK=255.255.255.0 +[RX] 2026-10-27T01:55:42.536+08:00 [2026-10-26 17:55:40][UI_TASK] UI task: started, wait net ready +[RX] 2026-10-27T01:55:44.437+08:00 [2026-10-26 17:55:42][NET_TASK] PHY: 100M FULL +[RX] 2026-10-27T01:55:44.458+08:00 [2026-10-26 17:55:42][NET_TASK] netTask: started (single-socket mode) +[RX] 2026-10-27T01:55:44.489+08:00 [2026-10-26 17:55:42] [FTP] using factory default password +[RX] 2026-10-27T01:55:44.520+08:00 [2026-10-26 17:55:42][TIME_SYNC] time_sync: TCP listen on :8888 (sock=0) +[RX] 2026-10-27T01:55:44.551+08:00 [2026-10-26 17:55:42][I104] i104: listening on 2404 +[RX] 2026-10-27T01:55:44.562+08:00 MISS start snap=0x000001E7 req=0x000001F7 t=2919 +[RX] 2026-10-27T01:55:44.562+08:00 [PROF] t=2924 uic=0 uip=0 uipn=0 uil=0 uiw=0 uis=0 uisn=0 adc=2464 adcm=2238 adcn=0 gl=0 +[RX] 2026-10-27T01:55:44.572+08:00 [PROF2] t=2924 defd=130740 defs=37616 netp=2013 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:55:44.583+08:00 [2026-10-26 17:55:42] [FTP] waiting for connection... +[RX] 2026-10-27T01:55:44.583+08:00 [2026-10-26 17:55:42][UI_TASK] UI task: net ready, init port +[RX] 2026-10-27T01:55:44.593+08:00 [2026-10-26 17:55:42][UI_TASK] UI task: ui_port_init enter +[RX] 2026-10-27T01:55:44.603+08:00 [2026-10-26 17:55:42][UI_PORT] theme: mono dark_bg=true applied +[RX] 2026-10-27T01:55:44.603+08:00 [2026-10-26 17:55:42][UI_TASK] UI port init: OK +[RX] 2026-10-27T01:55:44.614+08:00 [2026-10-26 17:55:42][UI_TASK] UI task: ui_menu_init enter +[RX] 2026-10-27T01:55:44.614+08:00 [2026-10-26 17:55:42][UI_MENU] menu build start: total=15136 free=12692 big=12692 +[RX] 2026-10-27T01:55:44.624+08:00 [2026-10-26 17:55:42][UI_MENU_VIEW] view init: root frame w=66 h=107 +[RX] 2026-10-27T01:55:44.635+08:00 [2026-10-26 17:55:42][UI_MENU] menu build done: total=15020 free=11828 big=11816 used=3192 +[RX] 2026-10-27T01:55:44.645+08:00 [2026-10-26 17:55:42][UI_TASK] UI menu init: OK +[RX] 2026-10-27T01:55:44.645+08:00 [2026-10-26 17:55:42][UI_STANDBY] standby: ready (idle=60000ms) +[RX] 2026-10-27T01:55:44.655+08:00 [2026-10-26 17:55:42][UI_TASK] UI standby: ready (idle=60s) +[RX] 2026-10-27T01:55:44.707+08:00 [2026-10-26 17:55:42][UI_TASK] UI net sink: started (port 7003) +[RX] 2026-10-27T01:55:46.674+08:00 [PROF] t=5015 uic=176 uip=22442 uipn=1839 uil=10999 uiw=12534 uis=1245 uisn=0 adc=4554 adcm=2238 adcn=0 gl=0 +[RX] 2026-10-27T01:55:46.674+08:00 [PROF2] t=5015 defd=130740 defs=37616 netp=3983 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:55:47.126+08:00 [2026-10-26 17:55:45] [STACK] default peak_used=2160/5120 free_min=2960 (57%) +[RX] 2026-10-27T01:55:47.136+08:00 [2026-10-26 17:55:45] [STACK] net peak_used=1116/3840 free_min=2724 (70%) +[RX] 2026-10-27T01:55:47.136+08:00 [2026-10-26 17:55:45] [STACK] ftp peak_used=748/4096 free_min=3348 (81%) +[RX] 2026-10-27T01:55:47.147+08:00 [2026-10-26 17:55:45] [STACK] ui peak_used=4188/16384 free_min=12196 (74%) +[RX] 2026-10-27T01:55:47.157+08:00 [2026-10-26 17:55:45] [STACK] timesync peak_used=616/2560 free_min=1944 (75%) +[RX] 2026-10-27T01:55:47.157+08:00 [2026-10-26 17:55:45] [STACK] adc peak_used=920/2560 free_min=1640 (64%) +[RX] 2026-10-27T01:55:47.167+08:00 [2026-10-26 17:55:45] [STACK] iec104 peak_used=540/2560 free_min=2020 (78%) +[RX] 2026-10-27T01:55:47.177+08:00 [2026-10-26 17:55:45] [STACK] protect peak_used=492/2048 free_min=1556 (75%) +[RX] 2026-10-27T01:55:47.177+08:00 [2026-10-26 17:55:45] [STACK] heap free=15624 min_ever=8464 +[RX] 2026-10-27T01:55:48.687+08:00 [PROF] t=7044 uic=354 uip=72586 uipn=3822 uil=10909 uiw=12534 uis=1245 uisn=0 adc=6583 adcm=2238 adcn=0 gl=0 +[RX] 2026-10-27T01:55:48.697+08:00 [PROF2] t=7044 defd=130740 defs=37616 netp=3983 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:55:50.701+08:00 [PROF] t=9062 uic=536 uip=72586 uipn=9839 uil=10999 uiw=12534 uis=1245 uisn=0 adc=8601 adcm=2238 adcn=0 gl=0 +[RX] 2026-10-27T01:55:50.712+08:00 [PROF2] t=9062 defd=130740 defs=37616 netp=3983 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:55:52.106+08:00 [2026-10-26 17:55:50][ADC_TASK] frames=10001 idle=0 skip=39 seq=10006 frst_err=0 ring=9962 adc1_rc=0 adc1_err=0 adc1_seq=10004 adc1_gap=41 adc1_hw=0 tgap=1 +[RX] 2026-10-27T01:55:52.117+08:00 [2026-10-26 17:55:50][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:55:52.127+08:00 [2026-10-26 17:55:50][ADC_TASK] phasor(hb) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:55:52.127+08:00 [2026-10-26 17:55:50][ADC_TASK] phasor(hb) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:55:52.138+08:00 [2026-10-26 17:55:50][ADC_TASK] phasor(hb) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:55:52.148+08:00 [2026-10-26 17:55:50][ADC_TASK] phasor(hb) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:55:52.158+08:00 [2026-10-26 17:55:50][ADC_TASK] freq(hb): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:55:52.158+08:00 [2026-10-26 17:55:50][ADC_TASK] cal: ua_mv=1743 un_mv=1747 ia_mv=1747 vl=0x00 cl=0xe6 rail=0x000 edge=0x000 +[RX] 2026-10-27T01:55:52.168+08:00 [2026-10-26 17:55:50][ADC_TASK] meas: seq=49 v=1 ua_mv=0 un_mv=0 ia_mv=0 f=0 fv=0 +[RX] 2026-10-27T01:55:52.726+08:00 [PROF] t=11083 uic=712 uip=79728 uipn=9837 uil=11000 uiw=12534 uis=1245 uisn=0 adc=10621 adcm=2825 adcn=0 gl=0 +[RX] 2026-10-27T01:55:52.736+08:00 [PROF2] t=11083 defd=130740 defs=37616 netp=5009 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:55:53.199+08:00 [2026-10-26 17:55:51] [STACK] default peak_used=2160/5120 free_min=2960 (57%) +[RX] 2026-10-27T01:55:53.199+08:00 [2026-10-26 17:55:51] [STACK] net peak_used=1116/3840 free_min=2724 (70%) +[RX] 2026-10-27T01:55:53.210+08:00 [2026-10-26 17:55:51] [STACK] ftp peak_used=748/4096 free_min=3348 (81%) +[RX] 2026-10-27T01:55:53.220+08:00 [2026-10-26 17:55:51] [STACK] ui peak_used=4188/16384 free_min=12196 (74%) +[RX] 2026-10-27T01:55:53.220+08:00 [2026-10-26 17:55:51] [STACK] timesync peak_used=616/2560 free_min=1944 (75%) +[RX] 2026-10-27T01:55:53.230+08:00 [2026-10-26 17:55:51] [STACK] adc peak_used=1000/2560 free_min=1560 (60%) +[RX] 2026-10-27T01:55:53.241+08:00 [2026-10-26 17:55:51] [STACK] iec104 peak_used=540/2560 free_min=2020 (78%) +[RX] 2026-10-27T01:55:53.241+08:00 [2026-10-26 17:55:51] [STACK] protect peak_used=492/2048 free_min=1556 (75%) +[RX] 2026-10-27T01:55:53.251+08:00 [2026-10-26 17:55:51] [STACK] heap free=15624 min_ever=8464 +[RX] 2026-10-27T01:55:54.751+08:00 [PROF] t=13113 uic=890 uip=79728 uipn=2838 uil=10999 uiw=12534 uis=1245 uisn=0 adc=12651 adcm=2825 adcn=0 gl=0 +[RX] 2026-10-27T01:55:54.762+08:00 [PROF2] t=13113 defd=130740 defs=37616 netp=5009 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:55:55.229+08:00 [2026-10-26 17:55:53] [STACK] default peak_used=2160/5120 free_min=2960 (57%) +[RX] 2026-10-27T01:55:55.229+08:00 [2026-10-26 17:55:53] [STACK] net peak_used=1116/3840 free_min=2724 (70%) +[RX] 2026-10-27T01:55:55.240+08:00 [2026-10-26 17:55:53] [STACK] ftp peak_used=764/4096 free_min=3332 (81%) +[RX] 2026-10-27T01:55:55.250+08:00 [2026-10-26 17:55:53] [STACK] ui peak_used=4188/16384 free_min=12196 (74%) +[RX] 2026-10-27T01:55:55.250+08:00 [2026-10-26 17:55:53] [STACK] timesync peak_used=616/2560 free_min=1944 (75%) +[RX] 2026-10-27T01:55:55.261+08:00 [2026-10-26 17:55:53] [STACK] adc peak_used=1000/2560 free_min=1560 (60%) +[RX] 2026-10-27T01:55:55.261+08:00 [2026-10-26 17:55:53] [STACK] iec104 peak_used=540/2560 free_min=2020 (78%) +[RX] 2026-10-27T01:55:55.271+08:00 [2026-10-26 17:55:53] [STACK] protect peak_used=492/2048 free_min=1556 (75%) +[RX] 2026-10-27T01:55:55.282+08:00 [2026-10-26 17:55:53] [STACK] heap free=15624 min_ever=8464 +[RX] 2026-10-27T01:55:56.788+08:00 [PROF] t=15143 uic=1068 uip=79728 uipn=2839 uil=10999 uiw=12534 uis=1245 uisn=0 adc=14681 adcm=2825 adcn=0 gl=0 +[RX] 2026-10-27T01:55:56.798+08:00 [PROF2] t=15143 defd=130740 defs=37616 netp=5009 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:55:58.804+08:00 [PROF] t=17161 uic=1250 uip=79728 uipn=9839 uil=11000 uiw=12534 uis=1245 uisn=0 adc=16699 adcm=2825 adcn=0 gl=0 +[RX] 2026-10-27T01:55:58.814+08:00 [PROF2] t=17161 defd=130740 defs=37616 netp=5009 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:56:00.825+08:00 [PROF] t=19179 uic=1432 uip=79728 uipn=9839 uil=10998 uiw=12534 uis=1245 uisn=0 adc=18717 adcm=2825 adcn=0 gl=0 +[RX] 2026-10-27T01:56:00.835+08:00 [PROF2] t=19179 defd=130740 defs=37616 netp=5009 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:56:02.104+08:00 [2026-10-26 17:56:00][ADC_TASK] frames=20000 idle=0 skip=47 seq=20006 frst_err=0 ring=19953 adc1_rc=0 adc1_err=0 adc1_seq=20004 adc1_gap=50 adc1_hw=0 tgap=2 +[RX] 2026-10-27T01:56:02.115+08:00 [2026-10-26 17:56:00][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:02.126+08:00 [2026-10-26 17:56:00][ADC_TASK] phasor(hb) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:02.126+08:00 [2026-10-26 17:56:00][ADC_TASK] phasor(hb) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:02.136+08:00 [2026-10-26 17:56:00][ADC_TASK] phasor(hb) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:02.147+08:00 [2026-10-26 17:56:00][ADC_TASK] phasor(hb) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:02.157+08:00 [2026-10-26 17:56:00][ADC_TASK] freq(hb): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:56:02.157+08:00 [2026-10-26 17:56:00][ADC_TASK] cal: ua_mv=1743 un_mv=1747 ia_mv=1747 vl=0x00 cl=0xe6 rail=0x000 edge=0x000 +[RX] 2026-10-27T01:56:02.167+08:00 [2026-10-26 17:56:00][ADC_TASK] meas: seq=99 v=1 ua_mv=0 un_mv=0 ia_mv=0 f=0 fv=0 +[RX] 2026-10-27T01:56:02.825+08:00 [PROF] t=21183 uic=1607 uip=83612 uipn=847 uil=10998 uiw=12534 uis=1245 uisn=834 adc=20721 adcm=2825 adcn=0 gl=0 +[RX] 2026-10-27T01:56:02.835+08:00 [PROF2] t=21183 defd=130740 defs=37616 netp=5983 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:56:04.844+08:00 [PROF] t=23201 uic=1788 uip=83612 uipn=9839 uil=10999 uiw=18678 uis=18664 uisn=0 adc=22738 adcm=2825 adcn=0 gl=0 +[RX] 2026-10-27T01:56:04.854+08:00 [PROF2] t=23201 defd=130740 defs=37616 netp=5983 netn=0 adcp=9 adcq=0 gl=0 +[RX] 2026-10-27T01:56:06.865+08:00 [PROF] t=25219 uic=1970 uip=83612 uipn=9837 uil=11000 uiw=18678 uis=18664 uisn=0 adc=24756 adcm=2825 adcn=0 gl=0 +[RX] 2026-10-27T01:56:06.875+08:00 [PROF2] t=25219 defd=130740 defs=37616 netp=5983 netn=0 adcp=9 adcq=0 gl=0 + +===== boot_r3_gen275 (serial gen=275, 146 raw lines, reset-only) ===== +[RX] 2026-10-27T01:56:08.003+08:00 [----/--/-- --:--:--][APP] boot: syslog init OK +[RX] 2026-10-27T01:56:08.003+08:00 [----/--/-- --:--:--][APP] fw build: Oct 26 2026 22:52:09 suite=NONE dstr=off +[RX] 2026-10-27T01:56:08.016+08:00 [----/--/-- --:--:--][APP] reset cause: software (NVIC_SystemReset) (CSR=0x14000000) +[RX] 2026-10-27T01:56:08.016+08:00 PREVRUN seg=2 seq=2160947305 t=25937 +[RX] 2026-10-27T01:56:08.016+08:00 TICKRUN uw=14 n=14 duw=4294941373 +[RX] 2026-10-27T01:56:08.029+08:00 [----/--/-- --:--:--][RTC] sd2506_init: OK +[RX] 2026-10-27T01:56:08.029+08:00 [----/--/-- --:--:--][APP] SD2506 init: OK (ret=0) +[RX] 2026-10-27T01:56:08.043+08:00 [2026-10-26 17:56:07][CLK] sys_clock_init: RTC initial time 2026-10-26 17:56:07 +[RX] 2026-10-27T01:56:08.043+08:00 [2026-10-26 17:56:07][CLK] sys_clock_init: wall clock base = unix 1793037367, base_tick=138 +[RX] 2026-10-27T01:56:08.055+08:00 [2026-10-26 17:56:07][APP] RS485 init: OK (UART4, DE=PA15) +[RX] 2026-10-27T01:56:08.069+08:00 [2026-10-26 17:56:07][NAND] Resetting NAND... +[RX] 2026-10-27T01:56:08.080+08:00 [2026-10-26 17:56:07][NAND] Reading NAND ID... +[RX] 2026-10-27T01:56:08.080+08:00 [2026-10-26 17:56:07][NAND] NAND ID: MID=0xC8, DID=0x52 +[RX] 2026-10-27T01:56:08.093+08:00 [2026-10-26 17:56:07][NAND] Scanning bad blocks... +[RX] 2026-10-27T01:56:08.234+08:00 [2026-10-26 17:56:07][NAND] BBT scan: 0 bad blocks found +[RX] 2026-10-27T01:56:08.234+08:00 [2026-10-26 17:56:07][NAND] Enabling ECC... +[RX] 2026-10-27T01:56:08.234+08:00 [2026-10-26 17:56:07][NAND] Unlocking block protection... +[RX] 2026-10-27T01:56:08.234+08:00 [2026-10-26 17:56:07][NAND] Locating BBT pool... +[RX] 2026-10-27T01:56:08.245+08:00 [2026-10-26 17:56:07][NAND] Loading persisted BBT... +[RX] 2026-10-27T01:56:08.245+08:00 [2026-10-26 17:56:07][NAND] NAND init OK +[RX] 2026-10-27T01:56:08.260+08:00 [2026-10-26 17:56:07][APP] NAND init: OK +[RX] 2026-10-27T01:56:08.260+08:00 [2026-10-26 17:56:07][ADC] Init OK +[RX] 2026-10-27T01:56:08.260+08:00 [2026-10-26 17:56:07][APP] ADC init: OK +[RX] 2026-10-27T01:56:08.260+08:00 [2026-10-26 17:56:07][APP] ADC input layer init: OK +[RX] 2026-10-27T01:56:08.279+08:00 [2026-10-26 17:56:07][APP] phasor layer init: OK (inst=5) +[RX] 2026-10-27T01:56:08.279+08:00 [2026-10-26 17:56:07][APP] freq layer init: OK +[RX] 2026-10-27T01:56:08.279+08:00 [2026-10-26 17:56:07][CFG] register: section 'adc_cal' (9 keys) +[RX] 2026-10-27T01:56:08.295+08:00 [2026-10-26 17:56:07][CFG] register: section 'adc_cal_ofs' (8 keys) +[RX] 2026-10-27T01:56:08.295+08:00 [2026-10-26 17:56:07][APP] adc cal init: OK (k_q16 tpafe=10000000 stm32=52800000) +[RX] 2026-10-27T01:56:08.295+08:00 [2026-10-26 17:56:07][CFG] register: section 'run_par' (9 keys) +[RX] 2026-10-27T01:56:08.312+08:00 [2026-10-26 17:56:07][APP] run par init: OK (db9 k/b via adc_cal, evt=1<<8) +[RX] 2026-10-27T01:56:08.312+08:00 [2026-10-26 17:56:07][CFG] register: section 'comm' (2 keys) +[RX] 2026-10-27T01:56:08.312+08:00 [2026-10-26 17:56:07][APP] comm init: OK (ca=1 port=2404) +[RX] 2026-10-27T01:56:08.323+08:00 [2026-10-26 17:56:07][APP] protection init: OK (set=40 elm=9) +[RX] 2026-10-27T01:56:08.334+08:00 [2026-10-26 17:56:07][APP] SD2506 ID: 2512153425482405 +[RX] 2026-10-27T01:56:08.334+08:00 [2026-10-26 17:56:07][APP] SD2506 time: 2026-10-26 17:56:07 (week 1) +[RX] 2026-10-27T01:56:08.350+08:00 [2026-10-26 17:56:07][APP] SD2506 temp: 25 C +[RX] 2026-10-27T01:56:08.350+08:00 [2026-10-26 17:56:07][APP] SD2506 battery: 3.12 V +[RX] 2026-10-27T01:56:08.350+08:00 [2026-10-26 17:56:07][APP] App init OK +[RX] 2026-10-27T01:56:08.365+08:00 [2026-10-26 17:56:07][NAND_FTL] Initializing NAND FTL... +[RX] 2026-10-27T01:56:08.377+08:00 [2026-10-26 17:56:07][PROT] uncalibrated -> protection blocked (UA/UN/IA VALID not all set) +[RX] 2026-10-27T01:56:08.456+08:00 [2026-10-26 17:56:07][NAND_FTL] Map resumed: 14094/97504 sectors used +[RX] 2026-10-27T01:56:08.456+08:00 [2026-10-26 17:56:07][NAND_FTL] Map head=50416 tail=3669 epoch=7 +[RX] 2026-10-27T01:56:08.467+08:00 [2026-10-26 17:56:07][NAND_FTL] NAND FTL ready (capacity: 97504 pages = 190 MB) +[RX] 2026-10-27T01:56:08.545+08:00 [2026-10-26 17:56:07] [FS] FATFS mounted +[RX] 2026-10-27T01:56:08.598+08:00 [2026-10-26 17:56:07][SYSLOG] runlog boot entry: reboot +[RX] 2026-10-27T01:56:08.609+08:00 [2026-10-26 17:56:07][CFG] register: section 'network' (4 keys) +[RX] 2026-10-27T01:56:08.609+08:00 [2026-10-26 17:56:07][CFG] register: section 'ftp' (3 keys) +[RX] 2026-10-27T01:56:08.619+08:00 [2026-10-26 17:56:07][CFG] load: OK (957B, heap free 16552B) +[RX] 2026-10-27T01:56:08.630+08:00 [2026-10-26 17:56:07][NET_CFG] load: OK ip=192.168.1.100 +[RX] 2026-10-27T01:56:08.640+08:00 [2026-10-26 17:56:07] [CFG] prot set loaded (/prot_set.bin) +[RX] 2026-10-27T01:56:08.662+08:00 [2026-10-26 17:56:07][ADC_TASK] first: UA=11428 UB=1060 UC=923 UN=11453 IA=11452 IB=1021 IC=1018 IN=967 T=975 +[RX] 2026-10-27T01:56:08.662+08:00 [2026-10-26 17:56:07][ADC_TASK] phasor(first) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:08.672+08:00 [2026-10-26 17:56:07][ADC_TASK] phasor(first) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:08.682+08:00 [2026-10-26 17:56:07][ADC_TASK] phasor(first) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:08.682+08:00 [2026-10-26 17:56:07][ADC_TASK] phasor(first) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:08.693+08:00 [2026-10-26 17:56:07][ADC_TASK] phasor(first) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:08.704+08:00 [2026-10-26 17:56:07][ADC_TASK] freq(first): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:56:08.704+08:00 [2026-10-26 17:56:07][NET_TASK] === Network Init === +[RX] 2026-10-27T01:56:08.714+08:00 [2026-10-26 17:56:07][PROT] protect task start: cycle=20ms elm=9 +[RX] 2026-10-27T01:56:08.714+08:00 [2026-10-26 17:56:07][NET] ch395f ver=0x4A fun_para=0x08 +[RX] 2026-10-27T01:56:08.725+08:00 MISS start snap=0x000001E7 req=0x000001F7 t=826 +[RX] 2026-10-27T01:56:08.725+08:00 [2026-10-26 17:56:07][WD] [WD] armed: timeout ~2498ms (worst ~1701ms), miss_tol=800ms +[RX] 2026-10-27T01:56:08.736+08:00 [2026-10-26 17:56:07][NET_TASK] net init: OK +[RX] 2026-10-27T01:56:08.777+08:00 [2026-10-26 17:56:07][NET_TASK] MAC: 3C:AB:72:53:2B:12 +[RX] 2026-10-27T01:56:08.777+08:00 [2026-10-26 17:56:07][NET_TASK] IP_INF: IP=192.168.1.100 GW=192.168.1.1 MASK=255.255.255.0 +[RX] 2026-10-27T01:56:08.788+08:00 [2026-10-26 17:56:07][UI_TASK] UI task: started, wait net ready +[RX] 2026-10-27T01:56:10.725+08:00 [2026-10-26 17:56:09][NET_TASK] PHY: 100M FULL +[RX] 2026-10-27T01:56:10.745+08:00 [2026-10-26 17:56:09][NET_TASK] netTask: started (single-socket mode) +[RX] 2026-10-27T01:56:10.776+08:00 [2026-10-26 17:56:09] [FTP] using factory default password +[RX] 2026-10-27T01:56:10.808+08:00 [2026-10-26 17:56:09][TIME_SYNC] time_sync: TCP listen on :8888 (sock=0) +[RX] 2026-10-27T01:56:10.839+08:00 [2026-10-26 17:56:09][I104] i104: listening on 2404 +[RX] 2026-10-27T01:56:10.849+08:00 [2026-10-26 17:56:09] [FTP] waiting for connection... +[RX] 2026-10-27T01:56:10.849+08:00 [2026-10-26 17:56:09][UI_TASK] UI task: net ready, init port +[RX] 2026-10-27T01:56:10.860+08:00 [2026-10-26 17:56:09][UI_TASK] UI task: ui_port_init enter +[RX] 2026-10-27T01:56:10.870+08:00 [2026-10-26 17:56:09][UI_PORT] theme: mono dark_bg=true applied +[RX] 2026-10-27T01:56:10.870+08:00 [2026-10-26 17:56:09][UI_TASK] UI port init: OK +[RX] 2026-10-27T01:56:10.880+08:00 [2026-10-26 17:56:09][UI_TASK] UI task: ui_menu_init enter +[RX] 2026-10-27T01:56:10.880+08:00 [2026-10-26 17:56:09][UI_MENU] menu build start: total=15136 free=12692 big=12692 +[RX] 2026-10-27T01:56:10.891+08:00 [2026-10-26 17:56:09][UI_MENU_VIEW] view init: root frame w=66 h=107 +[RX] 2026-10-27T01:56:10.901+08:00 [2026-10-26 17:56:09][UI_MENU] menu build done: total=15020 free=11828 big=11816 used=3192 +[RX] 2026-10-27T01:56:10.911+08:00 [2026-10-26 17:56:09][UI_TASK] UI menu init: OK +[RX] 2026-10-27T01:56:10.911+08:00 [2026-10-26 17:56:09][UI_STANDBY] standby: ready (idle=60000ms) +[RX] 2026-10-27T01:56:10.922+08:00 [2026-10-26 17:56:09][UI_TASK] UI standby: ready (idle=60s) +[RX] 2026-10-27T01:56:10.973+08:00 [2026-10-26 17:56:09][UI_TASK] UI net sink: started (port 7003) +[RX] 2026-10-27T01:56:10.973+08:00 MISS start snap=0x000001E7 req=0x000001F7 t=3078 +[RX] 2026-10-27T01:56:10.973+08:00 [PROF] t=3082 uic=0 uip=0 uipn=0 uil=0 uiw=0 uis=0 uisn=0 adc=2623 adcm=2157 adcn=0 gl=0 +[RX] 2026-10-27T01:56:10.984+08:00 [PROF2] t=3082 defd=131028 defs=35494 netp=2983 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:12.944+08:00 [PROF] t=5047 uic=176 uip=21700 uipn=2839 uil=10999 uiw=11793 uis=1284 uisn=0 adc=4587 adcm=2157 adcn=0 gl=0 +[RX] 2026-10-27T01:56:12.958+08:00 [PROF2] t=5047 defd=131028 defs=35494 netp=2983 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:13.371+08:00 [2026-10-26 17:56:12] [STACK] default peak_used=2160/5120 free_min=2960 (57%) +[RX] 2026-10-27T01:56:13.371+08:00 [2026-10-26 17:56:12] [STACK] net peak_used=1116/3840 free_min=2724 (70%) +[RX] 2026-10-27T01:56:13.371+08:00 [2026-10-26 17:56:12] [STACK] ftp peak_used=740/4096 free_min=3356 (81%) +[RX] 2026-10-27T01:56:13.382+08:00 [2026-10-26 17:56:12] [STACK] ui peak_used=4188/16384 free_min=12196 (74%) +[RX] 2026-10-27T01:56:13.394+08:00 [2026-10-26 17:56:12] [STACK] timesync peak_used=616/2560 free_min=1944 (75%) +[RX] 2026-10-27T01:56:13.394+08:00 [2026-10-26 17:56:12] [STACK] adc peak_used=1000/2560 free_min=1560 (60%) +[RX] 2026-10-27T01:56:13.407+08:00 [2026-10-26 17:56:12] [STACK] iec104 peak_used=540/2560 free_min=2020 (78%) +[RX] 2026-10-27T01:56:13.407+08:00 [2026-10-26 17:56:12] [STACK] protect peak_used=492/2048 free_min=1556 (75%) +[RX] 2026-10-27T01:56:13.418+08:00 [2026-10-26 17:56:12] [STACK] heap free=15624 min_ever=8464 +[RX] 2026-10-27T01:56:14.974+08:00 [PROF] t=7077 uic=354 uip=67687 uipn=8847 uil=10998 uiw=11793 uis=1284 uisn=0 adc=6617 adcm=2157 adcn=0 gl=0 +[RX] 2026-10-27T01:56:14.985+08:00 [PROF2] t=7077 defd=131028 defs=35494 netp=2983 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:16.989+08:00 [PROF] t=9095 uic=536 uip=67687 uipn=9838 uil=10999 uiw=11793 uis=1284 uisn=0 adc=8635 adcm=2157 adcn=0 gl=0 +[RX] 2026-10-27T01:56:16.999+08:00 [PROF2] t=9095 defd=131028 defs=35494 netp=2984 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:18.363+08:00 [2026-10-26 17:56:17][ADC_TASK] frames=10001 idle=0 skip=28 seq=10006 frst_err=0 ring=9973 adc1_rc=0 adc1_err=0 adc1_seq=10004 adc1_gap=30 adc1_hw=0 tgap=1 +[RX] 2026-10-27T01:56:18.373+08:00 [2026-10-26 17:56:17][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:18.384+08:00 [2026-10-26 17:56:17][ADC_TASK] phasor(hb) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:18.384+08:00 [2026-10-26 17:56:17][ADC_TASK] phasor(hb) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:18.394+08:00 [2026-10-26 17:56:17][ADC_TASK] phasor(hb) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:18.394+08:00 [2026-10-26 17:56:17][ADC_TASK] phasor(hb) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:18.404+08:00 [2026-10-26 17:56:17][ADC_TASK] freq(hb): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:56:18.414+08:00 [2026-10-26 17:56:17][ADC_TASK] cal: ua_mv=1743 un_mv=1747 ia_mv=1747 vl=0x00 cl=0xe6 rail=0x000 edge=0x000 +[RX] 2026-10-27T01:56:18.425+08:00 [2026-10-26 17:56:17][ADC_TASK] meas: seq=49 v=1 ua_mv=0 un_mv=0 ia_mv=0 f=0 fv=0 +[RX] 2026-10-27T01:56:19.026+08:00 [PROF] t=11132 uic=714 uip=78731 uipn=4838 uil=10999 uiw=11793 uis=1284 uisn=0 adc=10671 adcm=2822 adcn=0 gl=0 +[RX] 2026-10-27T01:56:19.036+08:00 [PROF2] t=11132 defd=131028 defs=35494 netp=4016 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:21.046+08:00 [PROF] t=13150 uic=896 uip=78731 uipn=9838 uil=11000 uiw=11793 uis=1284 uisn=0 adc=12689 adcm=2822 adcn=0 gl=0 +[RX] 2026-10-27T01:56:21.057+08:00 [PROF2] t=13150 defd=131028 defs=35494 netp=4016 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:23.064+08:00 [PROF] t=15168 uic=1078 uip=78731 uipn=9838 uil=10998 uiw=11793 uis=1284 uisn=0 adc=14707 adcm=2822 adcn=0 gl=0 +[RX] 2026-10-27T01:56:23.075+08:00 [PROF2] t=15168 defd=131028 defs=35494 netp=4016 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:25.087+08:00 [PROF] t=17186 uic=1260 uip=78731 uipn=9846 uil=11000 uiw=11793 uis=1284 uisn=0 adc=16725 adcm=2822 adcn=0 gl=0 +[RX] 2026-10-27T01:56:25.087+08:00 [PROF2] t=17186 defd=131028 defs=35494 netp=4016 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:27.103+08:00 [PROF] t=19204 uic=1442 uip=78731 uipn=8834 uil=11002 uiw=11793 uis=1284 uisn=0 adc=18743 adcm=2822 adcn=0 gl=0 +[RX] 2026-10-27T01:56:27.114+08:00 [PROF2] t=19204 defd=131028 defs=35494 netp=4016 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:28.363+08:00 [2026-10-26 17:56:27][ADC_TASK] frames=20000 idle=0 skip=31 seq=20006 frst_err=0 ring=19969 adc1_rc=0 adc1_err=0 adc1_seq=20004 adc1_gap=34 adc1_hw=0 tgap=2 +[RX] 2026-10-27T01:56:28.373+08:00 [2026-10-26 17:56:27][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:28.384+08:00 [2026-10-26 17:56:27][ADC_TASK] phasor(hb) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:28.384+08:00 [2026-10-26 17:56:27][ADC_TASK] phasor(hb) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:28.394+08:00 [2026-10-26 17:56:27][ADC_TASK] phasor(hb) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:28.394+08:00 [2026-10-26 17:56:27][ADC_TASK] phasor(hb) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:28.404+08:00 [2026-10-26 17:56:27][ADC_TASK] freq(hb): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:56:28.415+08:00 [2026-10-26 17:56:27][ADC_TASK] cal: ua_mv=1743 un_mv=1747 ia_mv=1747 vl=0x00 cl=0xe6 rail=0x000 edge=0x000 +[RX] 2026-10-27T01:56:28.426+08:00 [2026-10-26 17:56:27][ADC_TASK] meas: seq=99 v=1 ua_mv=0 un_mv=0 ia_mv=0 f=0 fv=0 +[RX] 2026-10-27T01:56:29.131+08:00 [PROF] t=21232 uic=1619 uip=79788 uipn=5837 uil=11000 uiw=11793 uis=1284 uisn=0 adc=20770 adcm=2831 adcn=0 gl=0 +[RX] 2026-10-27T01:56:29.142+08:00 [PROF2] t=21232 defd=131028 defs=35494 netp=4016 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:29.552+08:00 [2026-10-26 17:56:28] [STACK] default peak_used=2160/5120 free_min=2960 (57%) +[RX] 2026-10-27T01:56:29.552+08:00 [2026-10-26 17:56:28] [STACK] net peak_used=1116/3840 free_min=2724 (70%) +[RX] 2026-10-27T01:56:29.563+08:00 [2026-10-26 17:56:28] [STACK] ftp peak_used=740/4096 free_min=3356 (81%) +[RX] 2026-10-27T01:56:29.573+08:00 [2026-10-26 17:56:28] [STACK] ui peak_used=4188/16384 free_min=12196 (74%) +[RX] 2026-10-27T01:56:29.573+08:00 [2026-10-26 17:56:28] [STACK] timesync peak_used=616/2560 free_min=1944 (75%) +[RX] 2026-10-27T01:56:29.584+08:00 [2026-10-26 17:56:28] [STACK] adc peak_used=1000/2560 free_min=1560 (60%) +[RX] 2026-10-27T01:56:29.594+08:00 [2026-10-26 17:56:28] [STACK] iec104 peak_used=580/2560 free_min=1980 (77%) +[RX] 2026-10-27T01:56:29.594+08:00 [2026-10-26 17:56:28] [STACK] protect peak_used=492/2048 free_min=1556 (75%) +[RX] 2026-10-27T01:56:29.605+08:00 [2026-10-26 17:56:28] [STACK] heap free=15624 min_ever=8464 +[RX] 2026-10-27T01:56:31.156+08:00 [PROF] t=23262 uic=1797 uip=79788 uipn=9838 uil=11000 uiw=11793 uis=1284 uisn=0 adc=22800 adcm=2831 adcn=0 gl=0 +[RX] 2026-10-27T01:56:31.166+08:00 [PROF2] t=23262 defd=131028 defs=35494 netp=4016 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:33.181+08:00 [PROF] t=25280 uic=1979 uip=79788 uipn=9837 uil=11000 uiw=11793 uis=1284 uisn=0 adc=24818 adcm=2831 adcn=0 gl=0 +[RX] 2026-10-27T01:56:33.181+08:00 [PROF2] t=25280 defd=131028 defs=35494 netp=4016 netn=0 adcp=10 adcq=0 gl=0 + +===== boot_r4_gen276 (serial gen=276, 146 raw lines, reset-only) ===== +[RX] 2026-10-27T01:56:34.371+08:00 [----/--/-- --:--:--][APP] boot: syslog init OK +[RX] 2026-10-27T01:56:34.371+08:00 [----/--/-- --:--:--][APP] fw build: Oct 26 2026 22:52:09 suite=NONE dstr=off +[RX] 2026-10-27T01:56:34.392+08:00 [----/--/-- --:--:--][APP] reset cause: software (NVIC_SystemReset) (CSR=0x14000000) +[RX] 2026-10-27T01:56:34.392+08:00 PREVRUN seg=2 seq=2160950968 t=26048 +[RX] 2026-10-27T01:56:34.392+08:00 TICKRUN uw=5 n=5 duw=4294941253 +[RX] 2026-10-27T01:56:34.392+08:00 [----/--/-- --:--:--][RTC] sd2506_init: OK +[RX] 2026-10-27T01:56:34.392+08:00 [----/--/-- --:--:--][APP] SD2506 init: OK (ret=0) +[RX] 2026-10-27T01:56:34.412+08:00 [2026-10-26 17:56:33][CLK] sys_clock_init: RTC initial time 2026-10-26 17:56:33 +[RX] 2026-10-27T01:56:34.412+08:00 [2026-10-26 17:56:33][CLK] sys_clock_init: wall clock base = unix 1793037393, base_tick=139 +[RX] 2026-10-27T01:56:34.435+08:00 [2026-10-26 17:56:33][APP] RS485 init: OK (UART4, DE=PA15) +[RX] 2026-10-27T01:56:34.435+08:00 [2026-10-26 17:56:33][NAND] Resetting NAND... +[RX] 2026-10-27T01:56:34.452+08:00 [2026-10-26 17:56:33][NAND] Reading NAND ID... +[RX] 2026-10-27T01:56:34.452+08:00 [2026-10-26 17:56:33][NAND] NAND ID: MID=0xC8, DID=0x52 +[RX] 2026-10-27T01:56:34.469+08:00 [2026-10-26 17:56:33][NAND] Scanning bad blocks... +[RX] 2026-10-27T01:56:34.597+08:00 [2026-10-26 17:56:33][NAND] BBT scan: 0 bad blocks found +[RX] 2026-10-27T01:56:34.597+08:00 [2026-10-26 17:56:33][NAND] Enabling ECC... +[RX] 2026-10-27T01:56:34.597+08:00 [2026-10-26 17:56:33][NAND] Unlocking block protection... +[RX] 2026-10-27T01:56:34.608+08:00 [2026-10-26 17:56:33][NAND] Locating BBT pool... +[RX] 2026-10-27T01:56:34.608+08:00 [2026-10-26 17:56:33][NAND] Loading persisted BBT... +[RX] 2026-10-27T01:56:34.630+08:00 [2026-10-26 17:56:33][NAND] NAND init OK +[RX] 2026-10-27T01:56:34.630+08:00 [2026-10-26 17:56:33][APP] NAND init: OK +[RX] 2026-10-27T01:56:34.630+08:00 [2026-10-26 17:56:33][ADC] Init OK +[RX] 2026-10-27T01:56:34.630+08:00 [2026-10-26 17:56:33][APP] ADC init: OK +[RX] 2026-10-27T01:56:34.630+08:00 [2026-10-26 17:56:33][APP] ADC input layer init: OK +[RX] 2026-10-27T01:56:34.630+08:00 [2026-10-26 17:56:33][APP] phasor layer init: OK (inst=5) +[RX] 2026-10-27T01:56:34.643+08:00 [2026-10-26 17:56:33][APP] freq layer init: OK +[RX] 2026-10-27T01:56:34.653+08:00 [2026-10-26 17:56:33][CFG] register: section 'adc_cal' (9 keys) +[RX] 2026-10-27T01:56:34.653+08:00 [2026-10-26 17:56:33][CFG] register: section 'adc_cal_ofs' (8 keys) +[RX] 2026-10-27T01:56:34.669+08:00 [2026-10-26 17:56:33][APP] adc cal init: OK (k_q16 tpafe=10000000 stm32=52800000) +[RX] 2026-10-27T01:56:34.669+08:00 [2026-10-26 17:56:33][CFG] register: section 'run_par' (9 keys) +[RX] 2026-10-27T01:56:34.669+08:00 [2026-10-26 17:56:33][APP] run par init: OK (db9 k/b via adc_cal, evt=1<<8) +[RX] 2026-10-27T01:56:34.683+08:00 [2026-10-26 17:56:33][CFG] register: section 'comm' (2 keys) +[RX] 2026-10-27T01:56:34.683+08:00 [2026-10-26 17:56:33][APP] comm init: OK (ca=1 port=2404) +[RX] 2026-10-27T01:56:34.694+08:00 [2026-10-26 17:56:33][APP] protection init: OK (set=40 elm=9) +[RX] 2026-10-27T01:56:34.694+08:00 [2026-10-26 17:56:33][APP] SD2506 ID: 2512153425482405 +[RX] 2026-10-27T01:56:34.708+08:00 [2026-10-26 17:56:33][APP] SD2506 time: 2026-10-26 17:56:33 (week 1) +[RX] 2026-10-27T01:56:34.708+08:00 [2026-10-26 17:56:33][APP] SD2506 temp: 25 C +[RX] 2026-10-27T01:56:34.720+08:00 [2026-10-26 17:56:33][APP] SD2506 battery: 3.12 V +[RX] 2026-10-27T01:56:34.720+08:00 [2026-10-26 17:56:33][APP] App init OK +[RX] 2026-10-27T01:56:34.731+08:00 [2026-10-26 17:56:33][NAND_FTL] Initializing NAND FTL... +[RX] 2026-10-27T01:56:34.753+08:00 [2026-10-26 17:56:33][PROT] uncalibrated -> protection blocked (UA/UN/IA VALID not all set) +[RX] 2026-10-27T01:56:34.821+08:00 [2026-10-26 17:56:33][NAND_FTL] Map resumed: 14094/97504 sectors used +[RX] 2026-10-27T01:56:34.832+08:00 [2026-10-26 17:56:33][NAND_FTL] Map head=50480 tail=3726 epoch=7 +[RX] 2026-10-27T01:56:34.832+08:00 [2026-10-26 17:56:33][NAND_FTL] NAND FTL ready (capacity: 97504 pages = 190 MB) +[RX] 2026-10-27T01:56:34.918+08:00 [2026-10-26 17:56:33] [FS] FATFS mounted +[RX] 2026-10-27T01:56:34.981+08:00 [2026-10-26 17:56:33][SYSLOG] runlog boot entry: reboot +[RX] 2026-10-27T01:56:34.981+08:00 [2026-10-26 17:56:33][CFG] register: section 'network' (4 keys) +[RX] 2026-10-27T01:56:34.981+08:00 [2026-10-26 17:56:33][CFG] register: section 'ftp' (3 keys) +[RX] 2026-10-27T01:56:34.991+08:00 [2026-10-26 17:56:33][CFG] load: OK (957B, heap free 16552B) +[RX] 2026-10-27T01:56:35.002+08:00 [2026-10-26 17:56:33][NET_CFG] load: OK ip=192.168.1.100 +[RX] 2026-10-27T01:56:35.012+08:00 [2026-10-26 17:56:33] [CFG] prot set loaded (/prot_set.bin) +[RX] 2026-10-27T01:56:35.033+08:00 [2026-10-26 17:56:33][ADC_TASK] first: UA=11427 UB=1105 UC=959 UN=11452 IA=11450 IB=1027 IC=1031 IN=970 T=1004 +[RX] 2026-10-27T01:56:35.044+08:00 [2026-10-26 17:56:33][ADC_TASK] phasor(first) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:35.044+08:00 [2026-10-26 17:56:33][ADC_TASK] phasor(first) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:35.054+08:00 [2026-10-26 17:56:33][ADC_TASK] phasor(first) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:35.064+08:00 [2026-10-26 17:56:33][ADC_TASK] phasor(first) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:35.064+08:00 [2026-10-26 17:56:33][ADC_TASK] phasor(first) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:35.075+08:00 [2026-10-26 17:56:33][ADC_TASK] freq(first): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:56:35.085+08:00 [2026-10-26 17:56:33][NET_TASK] === Network Init === +[RX] 2026-10-27T01:56:35.085+08:00 [2026-10-26 17:56:33][PROT] protect task start: cycle=20ms elm=9 +[RX] 2026-10-27T01:56:35.085+08:00 [2026-10-26 17:56:33][NET] ch395f ver=0x4A fun_para=0x08 +[RX] 2026-10-27T01:56:35.095+08:00 MISS start snap=0x000001E7 req=0x000001F7 t=833 +[RX] 2026-10-27T01:56:35.105+08:00 [2026-10-26 17:56:33][WD] [WD] armed: timeout ~2498ms (worst ~1701ms), miss_tol=800ms +[RX] 2026-10-27T01:56:35.147+08:00 [2026-10-26 17:56:33][NET_TASK] net init: OK +[RX] 2026-10-27T01:56:35.147+08:00 [2026-10-26 17:56:33][NET_TASK] MAC: 3C:AB:72:53:2B:12 +[RX] 2026-10-27T01:56:35.157+08:00 [2026-10-26 17:56:33][NET_TASK] IP_INF: IP=192.168.1.100 GW=192.168.1.1 MASK=255.255.255.0 +[RX] 2026-10-27T01:56:35.167+08:00 [2026-10-26 17:56:33][UI_TASK] UI task: started, wait net ready +[RX] 2026-10-27T01:56:37.062+08:00 [2026-10-26 17:56:35][NET_TASK] PHY: 100M FULL +[RX] 2026-10-27T01:56:37.084+08:00 [2026-10-26 17:56:35][NET_TASK] netTask: started (single-socket mode) +[RX] 2026-10-27T01:56:37.116+08:00 [2026-10-26 17:56:35] [FTP] using factory default password +[RX] 2026-10-27T01:56:37.147+08:00 [2026-10-26 17:56:35][TIME_SYNC] time_sync: TCP listen on :8888 (sock=0) +[RX] 2026-10-27T01:56:37.178+08:00 [2026-10-26 17:56:35][I104] i104: listening on 2404 +[RX] 2026-10-27T01:56:37.188+08:00 MISS start snap=0x000001E7 req=0x000001F7 t=2921 +[RX] 2026-10-27T01:56:37.188+08:00 [PROF] t=2926 uic=0 uip=0 uipn=0 uil=0 uiw=0 uis=0 uisn=0 adc=2465 adcm=2238 adcn=0 gl=0 +[RX] 2026-10-27T01:56:37.198+08:00 [PROF2] t=2926 defd=130739 defs=36026 netp=2013 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:37.209+08:00 [2026-10-26 17:56:35] [FTP] waiting for connection... +[RX] 2026-10-27T01:56:37.209+08:00 [2026-10-26 17:56:35][UI_TASK] UI task: net ready, init port +[RX] 2026-10-27T01:56:37.209+08:00 [2026-10-26 17:56:35][UI_TASK] UI task: ui_port_init enter +[RX] 2026-10-27T01:56:37.219+08:00 [2026-10-26 17:56:35][UI_PORT] theme: mono dark_bg=true applied +[RX] 2026-10-27T01:56:37.230+08:00 [2026-10-26 17:56:35][UI_TASK] UI port init: OK +[RX] 2026-10-27T01:56:37.230+08:00 [2026-10-26 17:56:35][UI_TASK] UI task: ui_menu_init enter +[RX] 2026-10-27T01:56:37.240+08:00 [2026-10-26 17:56:35][UI_MENU] menu build start: total=15136 free=12692 big=12692 +[RX] 2026-10-27T01:56:37.250+08:00 [2026-10-26 17:56:35][UI_MENU_VIEW] view init: root frame w=66 h=107 +[RX] 2026-10-27T01:56:37.260+08:00 [2026-10-26 17:56:35][UI_MENU] menu build done: total=15020 free=11828 big=11816 used=3192 +[RX] 2026-10-27T01:56:37.260+08:00 [2026-10-26 17:56:35][UI_TASK] UI menu init: OK +[RX] 2026-10-27T01:56:37.271+08:00 [2026-10-26 17:56:35][UI_STANDBY] standby: ready (idle=60000ms) +[RX] 2026-10-27T01:56:37.281+08:00 [2026-10-26 17:56:35][UI_TASK] UI standby: ready (idle=60s) +[RX] 2026-10-27T01:56:37.322+08:00 [2026-10-26 17:56:35][UI_TASK] UI net sink: started (port 7003) +[RX] 2026-10-27T01:56:39.278+08:00 [PROF] t=5017 uic=176 uip=22473 uipn=1838 uil=10999 uiw=12564 uis=1246 uisn=0 adc=4555 adcm=2238 adcn=0 gl=0 +[RX] 2026-10-27T01:56:39.294+08:00 [PROF2] t=5017 defd=130739 defs=36026 netp=3009 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:39.752+08:00 [2026-10-26 17:56:38] [STACK] default peak_used=2160/5120 free_min=2960 (57%) +[RX] 2026-10-27T01:56:39.752+08:00 [2026-10-26 17:56:38] [STACK] net peak_used=1116/3840 free_min=2724 (70%) +[RX] 2026-10-27T01:56:39.762+08:00 [2026-10-26 17:56:38] [STACK] ftp peak_used=748/4096 free_min=3348 (81%) +[RX] 2026-10-27T01:56:39.773+08:00 [2026-10-26 17:56:38] [STACK] ui peak_used=4188/16384 free_min=12196 (74%) +[RX] 2026-10-27T01:56:39.773+08:00 [2026-10-26 17:56:38] [STACK] timesync peak_used=616/2560 free_min=1944 (75%) +[RX] 2026-10-27T01:56:39.783+08:00 [2026-10-26 17:56:38] [STACK] adc peak_used=920/2560 free_min=1640 (64%) +[RX] 2026-10-27T01:56:39.793+08:00 [2026-10-26 17:56:38] [STACK] iec104 peak_used=540/2560 free_min=2020 (78%) +[RX] 2026-10-27T01:56:39.793+08:00 [2026-10-26 17:56:38] [STACK] protect peak_used=492/2048 free_min=1556 (75%) +[RX] 2026-10-27T01:56:39.804+08:00 [2026-10-26 17:56:38] [STACK] heap free=15624 min_ever=8464 +[RX] 2026-10-27T01:56:41.315+08:00 [PROF] t=7047 uic=354 uip=73592 uipn=3822 uil=10911 uiw=12564 uis=1246 uisn=0 adc=6585 adcm=2238 adcn=0 gl=0 +[RX] 2026-10-27T01:56:41.315+08:00 [PROF2] t=7047 defd=130739 defs=36026 netp=3009 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:43.333+08:00 [PROF] t=9065 uic=536 uip=73592 uipn=9838 uil=10999 uiw=12564 uis=1246 uisn=0 adc=8603 adcm=2238 adcn=0 gl=0 +[RX] 2026-10-27T01:56:43.333+08:00 [PROF2] t=9065 defd=130739 defs=36026 netp=3010 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:44.726+08:00 [2026-10-26 17:56:43][ADC_TASK] frames=10001 idle=0 skip=61 seq=10006 frst_err=0 ring=9940 adc1_rc=0 adc1_err=0 adc1_seq=10004 adc1_gap=63 adc1_hw=0 tgap=1 +[RX] 2026-10-27T01:56:44.737+08:00 [2026-10-26 17:56:43][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:44.747+08:00 [2026-10-26 17:56:43][ADC_TASK] phasor(hb) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:44.757+08:00 [2026-10-26 17:56:43][ADC_TASK] phasor(hb) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:44.757+08:00 [2026-10-26 17:56:43][ADC_TASK] phasor(hb) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:44.768+08:00 [2026-10-26 17:56:43][ADC_TASK] phasor(hb) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:44.779+08:00 [2026-10-26 17:56:43][ADC_TASK] freq(hb): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:56:44.779+08:00 [2026-10-26 17:56:43][ADC_TASK] cal: ua_mv=1743 un_mv=1747 ia_mv=1747 vl=0x00 cl=0xe6 rail=0x000 edge=0x000 +[RX] 2026-10-27T01:56:44.789+08:00 [2026-10-26 17:56:43][ADC_TASK] meas: seq=49 v=1 ua_mv=0 un_mv=0 ia_mv=0 f=0 fv=0 +[RX] 2026-10-27T01:56:45.347+08:00 [PROF] t=11084 uic=712 uip=77741 uipn=9839 uil=10998 uiw=12564 uis=1246 uisn=0 adc=10621 adcm=2823 adcn=0 gl=0 +[RX] 2026-10-27T01:56:45.357+08:00 [PROF2] t=11084 defd=130739 defs=36026 netp=6008 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:45.813+08:00 [2026-10-26 17:56:44] [STACK] default peak_used=2160/5120 free_min=2960 (57%) +[RX] 2026-10-27T01:56:45.823+08:00 [2026-10-26 17:56:44] [STACK] net peak_used=1116/3840 free_min=2724 (70%) +[RX] 2026-10-27T01:56:45.833+08:00 [2026-10-26 17:56:44] [STACK] ftp peak_used=748/4096 free_min=3348 (81%) +[RX] 2026-10-27T01:56:45.833+08:00 [2026-10-26 17:56:44] [STACK] ui peak_used=4188/16384 free_min=12196 (74%) +[RX] 2026-10-27T01:56:45.843+08:00 [2026-10-26 17:56:44] [STACK] timesync peak_used=616/2560 free_min=1944 (75%) +[RX] 2026-10-27T01:56:45.854+08:00 [2026-10-26 17:56:44] [STACK] adc peak_used=1000/2560 free_min=1560 (60%) +[RX] 2026-10-27T01:56:45.854+08:00 [2026-10-26 17:56:44] [STACK] iec104 peak_used=540/2560 free_min=2020 (78%) +[RX] 2026-10-27T01:56:45.864+08:00 [2026-10-26 17:56:44] [STACK] protect peak_used=492/2048 free_min=1556 (75%) +[RX] 2026-10-27T01:56:45.875+08:00 [2026-10-26 17:56:44] [STACK] heap free=15624 min_ever=8464 +[RX] 2026-10-27T01:56:47.381+08:00 [PROF] t=13114 uic=890 uip=77741 uipn=2839 uil=10998 uiw=12564 uis=1246 uisn=0 adc=12651 adcm=2823 adcn=0 gl=0 +[RX] 2026-10-27T01:56:47.391+08:00 [PROF2] t=13114 defd=130739 defs=36026 netp=6008 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:49.396+08:00 [PROF] t=15132 uic=1072 uip=77741 uipn=9834 uil=11004 uiw=12564 uis=1246 uisn=0 adc=14669 adcm=2823 adcn=0 gl=0 +[RX] 2026-10-27T01:56:49.407+08:00 [PROF2] t=15132 defd=130739 defs=36026 netp=6008 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:51.411+08:00 [PROF] t=17150 uic=1254 uip=77741 uipn=9837 uil=11000 uiw=12564 uis=1246 uisn=0 adc=16687 adcm=2823 adcn=0 gl=0 +[RX] 2026-10-27T01:56:51.421+08:00 [PROF2] t=17150 defd=130739 defs=36026 netp=6008 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:53.433+08:00 [PROF] t=19168 uic=1436 uip=77741 uipn=9839 uil=10982 uiw=12564 uis=1246 uisn=0 adc=18705 adcm=2823 adcn=0 gl=0 +[RX] 2026-10-27T01:56:53.443+08:00 [PROF2] t=19168 defd=130739 defs=36026 netp=6008 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:54.732+08:00 [2026-10-26 17:56:53][ADC_TASK] frames=20000 idle=0 skip=64 seq=20006 frst_err=0 ring=19936 adc1_rc=0 adc1_err=0 adc1_seq=20004 adc1_gap=67 adc1_hw=0 tgap=2 +[RX] 2026-10-27T01:56:54.742+08:00 [2026-10-26 17:56:53][ADC_TASK] phasor(hb) C01-IA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:54.752+08:00 [2026-10-26 17:56:53][ADC_TASK] phasor(hb) C02-UA-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:54.752+08:00 [2026-10-26 17:56:53][ADC_TASK] phasor(hb) C03-UN-F1: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:54.763+08:00 [2026-10-26 17:56:53][ADC_TASK] phasor(hb) C04-IA-F2: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:54.763+08:00 [2026-10-26 17:56:53][ADC_TASK] phasor(hb) C05-IA-F5: Re=0 Im=0 rms=0 (x0.1) +[RX] 2026-10-27T01:56:54.773+08:00 [2026-10-26 17:56:53][ADC_TASK] freq(hb): f=0 valid=0 (x0.01) +[RX] 2026-10-27T01:56:54.784+08:00 [2026-10-26 17:56:53][ADC_TASK] cal: ua_mv=1743 un_mv=1747 ia_mv=1747 vl=0x00 cl=0xe6 rail=0x000 edge=0x000 +[RX] 2026-10-27T01:56:54.794+08:00 [2026-10-26 17:56:53][ADC_TASK] meas: seq=99 v=1 ua_mv=0 un_mv=0 ia_mv=0 f=0 fv=0 +[RX] 2026-10-27T01:56:55.444+08:00 [PROF] t=21184 uic=1612 uip=83999 uipn=837 uil=10999 uiw=73947 uis=73933 uisn=828 adc=20720 adcm=2833 adcn=0 gl=0 +[RX] 2026-10-27T01:56:55.455+08:00 [PROF2] t=21184 defd=130739 defs=36026 netp=6008 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:57.464+08:00 [PROF] t=23202 uic=1793 uip=83999 uipn=9839 uil=10998 uiw=73947 uis=73933 uisn=0 adc=22738 adcm=2833 adcn=0 gl=0 +[RX] 2026-10-27T01:56:57.474+08:00 [PROF2] t=23202 defd=130739 defs=36026 netp=6008 netn=0 adcp=10 adcq=0 gl=0 +[RX] 2026-10-27T01:56:59.483+08:00 [PROF] t=25220 uic=1975 uip=83999 uipn=9838 uil=11000 uiw=73947 uis=73933 uisn=0 adc=24756 adcm=2833 adcn=0 gl=0 +[RX] 2026-10-27T01:56:59.494+08:00 [PROF2] t=25220 defd=130739 defs=36026 netp=6008 netn=0 adcp=10 adcq=0 gl=0 diff --git a/docs/测试说明/boot_log_data/20261027_bench42_ui_clock_page.png b/docs/测试说明/boot_log_data/20261027_bench42_ui_clock_page.png new file mode 100644 index 00000000..c93db5a3 Binary files /dev/null and b/docs/测试说明/boot_log_data/20261027_bench42_ui_clock_page.png differ diff --git a/docs/测试说明/boot_log_data/20261027_bench42_verdicts.txt b/docs/测试说明/boot_log_data/20261027_bench42_verdicts.txt new file mode 100644 index 00000000..bcbaa8ea --- /dev/null +++ b/docs/测试说明/boot_log_data/20261027_bench42_verdicts.txt @@ -0,0 +1,70 @@ +2026-10-27 bench task-42 verdicts -- UI-landed image, 4 counted reset-only circles +identity: fw build: Oct 26 2026 22:52:09 suite=NONE dstr=off (suite=NONE => product build; dstr=off => non-destructive) +coordinate: HEAD b24b2b5f; firmware .c/.h identical to b623a406..HEAD (mechanically checked: no commit touched .c/.h after b623a406, + working tree had no dirty .c/.h; the only source newer than the .hex is test/host/console_log/console_log_test.c, + a HOST unit test not present in the uvprojx) => main-tree .hex IS HEAD firmware, no rebuild needed. +reporting rule (agreed with lead): flash boot and reset-only circles are counted SEPARATELY. A circle that had a flash in + front of it does NOT join the "consecutive reset-only" count (task-32 rule 4), and the 01:34 attempt is excluded + twice over: it had a flash behind it AND it captured 0 bytes (measurement failure, no data exists to count). + +BOOTS REPORTED: + flash boot x1 (00:25:06, @test rc=0, NOT in the reset-only sequence): 9 required markers incl. identity stamp, + forbidden 0, banner x1, boot->net init 777 ms, readback "No difference found". + reset-only x4 (01:46-01:52, the sequence proper): + +boot_r1_gen272 verdict=FAIL banner=0 cause="" forbidden_hits=0 [] boot->net_init=n/a + heap: - ui: - protect: - + prot_set: - comm: - CONSOLE dropped: absent +boot_r1_gen273 verdict=PASS banner=1 cause="software (NVIC_SystemReset)" forbidden_hits=0 [PROT=91px nb=0 head_bad=0] [NAND_FTL=56px nb=0 head_bad=0] [APP=57px nb=0 head_bad=0] boot->net_init=745 ms + heap: heap free=15624 min_ever=8464 ui: [STACK] ui peak_used=4188/16384 free_min=12196 (74%) protect: [STACK] protect peak_used=492/2048 free_min=1556 (75%) + prot_set: prot set loaded (/prot_set.bin) comm: comm init: OK (ca=1 port=2404) CONSOLE dropped: absent +boot_r2_gen274 verdict=PASS banner=1 cause="software (NVIC_SystemReset)" forbidden_hits=0 [PROT=91px nb=0 head_bad=0] [NAND_FTL=56px nb=0 head_bad=0] [APP=57px nb=0 head_bad=0] boot->net_init=786 ms + heap: heap free=15624 min_ever=8464 ui: [STACK] ui peak_used=4188/16384 free_min=12196 (74%) protect: [STACK] protect peak_used=492/2048 free_min=1556 (75%) + prot_set: prot set loaded (/prot_set.bin) comm: comm init: OK (ca=1 port=2404) CONSOLE dropped: absent +boot_r3_gen275 verdict=PASS banner=1 cause="software (NVIC_SystemReset)" forbidden_hits=0 [PROT=91px nb=0 head_bad=0] [NAND_FTL=56px nb=0 head_bad=0] [APP=57px nb=0 head_bad=0] boot->net_init=733 ms + heap: heap free=15624 min_ever=8464 ui: [STACK] ui peak_used=4188/16384 free_min=12196 (74%) protect: [STACK] protect peak_used=492/2048 free_min=1556 (75%) + prot_set: prot set loaded (/prot_set.bin) comm: comm init: OK (ca=1 port=2404) CONSOLE dropped: absent +boot_r4_gen276 verdict=PASS banner=1 cause="software (NVIC_SystemReset)" forbidden_hits=0 [PROT=91px nb=0 head_bad=0] [NAND_FTL=56px nb=0 head_bad=0] [APP=57px nb=0 head_bad=0] boot->net_init=776 ms + heap: heap free=15624 min_ever=8464 ui: [STACK] ui peak_used=4188/16384 free_min=12196 (74%) protect: [STACK] protect peak_used=492/2048 free_min=1556 (75%) + prot_set: prot set loaded (/prot_set.bin) comm: comm init: OK (ca=1 port=2404) CONSOLE dropped: absent + +NEGATIVE CONTROL (proves these PASSes are not vacuous) -- same verifier, same flags, pointed at the pre-fix defective capture: +rc=1 +[FAIL] exact line: \[[^\]]*\]\[PROT\] uncalibrated -> protection blocked \(UA/UN/IA hits=0 lens=[] loose_neighbours=0 +[FAIL] exact line: \[[^\]]*\]\[NAND_FTL\] Initializing NAND FTL\.\.\. hits=0 lens=[] loose_neighbours=1 + inexact neighbour: 26-10-26 08:37:07][NAND_FTL] Initializing NAND FTL... +VERDICT: FAIL + +EXECUTIVE-ACTION PAGE GATE, PROVEN ON REAL HARDWARE (not simulator): + --to clear -> refused before ANY key was injected (no trace file was even written), rc non-zero: + raise RuntimeError("刻意跳过执行类页面 " + pid + "：进入后第二次 ENTER 即真执行" + RuntimeError: 刻意跳过执行类页面 clear：进入后第二次 ENTER 即真执行（强制复归 = 复归保护位并写 SOE；清除记录 = 清 SOE/运行/操作记录）。显示正确性请走模拟器黄金参考；确需真机下钻才加 --allow-exec-pages。 + --to reset -> same refusal, same reason: + raise RuntimeError("刻意跳过执行类页面 " + pid + "：进入后第二次 ENTER 即真执行" + reason text names the exact stacking hazard: entering the page + a SECOND ENTER executes + (强制复归 = reset protection bits + write SOE; 清除记录 = clear SOE/run/op records). + clock page navigation (9 steps, keys e,l,d,d,d,d,e,e,e -- every ENTER in a menu context): reached, kind=PAGE, ink=3018 + +FINAL READBACK (last hardware action, after every capture, since -CmpFile resets the target): + rc=0 + CMP: MDK-ARM\STM32F407-Demo\STM32F407-Demo.hex vs device flash @ 0x08000000 (NOTE: connecting resets the target) + No difference found. + +INCIDENTS AND SELF-REPORTED MEASUREMENT ERRORS IN THIS WINDOW (kept because they are the useful part): + 1) 01:34 first attempt captured 0 bytes. Root cause NOT the board: the long-running serial-assistant daemon + (pid 18020, uptime 156589 s) had DIED, and "serial_tool.py status" auto-spawns a fresh daemon, so status kept + answering happily with port.ready=false / rx_lines=0 / 58-byte log. Verified afterwards: the board had booted + normally from that very reset (uptime t=386840 ticks matched 01:34:08 and PROF lines streamed). + => Rule for every window: run "open" and assert port.ready AND watch rx_lines grow BEFORE the first reset; + never assume the port state left behind by @test survives (it does not survive an hour). + 2) My own forbidden pattern "Fault" is a false red: it substring-matches "de*fault*" and hit two innocent lines + ([FTP] using factory default password / [STACK] default peak_used). Replaced by the explicit fault tokens. + Any Fault dump starts with [ERR] anyway (platform convention), so bare "Fault" added nothing but noise. + 3) My harness parsed the verifier's --json from stdout+stderr concatenated; on a non-zero exit that breaks parsing. + Fixed by keeping the streams apart. Also "serial_tool.py log" returns JSON, not plain text (first attempt + filtered lines starting with "[RX]" and silently got zero) -- that is the second time tonight I assumed an + output format instead of reading it. + OBSERVATION (not a verdict, not my scope): the device wall clock reads 2026-10-26 18:00:35 while the host logged + 2026-10-27 01:5x+08:00, i.e. ~8 h behind local and a few minutes off true UTC; firmware log stamps show the same + 8 h offset against the daemon stamps. Frame evidence: 20261027_bench42_ui_clock_page.png. Left for the lead to + route (RTC/timezone semantics), with no claim attached. diff --git a/docs/测试说明/boot_log_data/README.md b/docs/测试说明/boot_log_data/README.md index 44b6113b..99d98f5e 100644 --- a/docs/测试说明/boot_log_data/README.md +++ b/docs/测试说明/boot_log_data/README.md @@ -76,6 +76,7 @@ git add -f docs/测试说明/boot_log_data/20261012_B9_soe_after_post.bin | 2026-10-26 | `prod`（**像来自仓外只读 detached worktree `_wt/bench-21-77779d49` @ 77779d49**；主树当时另有在飞文档改动，这份像**不含**主树未提交内容——别拿本行结论去对主树源码）/ 开机 + 30 s 空载，**@test PASS** | `protect` **492/2048（75%）**、`iec104` 540/2560（78%）、`adc` 1000/2560（60%）、`ui` 4088/16384（75%）、`default` 2160/5120（57%）、heap free=15624 **min_ever=8464**；`protection init: OK (set=40 elm=9)`、锚点 `reset cause:` ×1、**[ERR]=0 / Fault=0**、`net init: OK` **+762 ms**、身份戳 `Oct 26 2026 16:27:01 suite=NONE dstr=off` 从 hex 抠出并与线上相符、`-CmpFile` 回读 No difference found（**排在采日志之后**）；⚠ **启动日志行内字节交错缺陷**：protectTask `[PROT]` 与 `[NAND_FTL]` 两个写者并发，3 次启动命中 2 次，hexdump 实证「某行内多出的字节恰等于下一行被吃掉的行首」（串口 framing 错不可能让行变长）→ 已立项派 App/log 属主 | `20261026_prod_77779d49_boot_log.txt` / `20261026_prod_77779d49_boot_log_reset_only.txt` / `20261026_prod_console_interleave_evidence.txt` | | 2026-10-26 | 同镜像 / **整定页两条实机判据**（主站 `test/host/iec104_master.py` 以库形式复用，驱动脚本留在仓外 `_wt/scratch/bench21_104.py`（原写 `_wt/.state/`，但那是 task-worktree 的**台账目录**，放脚手架会把 `list` 撞崩，已挪出），**未改仓库**；复位只用 `-Rst -Run`，**全程不重烧**） | **C_RD 27/27 可寻址项全中出厂值**（清单取自 `git show 77779d49:App/algo/prot_set.[ch]` 而非工作树；**13 个 comm_addr=0 本地项结构性不可寻址 → 明确不参与本判据**，另以 0x8854/0x8855/0x8862 三个未映射地址实证「不应答」）；⚠ **未标定闭锁态下 C_SE 仍允许写**（闭锁 ≠ 禁写）：0x8858=7.5 / 0x885D=1234 / 0x8820=11000 三项 sel+exe 均 actcon 且 C_RD 同值 → 仅复位后仍为 7.5/1234/11000，启动日志 `[CFG] prot set loaded (/prot_set.bin)`、CORRUPT=0、version change=0、YX31=OFF（**校验和通过**）；越界写 0x8858=500(>100)、0x8821=0.5(<1) 均回 **actcon+PN** 且原值一字未变；还原默认值 → 再复位 → 27/27 回默认（双向持久化，台架留在出厂态）。屏检：整定页（123 修改密码）标题右侧**「未标定」徽标在位**（Glyph 精确命中 x=105/117/129；同页用查看密码进去无徽标 = 设计如此），**LOCK 未见且可证未闭锁**（ENTER 被消费进入数值编辑，而闭锁时 ENTER 一律不消费），全程零提交；强制真 LOCK 需篡改 `/prot_set.bin`，台架禁做 | `20261026_prod_77779d49_iec104_setpoint_leg.txt` / `20261026_prod_77779d49_ui_set_badge_uncal.png`（同名 `.bin` = 原始 3200 B 帧、可 `board_ui_nav.py --classify` 复判，但被 `.gitignore` 的 `*.bin` 全局规则挡住，**入库需 `git add -f`**；顺带一条既存事实：本目录上方 B9 那两行引用的 `20261012_B9_soe*.bin` 同样从未入库，`git ls-files` 查不到）/ `20261026_prod_77779d49_ui_set_view_readonly.png` / `20261026_prod_77779d49_ui_set_edit_enter_accepted.png` / `20261026_prod_77779d49_ui_nav_trace.json` | | 2026-10-26 | `prod`（**像 = `1d4b6a17` 控制台整行独占修复**；仓外只读 detached worktree `_wt/bench-23-1d4b6a17` 出像，主树同 HEAD 但压着 UI 道 task-6 未提交半成品 → **像不含它**）/ **task-23 收口复验：1 次烧录启动 + 连续 4 次「仅复位不重烧」** | **5/5 启动 [ERR]=0、CONSOLE dropped=0**（让路没被计成 [ERR]，与设计一致）；两条旧受害行**逐字节完整**：`[PROT]` 未标定行恒 91 px、`[NAND_FTL] Initializing…` 恒 56 px 且行首 `[ts]` 齐（旧缺陷正是吃它行首）；锚点 `reset cause:` ×1、无 Fault、`comm init: OK (ca=1 port=2404)` 每次都在、`prot set loaded` ×1 且 CORRUPT ×0；heap **free=15624 min_ever=8464 与上一轮逐字节相同**、protect 492/2048 相同；ui 峰值 **4116~4188/16384** —— **同一份像自己就摆 72 B**，故相对上一轮 4088 的 +100 B **不可归因于本修复**（顺带记账：`[STACK]` 峰值有 ±100 B 噪声，拿它当门禁得先定容差）；行序一处变化：`[NAND_FTL]` 现排在 `[PROT]` 前一行 = 抢不到独占者整行入环延后发，与修法吻合；**反证非空跑**：同一校验器打旧缺陷那份 → rc=1 FAIL、`nand_head_ok=false`（那行真读作 `26-10-26 …`）；`-CmpFile` 排在全批日志之后、No difference found | `20261026_bench23_flash_boot_log.txt` / `20261026_bench23_reset_only_boots_r1_r4.txt`（4 次仅复位原始字节，按 gen 264~267 分块）/ `20261026_bench23_recheck_verdicts.txt`（逐启动判据 + 反证 + 栈口径 + 最终回读） | +| 2026-10-27 | `prod`（**身份戳为准、SHA 只当坐标**：`fw build: Oct 26 2026 22:52:09 suite=NONE dstr=off`；坐标 HEAD `b24b2b5f`；像 = 主树现成 `MDK-ARM/STM32F407-Demo/STM32F407-Demo.hex`，出像前机械核验「`b623a406` 之后无任何提交碰过 `*.c/*.h`、工作树 `*.c/.h` 全干净、唯一比 .hex 新的源文件是 `test/host/console_log/console_log_test.c`（主机侧单测，不在 uvprojx）」→ **无需重建**，UI 道三页与维护链已含在像内）/ **task-42 台架窗口：UI 落地后同判据复跑 + 执行类页面真机硬闸** | **烧录启动 1 次（00:25，不计入仅复位序列）**：`@test` **PASS**，9 条 required 全中（含身份戳）、Forbidden 零命中、锚点 `reset cause:` ×1、boot→`net init: OK` **777 ms**、回读 **No difference found**。**仅复位 4 次（01:46–01:52，逐圈 clear 使 serial gen 273→276 单调递增自证窗口不重叠；`stlink_flash.py reset` = `-c SWD -Rst -Run`，零重烧）**：4/4 **PASS** —— `[ERR]` / `CONSOLE dropped` / 任一 Fault 令牌 / `ERROR` / `assert` **全部零命中**；两条旧受害行**逐字节完整**：`[PROT] … protection blocked (UA/UN/IA VALID not all set)` 恒 **91 px**、`[NAND_FTL] Initializing NAND FTL` 恒 **56 px**（行首 `[` 齐全、`loose_neighbours=0`、`head_bad=0`），锚定用**仓内** `verify_log.py --exact`（`b1280e3c` 并入的能力，本轮首次自用）；`[APP] comm init: OK (ca=1 port=2404)` 恒 **57 px**；`prot set loaded (/prot_set.bin)` ×4、CORRUPT ×0；boot→net init 733–786 ms。**反证非空跑**：同一把尺指向修复前归档 `20261026_prod_77779d49_boot_log_reset_only.txt` → **rc=1 FAIL**、缺行首邻居原样打回 `26-10-26 08:37:07][NAND_FTL] …`。**执行类页面硬闸真机实证**：`board_ui_nav --to clear / --to reset` **在下钻前即拒绝**（连轨迹文件都没生成、非零退出），理由文本点名「第二次 ENTER 即真执行」——正是 00:17 我报的那条三段叠险的收口；`--to clock` 正常到达（9 步，每次 ENTER 都落在菜单上下文），页面渲染无缺字白框（`年/月/日/时/分/秒` + `第 1 页，共 1 页` 全显），帧见 PNG。**栈/堆**：heap `free=15624 min_ever=8464` 与 task-30 **逐字节相同**，`protect 492/2048`、`ui 4188/16384` 四轮内部零摆动（本轮 max=4188，与上轮 max 4188 持平 → 无回退）；仍按 task-32 未定稿口径**只报数不做单次比较**。**收尾**：`-CmpFile` 排在全部日志采集**之后**（它复位目标），`No difference found`；bench 锁 `task-42` 释放并复验 build/bench 双空闲。**两次如实申报**：① 01:34 头一圈采到 0 字节——根因**不是板子**，是常驻 daemon（pid 18020，uptime 156589 s）已死，而 `serial_tool.py status` 会**自动拉起新 daemon**、于是 status 一直"正常"地报 `port.ready=false / rx_lines=0 / 日志 58 B`；事后证明板子那次复位后正常启动（uptime 计数对得上、PROF 成流）→ 立口径：**每圈复位前 `open` + 断言 ready + 观察 rx_lines 增长，别假设 @test 留下的端口状态能过夜**；② 我加的 Forbidden 令牌 `Fault` 是**假红**：它子串命中 `de*fault*`（打到 `[FTP] using factory default password` 与 `[STACK] default peak_used`），已换成显式故障令牌——四个 Fault 本来都以 `[ERR]` 开头，裸 `Fault` 只是噪声。**另记一条观察（不下结论、不属本卡职责）**：装置墙钟显示 `2026-10-26 18:00:35`，而主机记录为 `2026-10-27 01:5x +08:00`（固件日志时标与 daemon 时标也恒差 8 h）→ 时区/RTC 语义请 lead 定道处理 | `20261027_bench42_reset_only_boots_r1_r4.txt`、`20261027_bench42_verdicts.txt`、`20261027_bench42_ui_clock_page.png` | > f3rounds 两只是**判读证据存档**（非 `[STACK]` 水位快照）：源为 serial-assistant live 日志的 > 字节偏移切片（不 clear、行边界对齐），gz 前置 ASCII 头行携带偏移窗、负载定义与 v1.1 判据