uzbek-plus/logs/b7/b7c/c1/uart-markers.txt
q 8d7721c775 B7: add network time bootstrap and persistent B7C cache
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).
2026-10-02 20:18:25 +03:00

85 lines
6.8 KiB
Text
Raw Permalink Blame History

This file contains invisible Unicode characters

This file contains invisible Unicode characters that are indistinguishable to humans but may be processed differently by a computer. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

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 ~ # [ 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)