B7A: QMI DMS time vs VNIIFTRI NTP (DMS = UTC - 0.28 s, sigma 1 ms; NITZ = DMS truncated to 1 s). B7B: a 1970 -> 2026 date -s step is harmless for the modem stack. B7C: aurora-modem probes DMS/NITZ along the start flow and steps CLOCK_REALTIME once at the first valid sample (REG registered/attached), never RTC; background SNTP check (query only) after START OK. 3/3 class-A cold boots PASS (residual +0.04/+0.36/+0.84 s), cache 14fe453a written (B7C_WRITE_VERIFIED) and verified by a normal power-on (V1, +0.26 s). Also publishes the prerequisite R2 (boot-hang / lk eMMC investigation, T4 telnet baseline that B7C builds on) and R3 (autonomous cold boot, NCM loss) material, and extends tools/publish-sanitize.py to r2/, r3/, b7/. Binary images, initramfs, busybox and raw logs stay out (see b7/*/SHA256SUMS).
85 lines
6.8 KiB
Text
85 lines
6.8 KiB
Text
13:10:06.942 [ 0.000000] Linux version 7.2.7-aurora-bam1 (q@aiaiai) (aarch64-linux-gnu-gcc (Debian 14.2.0-19) 14.2.0, GNU ld (GNU Binutils for Debian) 2.44) #5 SMP PREEMPT Wed Sep 30 04:59:18 +06 2026
|
||
13:10:08.546 [ 1.155537] mmc0: new HS200 MMC card at address 0001
|
||
13:10:09.346 EMMC-RO-SUMMARY devices=30 all_ro=YES
|
||
13:10:14.348 [init] T4: telnetd started on 172.16.42.1:23
|
||
13:10:14.348 [ 7.014756] [init] T4: telnetd started on 172.16.42.1:23
|
||
13:10:16.551 B1_OK=1
|
||
13:10:16.751 ~ # [6n[ 9.216110] [aurora-modem] === START (conf /etc/aurora/modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
|
||
13:10:16.751 [ 9.303762] [aurora-modem] STATE OFF -> RMTFS_READY
|
||
13:10:16.751 [ 9.309175] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
|
||
13:10:17.352 [ 9.989395] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
|
||
13:10:20.553 [ 13.026921] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
|
||
13:10:20.553 [ 13.145898] [aurora-modem] TIME probe 1 [QMI_READY]: dms_ms=3228 dms_utc=315964803.228 nitz=none dms-nitz=- clock=4445 -> INVALID (year<2026)
|
||
13:10:20.553 [ 13.201862] [aurora-modem] STATE QMI_READY -> SIM_READY
|
||
13:10:20.753 [ 13.313434] [aurora-modem] TIME probe 2 [SIM_READY]: dms_ms=3399 dms_utc=315964803.399 nitz=none dms-nitz=- clock=4446 -> INVALID (year<2026)
|
||
13:10:23.957 [ 16.575820] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
|
||
13:10:24.157 [ 16.678606] [aurora-modem] TIME probe 3 [RADIO_ONLINE]: dms_ms=6765 dms_utc=315964806.765 nitz=none dms-nitz=- clock=4449 -> INVALID (year<2026)
|
||
13:10:24.557 [ 17.038693] [aurora-modem] REG t+0.3s: not-registered-searching / PS detached / none (none, ) - pci= si=/ cl=/
|
||
13:10:24.557 [ 17.140983] [aurora-modem] TIME probe 4 [REG:not-registered-searching/detached]: dms_ms=7227 dms_utc=315964807.227 nitz=none dms-nitz=- clock=4449 -> INVALID (year<2026)
|
||
13:10:27.959 [ 20.442946] [aurora-modem] REG t+3.7s: registered / PS attached / available (none, ps) 250-99 pci=390 si=7661/156416008 cl=7661/156416008
|
||
13:10:27.959 [ 20.548286] [aurora-modem] TIME probe 5 [REG:registered/attached]: dms_ms=1474971027620 dms_utc=1790935827.620 nitz=2026-10-02 10:10:27 dms-nitz=+0.65 clock=4453 -> VALID (ok)
|
||
13:10:28.359 [ 20.875568] [aurora-modem] TIME SET rc=0 source=qmi-dms phase=REG:registered/attached old=4453 (1970-01-01 01:14:13) new=1790935828 (2026-10-02 10:10:28) uptime=20.72 dms-nitz=+0.65 validation=VALID rtc=untouched
|
||
13:10:28.359 [ 20.889308] [aurora-modem] registered: MCC: '250' MNC: '99' Description: 'Beeline' MCC: '250' MNC: '99' after 4.2s
|
||
13:10:28.359 [ 20.901179] [aurora-modem] STATE RADIO_ONLINE -> REGISTERED
|
||
13:10:28.359 [ 21.010830] [aurora-modem] TIME probe 6 [REGISTERED]: dms_ms=1474971028082 dms_utc=1790935828.082 nitz=2026-10-02 10:10:28 dms-nitz=+0.12 clock=1790935828 -> VALID (ok)
|
||
13:10:42.599 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:42.799 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:43.000 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:43.200 <<<<<< message = "Release CID" (0x0023)
|
||
13:10:43.201 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:43.202 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:43.402 <<<<<< message = "Release CID" (0x0023)
|
||
13:10:43.402 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:43.403 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:43.603 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:43.604 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:43.604 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:43.804 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:43.805 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:44.005 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:44.006 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:44.006 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:44.207 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:44.207 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:44.208 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:44.409 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:44.409 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:44.610 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:44.611 <<<<<< type = "CID 3GPP" (0x1e)
|
||
13:10:44.611 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:10:46.217 <<<<<< type = "CID 3GPP" (0x1e)
|
||
13:10:47.818 <<<<<< type = "CID 3GPP" (0x1e)
|
||
13:10:51.420 <<<<<< type = "CID 3GPP" (0x1e)
|
||
13:10:52.626 <<<<<< translated = FAILURE: NotSupported
|
||
13:10:52.834 [1771]: <dbg> [1790935852.393304] [modem0] setup SIM hot swap (5/8): no need to register for SIM ICCID refresh events
|
||
13:10:53.034 <<<<<< translated = FAILURE: NotSupported
|
||
13:10:53.436 <<<<<< message = "UIM Get ICCID" (0x003C)
|
||
13:10:53.436 <<<<<< message = "UIM Get ICCID" (0x003C)
|
||
13:10:53.437 <<<<<< type = "ICCID" (0x01)
|
||
13:10:54.441 <<<<<< translated = FAILURE: NotProvisioned
|
||
13:10:54.642 <<<<<< translated = FAILURE: NotProvisioned
|
||
13:10:54.642 <<<<<< translated = FAILURE: NotProvisioned
|
||
13:11:19.469 [ 72.062468] [aurora-modem] STATE REGISTERED -> MM_READY
|
||
13:11:20.472 <<<<<< message = "UIM Get ICCID" (0x003C)
|
||
13:11:20.472 <<<<<< message = "UIM Get ICCID" (0x003C)
|
||
13:11:20.472 <<<<<< type = "ICCID" (0x01)
|
||
13:11:22.081 <<<<<< translated = FAILURE: InvalidQmiCommand
|
||
13:11:22.885 <<<<<< translated = FAILURE: MissingArgument
|
||
13:11:23.087 <<<<<< translated = FAILURE: DeviceNotReady
|
||
13:11:23.490 <<<<<< translated = FAILURE: InvalidArgument
|
||
13:11:23.692 <<<<<< translated = FAILURE: InvalidArgument
|
||
13:11:23.693 <<<<<< translated = FAILURE: MissingArgument
|
||
13:11:23.894 <<<<<< translated = FAILURE: DeviceNotReady
|
||
13:11:24.297 <<<<<< translated = FAILURE: InvalidArgument
|
||
13:11:24.298 <<<<<< translated = FAILURE: InvalidArgument
|
||
13:11:27.120 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:11:27.321 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:11:27.924 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:11:28.124 <<<<<< message = "Release CID" (0x0023)
|
||
13:11:28.125 <<<<<< message = "Allocate CID" (0x0022)
|
||
13:11:28.125 <<<<<< message = "Release CID" (0x0023)
|
||
13:11:30.739 [ 83.310151] [aurora-modem] STATE MM_READY -> BEARER_CONNECTED
|
||
13:11:30.739 [ 83.322783] [aurora-modem] === START OK in 74.1s (wwan0 10.84.21.8/28, routes: 10.10.22.1 194.186.191.1 77.88.8.8 1.1.1.1 )
|
||
13:11:30.939 [ 83.424777] [aurora-modem] TIME probe 7 [BEARER_CONNECTED]: dms_ms=1474971090500 dms_utc=1790935890.500 nitz=2026-10-02 10:11:30 dms-nitz=+0.54 clock=1790935890 -> VALID (ok)
|
||
13:11:46.156 [ 98.743112] [aurora-modem] SNTP check ( 89.109.251.21 89.109.251.22 89.109.251.23): 13 replies; best offset delay server: +0.192765 0.050548 89.109.251.23: (offset > 0 = clock behind)
|
||
13:11:46.157 [ 98.750910] [aurora-modem] SNTP: |offset| < 1s - clock kept (no slew: STA_UNSYNC stays, RTC_SYSTOHC never engages)
|