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).
81 lines
6.6 KiB
Text
81 lines
6.6 KiB
Text
13:29:58.026 [ 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:29:59.632 [ 1.173095] mmc0: new HS200 MMC card at address 0001
|
|
13:30:00.433 EMMC-RO-SUMMARY devices=30 all_ro=YES
|
|
13:30:05.640 [init] network: usb0 172.16[ 7.076450] [init] T4: telnetd started on 172.16.42.1:23
|
|
13:30:05.640 [init] T4: telnetd started on 172.16.42.1:23
|
|
13:30:07.847 B1_OK=1
|
|
13:30:07.847 ~ # [ 9.397896] [aurora-modem] === START (conf /etc/aurora/modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
|
|
13:30:08.047 [ 9.478387] [aurora-modem] STATE OFF -> RMTFS_READY
|
|
13:30:08.047 [ 9.483851] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
|
|
13:30:08.647 [ 10.168671] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
|
|
13:30:11.650 [ 13.213573] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
|
|
13:30:11.850 [ 13.319702] [aurora-modem] TIME probe 1 [QMI_READY]: dms_ms=3229 dms_utc=315964803.229 nitz=none dms-nitz=- clock=772 -> INVALID (year<2026)
|
|
13:30:11.851 [ 13.370985] [aurora-modem] STATE QMI_READY -> SIM_READY
|
|
13:30:12.051 [ 13.480159] [aurora-modem] TIME probe 2 [SIM_READY]: dms_ms=3385 dms_utc=315964803.385 nitz=none dms-nitz=- clock=772 -> INVALID (year<2026)
|
|
13:30:15.256 [ 16.749877] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
|
|
13:30:15.457 [ 16.852462] [aurora-modem] TIME probe 3 [RADIO_ONLINE]: dms_ms=6758 dms_utc=315964806.758 nitz=none dms-nitz=- clock=775 -> INVALID (year<2026)
|
|
13:30:15.657 [ 17.186280] [aurora-modem] REG t+0.3s: not-registered-searching / PS detached / none (none, ) - pci= si=/ cl=/
|
|
13:30:15.857 [ 17.291745] [aurora-modem] TIME probe 4 [REG:not-registered-searching/detached]: dms_ms=7193 dms_utc=315964807.193 nitz=none dms-nitz=- clock=776 -> INVALID (year<2026)
|
|
13:30:22.260 [ 23.739210] [aurora-modem] REG t+6.9s: registered / PS attached / available (none, ps) 250-99 pci=390 si=7661/156416008 cl=7661/156416008
|
|
13:30:22.460 [ 23.847336] [aurora-modem] TIME probe 5 [REG:registered/attached]: dms_ms=1474972221726 dms_utc=1790937021.726 nitz=2026-10-02 10:30:21 dms-nitz=+0.77 clock=782 -> VALID (ok)
|
|
13:30:22.661 [ 24.065852] [aurora-modem] TIME SET rc=0 source=qmi-dms phase=REG:registered/attached old=782 (1970-01-01 00:13:02) new=1790937022 (2026-10-02 10:30:22) uptime=23.91 dms-nitz=+0.77 validation=VALID rtc=untouched
|
|
13:30:22.661 [ 24.080262] [aurora-modem] registered: MCC: '250' MNC: '99' Description: 'Beeline' MCC: '250' MNC: '99' after 7.2s
|
|
13:30:22.661 [ 24.090986] [aurora-modem] STATE RADIO_ONLINE -> REGISTERED
|
|
13:30:22.661 [ 24.197252] [aurora-modem] TIME probe 6 [REGISTERED]: dms_ms=1474972222079 dms_utc=1790937022.079 nitz=2026-10-02 10:30:22 dms-nitz=+0.11 clock=1790937022 -> VALID (ok)
|
|
13:30:36.936 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:36.936 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:37.338 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:37.339 <<<<<< message = "Release CID" (0x0023)
|
|
13:30:37.539 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:37.540 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:37.540 <<<<<< message = "Release CID" (0x0023)
|
|
13:30:37.741 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:37.742 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:37.743 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:37.944 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:37.944 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.145 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.146 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.346 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.347 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.348 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.549 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.550 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.550 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.751 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.752 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.753 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:38.953 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:30:45.782 <<<<<< translated = FAILURE: NotSupported
|
|
13:30:45.983 [1823]: <dbg> [1790937045.210366] [modem0] setup SIM hot swap (5/8): no need to register for SIM ICCID refresh events
|
|
13:30:46.184 <<<<<< translated = FAILURE: NotSupported
|
|
13:30:46.587 <<<<<< message = "UIM Get ICCID" (0x003C)
|
|
13:30:46.587 <<<<<< message = "UIM Get ICCID" (0x003C)
|
|
13:30:46.587 <<<<<< type = "ICCID" (0x01)
|
|
13:30:47.392 <<<<<< translated = FAILURE: NotProvisioned
|
|
13:30:47.593 <<<<<< translated = FAILURE: NotProvisioned
|
|
13:30:47.794 <<<<<< translated = FAILURE: NotProvisioned
|
|
13:31:12.634 [ 74.082587] [aurora-modem] STATE REGISTERED -> MM_READY
|
|
13:31:13.638 <<<<<< message = "UIM Get ICCID" (0x003C)
|
|
13:31:13.639 <<<<<< message = "UIM Get ICCID" (0x003C)
|
|
13:31:13.639 <<<<<< type = "ICCID" (0x01)
|
|
13:31:15.052 <<<<<< translated = FAILURE: InvalidQmiCommand
|
|
13:31:16.057 <<<<<< translated = FAILURE: MissingArgument
|
|
13:31:16.258 <<<<<< translated = FAILURE: DeviceNotReady
|
|
13:31:16.460 <<<<<< translated = FAILURE: InvalidArgument
|
|
13:31:16.660 <<<<<< translated = FAILURE: InvalidArgument
|
|
13:31:16.861 <<<<<< translated = FAILURE: MissingArgument
|
|
13:31:17.062 <<<<<< translated = FAILURE: DeviceNotReady
|
|
13:31:17.264 <<<<<< translated = FAILURE: InvalidArgument
|
|
13:31:17.465 <<<<<< translated = FAILURE: InvalidArgument
|
|
13:31:20.282 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:31:20.282 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:31:21.086 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:31:21.086 <<<<<< message = "Release CID" (0x0023)
|
|
13:31:21.087 <<<<<< message = "Allocate CID" (0x0022)
|
|
13:31:21.287 <<<<<< message = "Release CID" (0x0023)
|
|
13:31:23.716 [ 85.307899] [aurora-modem] STATE MM_READY -> BEARER_CONNECTED
|
|
13:31:23.918 [ 85.319280] [aurora-modem] === START OK in 75.9s (wwan0 10.44.148.138/30, routes: 10.10.22.3 194.186.191.1 77.88.8.8 1.1.1.1 )
|
|
13:31:23.918 [ 85.427154] [aurora-modem] TIME probe 7 [BEARER_CONNECTED]: dms_ms=1474972283305 dms_utc=1790937083.305 nitz=2026-10-02 10:31:23 dms-nitz=+0.35 clock=1790937083 -> VALID (ok)
|
|
13:31:39.328 [ 100.758290] [aurora-modem] SNTP check ( 89.109.251.21 89.109.251.22 89.109.251.23): 12 replies; best offset delay server: +0.452674 0.039894 89.109.251.22: (offset > 0 = clock behind)
|
|
13:31:39.328 [ 100.764035] [aurora-modem] SNTP: |offset| < 1s - clock kept (no slew: STA_UNSYNC stays, RTC_SYSTOHC never engages)
|