[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd030]
[    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
[    0.000000] KASLR enabled
[    0.000000] random: crng init done
[    0.000000] Machine model: JZ08AU Aurora (RAM boot BAM1)
[    0.000000] earlycon: msm_serial_dm0 at MMIO 0x00000000078b0000 (options '115200n8')
[    0.000000] printk: legacy bootconsole [msm_serial_dm0] enabled
[    0.000000] printk: debug: ignoring loglevel setting.
[    0.000000] OF: reserved mem: 0x000000008e700000..0x000000008e7fffff (1024 KiB) nomap non-reusable mba
[    0.000000] OF: reserved mem: 0x0000000086000000..0x00000000862fffff (3072 KiB) nomap non-reusable tz-apps@86000000
[    0.000000] OF: reserved mem: 0x0000000086300000..0x00000000863fffff (1024 KiB) nomap non-reusable smem@86300000
[    0.000000] OF: reserved mem: 0x0000000086400000..0x00000000864fffff (1024 KiB) nomap non-reusable hypervisor@86400000
[    0.000000] OF: reserved mem: 0x0000000086500000..0x000000008667ffff (1536 KiB) nomap non-reusable tz@86500000
[    0.000000] OF: reserved mem: 0x0000000086680000..0x00000000866fffff (512 KiB) nomap non-reusable reserved@86680000
[    0.000000] OF: reserved mem: 0x0000000086700000..0x00000000867dffff (896 KiB) nomap non-reusable rmtfs@86700000
[    0.000000] OF: reserved mem: 0x00000000867e0000..0x00000000867fffff (128 KiB) nomap non-reusable rfsa@867e0000
[    0.000000] OF: reserved mem: 0x0000000086800000..0x000000008b5fffff (79872 KiB) nomap non-reusable mpss@86800000
[    0.000000] cma: Reserved 32 MiB at 0x000000009de00000
[    0.000000] psci: probing for conduit method from DT.
[    0.000000] psci: PSCIv1.0 detected in firmware.
[    0.000000] psci: Using standard PSCI v0.2 function IDs
[    0.000000] psci: MIGRATE_INFO_TYPE not supported.
[    0.000000] psci: SMC Calling Convention v1.0
[    0.000000] psci: OSI mode supported.
[    0.000000] psci: [Firmware Bug]: failed to set PC mode: -3
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000080000000-0x000000009fffffff]
[    0.000000]   DMA32    empty
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000080000000-0x0000000085ffffff]
[    0.000000]   node   0: [mem 0x0000000086000000-0x000000008b5fffff]
[    0.000000]   node   0: [mem 0x000000008b600000-0x000000008e6fffff]
[    0.000000]   node   0: [mem 0x000000008e700000-0x000000008e7fffff]
[    0.000000]   node   0: [mem 0x000000008e800000-0x000000009fffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000080000000-0x000000009fffffff]
[    0.000000] percpu: Embedded 19 pages/cpu s48408 r0 d29416 u77824
[    0.000000] pcpu-alloc: s48408 r0 d29416 u77824 alloc=19*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Detected VIPT I-cache on CPU0
[    0.000000] CPU features: kernel page table isolation forced ON by KASLR
[    0.000000] CPU features: detected: Kernel page table isolation (KPTI)
[    0.000000] CPU features: detected: ARM erratum 843419
[    0.000000] CPU features: detected: ARM erratum 845719
[    0.000000] CPU features: detected: ARM errata 826319, 827319, 824069, or 819472
[    0.000000] alternatives: applying boot alternatives
[    0.000000] Kernel command line: earlycon console=ttyMSM0,115200n8 ignore_loglevel loglevel=8 rdinit=/init
[    0.000000] printk: log buffer data + meta data: 131072 + 458752 = 589824 bytes
[    0.000000] Dentry cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 32768 (order: 6, 262144 bytes, linear)
[    0.000000] software IO TLB: SWIOTLB bounce buffer size adjusted to 0MB
[    0.000000] software IO TLB: area num 4.
[    0.000000] software IO TLB: SWIOTLB bounce buffer size roundup to 1MB
[    0.000000] software IO TLB: mapped [mem 0x000000009d480000-0x000000009d580000] (1MB)
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 131072
[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000] rcu: 	RCU event tracing is enabled.
[    0.000000] rcu: 	RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=4.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[    0.000000] Root IRQ handler: gic_handle_irq
[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.
[    0.000000] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.000000] arch_timer: cp15 timer running at 19.20MHz (virt).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000000] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.010989] Console: colour dummy device 80x25
[    0.018714] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=76800)
[    0.023191] pid_max: default: 32768 minimum: 301
[    0.033776] Mount-cache hash table entries: 1024 (order: 1, 8192 bytes, linear)
[    0.038208] Mountpoint-cache hash table entries: 1024 (order: 1, 8192 bytes, linear)
[    0.045585] VFS: Finished mounting rootfs on nullfs
[    0.055522] rcu: Hierarchical SRCU implementation.
[    0.057832] rcu: 	Max phase no-delay instances is 1000.
[    0.062924] Timer migration: 1 hierarchy levels; 8 children per group; 1 crossnode level
[    0.068793] smp: Bringing up secondary CPUs ...
[    0.076880] Detected VIPT I-cache on CPU1
[    0.077054] CPU1: Booted secondary processor 0x0000000001 [0x410fd030]
[    0.077902] Detected VIPT I-cache on CPU2
[    0.078062] CPU2: Booted secondary processor 0x0000000002 [0x410fd030]
[    0.078877] Detected VIPT I-cache on CPU3
[    0.079033] CPU3: Booted secondary processor 0x0000000003 [0x410fd030]
[    0.079173] smp: Brought up 1 node, 4 CPUs
[    0.111995] SMP: Total of 4 processors activated.
[    0.116057] CPU: All CPU(s) started at EL1
[    0.120853] CPU features: detected: 32-bit EL0 Support
[    0.124818] CPU features: detected: CRC32 instructions
[    0.129971] CPU features: detected: PMUv3
[    0.135112] alternatives: applying system-wide alternatives
[    0.140387] Memory: 353708K/524288K available (11904K kernel code, 3340K rwdata, 5696K rodata, 1408K init, 463K bss, 135476K reserved, 32768K cma-reserved)
[    0.145317] devtmpfs: initialized
[    0.172925] posixtimers hash table entries: 2048 (order: 3, 32768 bytes, linear)
[    0.173062] futex hash table entries: 1024 (65536 bytes on 1 NUMA nodes, total 64 KiB, linear).
[    0.180097] 2G module region forced by RANDOMIZE_MODULE_REGION_FULL
[    0.187848] 0 pages in range for non-PLT usage
[    0.187856] 518528 pages in range for PLT usage
[    0.198687] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.204062] DMA: preallocated 128 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[    0.210427] thermal_sys: Registered thermal governor 'step_wise'
[    0.210439] thermal_sys: Registered thermal governor 'power_allocator'
[    0.216995] cpuidle: using governor menu
[    0.229421] NET: Registered PF_QIPCRTR protocol family
[    0.233483] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[    0.238370] ASID allocator initialised with 32768 entries
[    0.245632] Serial: AMBA PL011 UART driver
[    0.253282] CPUidle PSCI: Initialized CPU PM domain topology using OSI mode
[    0.262441] /soc@0/usb@78d9000: Fixed dependency cycle(s) with /soc@0/usb@78d9000/ulpi/phy
[    0.262525] /soc@0/usb@78d9000/ulpi/phy: Fixed dependency cycle(s) with /soc@0/usb@78d9000
[    0.269705] /soc@0/interrupt-controller@b000000: Fixed dependency cycle(s) with /soc@0/interrupt-controller@b000000
[    0.290716] /soc@0/usb@78d9000: Fixed dependency cycle(s) with /soc@0/usb@78d9000/ulpi/phy
[    0.290875] /soc@0/usb@78d9000/ulpi/phy: Fixed dependency cycle(s) with /soc@0/usb@78d9000
[    0.300507] HugeTLB: registered 1.00 GiB page size, pre-allocated 0 pages
[    0.306174] HugeTLB: 0 KiB vmemmap can be freed for a 1.00 GiB page
[    0.313020] HugeTLB: registered 32.0 MiB page size, pre-allocated 0 pages
[    0.319087] HugeTLB: 0 KiB vmemmap can be freed for a 32.0 MiB page
[    0.326031] HugeTLB: registered 2.00 MiB page size, pre-allocated 0 pages
[    0.332105] HugeTLB: 0 KiB vmemmap can be freed for a 2.00 MiB page
[    0.339052] HugeTLB: registered 64.0 KiB page size, pre-allocated 0 pages
[    0.345124] HugeTLB: 0 KiB vmemmap can be freed for a 64.0 KiB page
[    0.357410] iommu: Default domain type: Translated
[    0.358135] iommu: DMA domain TLB invalidation policy: strict mode
[    0.364096] pps_core: LinuxPPS API ver. 1 registered
[    0.369181] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.374314] PTP clock support registered
[    0.383501] EDAC MC: Ver: 3.0.0
[    0.387687] scmi_core: SCMI protocol bus registered
[    0.391390] qcom_scm: convention: smc arm 32
[    0.395040] qcom_scm firmware:scm: SHM Bridge not supported
[    0.399738] qcom_scm firmware:scm: qseecom: found qseecom with version 0x800000
[    0.404883] qcom_scm firmware:scm: qseecom: untested machine, skipping
[    0.412885] FPGA manager framework
[    0.420263] clocksource: Switched to clocksource arch_sys_counter
[    0.422438] VFS: Disk quotas dquot_6.6.0
[    0.428342] VFS: Dquot-cache hash table entries: 512 (4096 bytes)
[    0.441401] NET: Registered PF_INET protocol family
[    0.441555] IP idents hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.445930] tcp_listen_portaddr_hash hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.452417] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.460650] TCP established hash table entries: 4096 (order: 3, 32768 bytes, linear)
[    0.468673] TCP bind hash table entries: 4096 (order: 5, 131072 bytes, linear)
[    0.476500] TCP: Hash tables configured (established 4096 bind 4096)
[    0.483468] UDP hash table entries: 256 (order: 2, 16384 bytes, linear)
[    0.490027] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    0.496548] Unpacking initramfs...
[    0.503302] Initialise system trusted keyrings
[    0.505621] workingset: timestamp_bits=46 (anon: 41) max_order=17 bucket_order=0 (anon: 0)
[    0.510327] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.518421] 9p: Installing v9fs 9p2000 file system support
[    0.524367] NET: Registered PF_ALG protocol family
[    0.529350] Key type asymmetric registered
[    0.534078] Asymmetric key parser 'x509' registered
[    0.538281] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 239)
[    0.542944] io scheduler mq-deadline registered
[    0.550584] io scheduler kyber registered
[    0.554910] io scheduler bfq registered
[    0.568153] ledtrig-cpu: registered to indicate activity on CPUs
[    0.568643] IPMI message handler: version 39.2
[    0.573362] ipmi device interface
[    0.577830] ipmi_si: IPMI System Interface driver
[    0.581142] ipmi_si: Unable to find any System Interface(s)
[    0.604525] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    0.608630] msm_serial 78b0000.serial: msm_serial: detected port #0
[    0.609682] msm_serial 78b0000.serial: uartclk = 7372800
[    0.616452] 78b0000.serial: ttyMSM0 at MMIO 0x78b0000 (irq = 17, base_baud = 460800) is a MSM
[    0.621475] msm_serial: console setup on port #0
[    0.621603] printk: legacy console [ttyMSM0] enabled
[    0.630177] printk: legacy bootconsole [msm_serial_dm0] disabled
[    0.644939] msm_serial: driver initialized
[    0.648599] qcom-iommu 1ef0000.iommu: iommu sec: pgtable size: 94208
[    0.668623] loop: module loaded
[    0.704437] spmi_pmic_arb 200f000.spmi: PMIC arbiter version v2 (0x20010000)
[    0.721375] tun: Universal TUN/TAP device driver, 1.6
[    0.722153] VFIO - User Level meta-driver version: 0.3
[    0.730536] rtc-pm8xxx 200f000.spmi:pmic@0:rtc@6000: registered as rtc0
[    0.730620] rtc-pm8xxx 200f000.spmi:pmic@0:rtc@6000: setting system clock to 1970-01-01T00:05:41 UTC (341)
[    0.737612] i2c_dev: i2c /dev entries driver
[    0.751358] input: pm8941_pwrkey as /devices/platform/soc@0/200f000.spmi/spmi-0/0-00/200f000.spmi:pmic@0:pon@800/200f000.spmi:pmic@0:pon@800:pwrkey/input/input0
[    0.763779] qcom_rng 22000.rng: TRNG support not detected
[    0.766175] clocksource: arch_mmio_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.770770] arch-timer-mmio b020000.timer: mmio timer running at 19.20MHz (virt)
[    0.787924] hw perfevents: enabled with armv8_cortex_a53 PMU driver, 7 (0,8000003f) counters available
[    0.790696]  cs_system_cfg: CoreSight Configuration manager initialised
[    0.801549] gnss: GNSS driver registered with major 505
[    0.806367] NET: Registered PF_INET6 protocol family
[    0.811312] Segment Routing with IPv6
[    0.815178] In-situ OAM (IOAM) with IPv6
[    0.818759] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    0.823366] NET: Registered PF_PACKET protocol family
[    0.828674] 9pnet: Installing 9P2000 support
[    0.833593] Key type dns_resolver registered
[    0.847894] registered taskstats version 1
[    0.847941] Loading compiled-in X.509 certificates
[    0.884023] qcom-smsm smsm: mbox_request_channel: can't parse "mboxes" property
[    0.884080] qcom-smsm smsm: mbox_request_channel: can't parse "mboxes" property
[    0.890231] qcom-smsm smsm: mbox_request_channel: can't parse "mboxes" property
[    0.928914] msm_hsusb 78d9000.usb: Failed to create device link (0x180) with supplier remoteproc for /soc@0/usb@78d9000/ulpi/phy
[    0.934875] remoteproc remoteproc0: releasing 4080000.remoteproc
[    0.949606] s3: Bringing 0uV into 1250000-1250000uV
[    0.950140] s4: Bringing 0uV into 1850000-1850000uV
[    0.954438] l2: Bringing 0uV into 1200000-1200000uV
[    0.959197] l5: Bringing 0uV into 1800000-1800000uV
[    0.963783] l6: Bringing 0uV into 1800000-1800000uV
[    0.968446] l7: Bringing 0uV into 1800000-1800000uV
[    0.973512] l8: Bringing 0uV into 2900000-2900000uV
[    0.978037] l9: Bringing 0uV into 3300000-3300000uV
[    0.983190] l11: Bringing 0uV into 2950000-2950000uV
[    0.987763] l12: Bringing 0uV into 1800000-1800000uV
[    0.992966] l13: Bringing 0uV into 3075000-3075000uV
[    0.999281] remoteproc remoteproc0: 4080000.remoteproc is available
[    1.011249] gcc-msm8916 1800000.clock-controller: sync_state() pending due to 7824900.mmc
[    1.011632] clk: Disabling unused clocks
[    1.018658] PM: genpd: Disabling unused power domains
[    1.035149] mmc0: SDHCI controller on 7824900.mmc [7824900.mmc] using ADMA
[    1.158908] mmc0: Card appears overclocked; req 177770000 Hz, actual 177777777 Hz
[    1.158967] mmc0: Card appears overclocked; req 177770000 Hz, actual 177777777 Hz
[    1.168138] mmc0: new HS200 MMC card at address 0001
[    1.173770] mmcblk0: mmc0:0001 H4G2a 3.64 GiB
[    1.183479]  mmcblk0: p1 p2 p3 p4 p5 p6 p7 p8 p9 p10 p11 p12 p13 p14 p15 p16 p17 p18 p19 p20 p21 p22 p23 p24 p25 p26 p27
[    1.188479] mmcblk0boot0: mmc0:0001 H4G2a 4.00 MiB
[    1.199928] mmcblk0boot1: mmc0:0001 H4G2a 4.00 MiB
[    1.205056] mmcblk0rpmb: mmc0:0001 H4G2a 4.00 MiB, chardev (506:0)
[    1.225467] Freeing initrd memory: 11664K
[    1.226688] Freeing unused kernel memory: 1408K
[    1.226854] Run /init as init process
[    1.230070]   with arguments:
[    1.233856]     /init
[    1.236805]   with environment:
[    1.239049]     HOME=/
[    1.242009]     TERM=linux
[    1.883468] [init] EMMC: all 30 block devices read-only (getro=1)
[    7.095632] [init] B1: modem FAT mounted RO at /firmware, firmware path /firmware/image
[    7.129630] configfs-gadget.aurora gadget.0: HOST MAC <MAC>
[    7.129671] configfs-gadget.aurora gadget.0: MAC <MAC>
[    7.135464] l13: voltage operation not allowed
[    7.146151] [init] usb gadget bound to UDC 'ci_hdrc.0'
[    7.163205] [init] ncm ifname='usb0' dev_addr=<MAC> host_addr=<MAC>
[    7.181479] [init] network: usb0 172.16.42.1/24 up (static, no DHCP)
[ 1254.832947] [b6] CYCLE 1 begin: w=0 s=0 mss=offline
[ 1254.850942] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 1254.910730] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 1254.911233] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 1254.921964] [aurora-modem] STATE OFF -> RMTFS_READY
[ 1254.927747] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 1254.960707] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 1255.505723] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 1255.598171] [aurora-modem] MSS running after 0.7s
[ 1255.604743] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 1256.097139] wwan wwan0: port wwan0at0 attached
[ 1256.097743] wwan wwan0: port wwan0at1 attached
[ 1256.273730] wwan wwan0: port wwan0qmi0 attached
[ 1256.450271] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 1258.634255] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 1258.644113] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 1258.651407] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online
[ 1258.688943] [aurora-modem] FAIL in QMI_READY: dms-set-operating-mode=online rc!=0
[ 1258.759708] [aurora-modem] rollback: full stop
[ 1258.805912] [aurora-modem] === STOP (from QMI_READY: mss=running rmtfs=1199 mm= bam=suspended)
[ 1258.888642] [aurora-modem] wwan links down, addresses/routes removed
[ 1258.897080] [aurora-modem] STATE QMI_READY -> WWAN_DOWN
[ 1258.954053] [aurora-modem] qmi-proxy stopped
[ 1258.962816] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 1258.990086] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 1259.007455] wwan wwan0: port wwan0at0 disconnected
[ 1259.007822] wwan wwan0: port wwan0at1 disconnected
[ 1259.008075] [aurora-modem] SIGTERM rmtfs 1199 (rmtfs stops MSS, then exits)
[ 1259.011560] wwan wwan0: port wwan0qmi0 disconnected
[ 1259.025285] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 1259.036158] [aurora-modem] MSS offline after 0.0s (rmtfs alive: yes)
[ 1259.041823] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 1259.269911] [aurora-modem] rmtfs exited after 0.3s
[ 1259.284044] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 1259.331182] [aurora-modem] === STOP done rc=0 in 0.5s (mss=offline rmtfs='' mm='' bam=suspended)
[ 1259.332048] [b6] CYCLE 1 start rc=1
[ 1259.571749] [b6] CYCLE 1 DATATEST not-run rc=9
[ 1259.578791] [b6] CYCLE 1 stop rc=0
[ 1265.252333] [b6] CYCLE 1 RESULT FAIL: start data nv-vs-boot (bam=suspended emmc=0/0 chan-already-open=0 dmesg-errs=0)
[ 1265.257224] [b6] STOPPING after failed cycle 1
[ 1265.276731] [b6] B6-RUN-END
[ 1375.216019] [b6] CYCLE 1 begin: w=0 s=0 mss=offline
[ 1375.234709] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 1375.297963] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 1375.298367] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 1375.309788] [aurora-modem] STATE OFF -> RMTFS_READY
[ 1375.315202] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 1375.344295] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 1375.890190] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 1375.992007] [aurora-modem] MSS running after 0.7s
[ 1375.997726] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 1376.487283] wwan wwan0: port wwan0at0 attached
[ 1376.488589] wwan wwan0: port wwan0at1 attached
[ 1376.662910] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 1376.662993] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 1376.668802] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 1376.675649] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 1376.682262] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 1376.689030] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 1376.695806] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 1376.702570] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 1376.709883] wwan wwan0: port wwan0qmi0 attached
[ 1376.844516] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 1379.026118] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 1379.038307] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 1379.092461] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 1379.100658] [aurora-modem] UIM card present, USIM app ready after 0.1s
[ 1379.106015] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 1382.346360] [aurora-modem] DMS online after 3.2s
[ 1382.351578] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 1386.502145] [aurora-modem] registered: MCC: '250' MNC: '99' Description: 'Beeline' MCC: '250' MNC: '99' after 4.1s
[ 1386.507028] [aurora-modem] STATE RADIO_ONLINE -> REGISTERED
[ 1386.555814] udevd[2164]: starting version 3.2.14
[ 1386.558490] udevd[2164]: specified group 'tty' unknown
[ 1386.559700] udevd[2164]: specified group 'dialout' unknown
[ 1386.564788] udevd[2164]: specified group 'kmem' unknown
[ 1386.570053] udevd[2164]: specified group 'input' unknown
[ 1386.575157] udevd[2164]: specified group 'video' unknown
[ 1386.580747] udevd[2164]: specified group 'audio' unknown
[ 1386.586090] udevd[2164]: specified group 'lp' unknown
[ 1386.591320] udevd[2164]: specified group 'disk' unknown
[ 1386.596294] udevd[2164]: specified group 'cdrom' unknown
[ 1386.627736] udevd[2165]: starting eudev-3.2.14
[ 1386.993495] [aurora-modem] udevd started
[ 1387.021547] [aurora-modem] dbus started
[ 1387.035419] [aurora-modem] polkitd started
[ 1387.054818] [aurora-modem] ModemManager started pid 2210 (log mm-0.log)
[ 1435.780952] [aurora-modem] MM modem 0 detected after 48.7s
[ 1435.884808] [aurora-modem] STATE REGISTERED -> MM_READY
[ 1497.118929] [aurora-modem] FAIL in MM_READY: MM state 'disabled' not registered after 60s
[ 1497.319812] [aurora-modem] rollback: full stop
[ 1497.371332] [aurora-modem] === STOP (from MM_READY: mss=running rmtfs=1913 mm=2210 bam=suspended)
[ 1497.579422] [aurora-modem] wwan links down, addresses/routes removed
[ 1497.591264] [aurora-modem] STATE MM_READY -> WWAN_DOWN
[ 1498.717014] [aurora-modem] ModemManager stopped
[ 1498.755046] [aurora-modem] qmi-proxy stopped
[ 1498.760536] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 1498.785958] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 1498.803966] [aurora-modem] SIGTERM rmtfs 1913 (rmtfs stops MSS, then exits)
[ 1498.805372] wwan wwan0: port wwan0at0 disconnected
[ 1498.811333] wwan wwan0: port wwan0at1 disconnected
[ 1498.815155] wwan wwan0: port wwan0qmi0 disconnected
[ 1498.824505] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 1499.045678] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 1499.053764] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 1499.069944] [aurora-modem] rmtfs exited after 0.3s
[ 1499.085757] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 1499.133871] [aurora-modem] === STOP done rc=0 in 1.8s (mss=offline rmtfs='' mm='' bam=suspended)
[ 1499.134717] [b6] CYCLE 1 start rc=1
[ 1499.378521] [b6] CYCLE 1 DATATEST not-run rc=9
[ 1499.387558] [b6] CYCLE 1 stop rc=0
[ 1505.036053] [b6] CYCLE 1 RESULT FAIL: start data (bam=suspended emmc=0/0 chan-already-open=8 dmesg-errs=0)
[ 1505.039325] [b6] STOPPING after failed cycle 1
[ 1505.142244] [b6] B6-RUN-END
[ 1540.812157] [b6] CYCLE 1 begin: w=0 s=0 mss=offline
[ 1540.831292] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 1540.838016] [aurora-modem] SAFETY: modemst1 not RO
[ 1540.842340] [aurora-modem] FAIL: safety gate (RO) - nothing started
[ 1540.845482] [b6] CYCLE 1 start rc=1
[ 1541.081848] [b6] CYCLE 1 DATATEST not-run rc=9
[ 1541.088777] [b6] CYCLE 1 stop rc=1
[ 1546.723975] [b6] CYCLE 1 RESULT FAIL: start data stop (bam=suspended emmc=0/0 chan-already-open=0 dmesg-errs=0)
[ 1546.727270] [b6] STOPPING after failed cycle 1
[ 1546.833864] [b6] B6-RUN-END
[ 1589.082642] [b6] CYCLE 1 begin: w=0 s=0 mss=offline
[ 1589.100512] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 1589.161752] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 1589.162192] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 1589.173022] [aurora-modem] STATE OFF -> RMTFS_READY
[ 1589.178254] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 1589.212540] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 1589.757345] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 1589.846712] [aurora-modem] MSS running after 0.7s
[ 1589.852709] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 1590.324249] wwan wwan0: port wwan0at0 attached
[ 1590.327678] wwan wwan0: port wwan0at1 attached
[ 1590.501913] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 1590.501973] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 1590.507846] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 1590.514538] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 1590.521259] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 1590.528024] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 1590.534806] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 1590.541565] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 1590.548907] wwan wwan0: port wwan0qmi0 attached
[ 1590.698758] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 1592.881169] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 1592.891836] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 1592.944445] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 1592.952865] [aurora-modem] UIM card present, USIM app ready after 0.1s
[ 1592.958954] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 1596.200411] [aurora-modem] DMS online after 3.2s
[ 1596.205831] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 1602.400979] [aurora-modem] registered: MCC: '250' MNC: '99' Description: 'Beeline' MCC: '250' MNC: '99' after 6.2s
[ 1602.406386] [aurora-modem] STATE RADIO_ONLINE -> REGISTERED
[ 1602.501306] [aurora-modem] ModemManager started pid 4474 (log mm-1.log)
[ 1640.777033] [aurora-modem] MM modem 0 detected after 38.3s
[ 1640.880083] [aurora-modem] STATE REGISTERED -> MM_READY
[ 1641.083922] [aurora-modem] MM state disabled after 0.2s
[ 1641.202187] [aurora-modem] mmcli -m 0 --simple-connect="apn=internet.beeline.ru,user=beeline,password=***,allowed-auth=pap,ip-type=ipv4"
[ 1651.951288] [aurora-modem] FAIL in MM_READY: no connected bearer after simple-connect
[ 1652.173555] [aurora-modem] rollback: full stop
[ 1652.226902] [aurora-modem] === STOP (from MM_READY: mss=running rmtfs=4194 mm=4474 bam=suspended)
[ 1652.426046] [aurora-modem] wwan links down, addresses/routes removed
[ 1652.434857] [aurora-modem] STATE MM_READY -> WWAN_DOWN
[ 1655.675937] [aurora-modem] ModemManager stopped
[ 1655.715539] [aurora-modem] qmi-proxy stopped
[ 1655.721582] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 1655.750232] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 1655.769254] wwan wwan0: port wwan0at0 disconnected
[ 1655.769688] wwan wwan0: port wwan0at1 disconnected
[ 1655.770239] [aurora-modem] SIGTERM rmtfs 4194 (rmtfs stops MSS, then exits)
[ 1655.773869] wwan wwan0: port wwan0qmi0 disconnected
[ 1655.787742] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 1656.017505] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 1656.023337] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 1656.040065] [aurora-modem] rmtfs exited after 0.3s
[ 1656.057763] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 1656.106906] [aurora-modem] === STOP done rc=0 in 3.9s (mss=offline rmtfs='' mm='' bam=suspended)
[ 1656.107750] [b6] CYCLE 1 start rc=1
[ 1656.359503] [b6] CYCLE 1 DATATEST not-run rc=9
[ 1656.366818] [b6] CYCLE 1 stop rc=0
[ 1662.035860] [b6] CYCLE 1 RESULT FAIL: start data (bam=suspended emmc=0/0 chan-already-open=8 dmesg-errs=0)
[ 1662.039213] [b6] STOPPING after failed cycle 1
[ 1662.255907] [b6] B6-RUN-END
[ 1742.770969] [b6] CYCLE 1 begin: w=0 s=0 mss=offline
[ 1742.789942] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 1742.851710] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 1742.852111] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 1742.863893] [aurora-modem] STATE OFF -> RMTFS_READY
[ 1742.868528] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 1742.896546] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 1743.443222] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 1743.539419] [aurora-modem] MSS running after 0.7s
[ 1743.546455] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 1744.011700] wwan wwan0: port wwan0at0 attached
[ 1744.013600] wwan wwan0: port wwan0at1 attached
[ 1744.189180] wwan wwan0: port wwan0qmi0 attached
[ 1744.190144] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 1744.192704] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 1744.199541] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 1744.206264] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 1744.213030] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 1744.219799] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 1744.226570] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 1744.233340] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 1744.393808] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 1746.574644] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 1746.585610] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 1746.634831] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 1746.642472] [aurora-modem] UIM card present, USIM app ready after 0.0s
[ 1746.649560] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 1749.881027] [aurora-modem] DMS online after 3.2s
[ 1749.886368] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 1754.037209] [aurora-modem] registered: MCC: '250' MNC: '99' Description: 'Beeline' MCC: '250' MNC: '99' after 4.1s
[ 1754.042530] [aurora-modem] STATE RADIO_ONLINE -> REGISTERED
[ 1754.137776] [aurora-modem] ModemManager started pid 5802 (log mm-2.log)
[ 1802.891219] [aurora-modem] MM modem 0 detected after 48.8s
[ 1802.998183] [aurora-modem] STATE REGISTERED -> MM_READY
[ 1803.196878] [aurora-modem] MM state disabled after 0.2s
[ 1803.318124] [aurora-modem] mmcli -m 0 --simple-connect="apn=internet.beeline.ru,user=beeline,password=***,allowed-auth=pap,ip-type=ipv4"
[ 1813.903853] [aurora-modem] FAIL in MM_READY: no connected bearer after simple-connect
[ 1814.139892] [aurora-modem] rollback: full stop
[ 1814.191562] [aurora-modem] === STOP (from MM_READY: mss=running rmtfs=5537 mm=5802 bam=suspended)
[ 1814.788140] [aurora-modem] simple-disconnect rc=0 (bearers: )
[ 1814.907585] [aurora-modem] no bearer connected
[ 1814.973884] [aurora-modem] wwan links down, addresses/routes removed
[ 1814.984180] [aurora-modem] STATE MM_READY -> WWAN_DOWN
[ 1817.680185] [aurora-modem] ModemManager stopped
[ 1817.730923] [aurora-modem] qmi-proxy stopped
[ 1817.741668] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 1817.783265] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 1817.808559] [aurora-modem] SIGTERM rmtfs 5537 (rmtfs stops MSS, then exits)
[ 1817.810384] wwan wwan0: port wwan0at0 disconnected
[ 1817.814962] wwan wwan0: port wwan0at1 disconnected
[ 1817.821184] wwan wwan0: port wwan0qmi0 disconnected
[ 1817.828707] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 1818.050203] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 1818.056020] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 1818.071792] [aurora-modem] rmtfs exited after 0.3s
[ 1818.086145] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 1818.134936] [aurora-modem] === STOP done rc=0 in 4.0s (mss=offline rmtfs='' mm='' bam=suspended)
[ 1818.135692] [b6] CYCLE 1 start rc=1
[ 1818.386116] [b6] CYCLE 1 DATATEST not-run rc=9
[ 1818.393705] [b6] CYCLE 1 stop rc=0
[ 1824.067246] [b6] CYCLE 1 RESULT FAIL: start data (bam=suspended emmc=0/0 chan-already-open=8 dmesg-errs=0)
[ 1824.071150] [b6] STOPPING after failed cycle 1
[ 1824.402190] [b6] B6-RUN-END
[ 1835.986525] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 1836.050130] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 1836.050536] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 1836.061481] [aurora-modem] STATE OFF -> RMTFS_READY
[ 1836.066841] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 1836.096525] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 1836.638015] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 1836.737312] [aurora-modem] MSS running after 0.7s
[ 1836.744031] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 1837.205107] wwan wwan0: port wwan0at0 attached
[ 1837.208103] wwan wwan0: port wwan0at1 attached
[ 1837.375509] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 1837.375569] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 1837.381380] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 1837.388117] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 1837.394855] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 1837.401745] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 1837.408414] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 1837.415157] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 1837.422461] wwan wwan0: port wwan0qmi0 attached
[ 1837.591953] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 1839.774368] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 1839.785758] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 1839.834579] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 1839.842131] [aurora-modem] UIM card present, USIM app ready after 0.0s
[ 1839.849985] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 1843.088760] [aurora-modem] DMS online after 3.2s
[ 1843.093898] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 2023.273096] [aurora-modem] FAIL in RADIO_ONLINE: not registered+PS attached after 180s (	Registration state: 'not-registered-searching')
[ 2023.345938] [aurora-modem] rollback: full stop
[ 2023.395199] [aurora-modem] === STOP (from RADIO_ONLINE: mss=running rmtfs=7006 mm= bam=suspended)
[ 2023.494667] [aurora-modem] wwan links down, addresses/routes removed
[ 2023.506887] [aurora-modem] STATE RADIO_ONLINE -> WWAN_DOWN
[ 2023.562995] [aurora-modem] qmi-proxy stopped
[ 2023.569743] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 2023.596928] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 2023.616786] wwan wwan0: port wwan0at0 disconnected
[ 2023.617217] wwan wwan0: port wwan0at1 disconnected
[ 2023.617391] [aurora-modem] SIGTERM rmtfs 7006 (rmtfs stops MSS, then exits)
[ 2023.622250] wwan wwan0: port wwan0qmi0 disconnected
[ 2023.639950] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 2023.866047] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 2023.873617] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 2023.887566] [aurora-modem] rmtfs exited after 0.3s
[ 2023.903103] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 2023.954984] [aurora-modem] === STOP done rc=0 in 0.6s (mss=offline rmtfs='' mm='' bam=suspended)
[ 2198.217704] [b6] CYCLE 1 begin: w=0 s=0 mss=offline
[ 2198.236709] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 2198.297484] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 2198.297896] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 2198.308988] [aurora-modem] STATE OFF -> RMTFS_READY
[ 2198.314249] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 2198.348522] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 2198.893192] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 2198.985405] [aurora-modem] MSS running after 0.7s
[ 2198.990738] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 2199.456294] wwan wwan0: port wwan0at0 attached
[ 2199.458601] wwan wwan0: port wwan0at1 attached
[ 2199.629327] wwan wwan0: port wwan0qmi0 attached
[ 2199.630589] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 2199.632771] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 2199.639707] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 2199.646416] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 2199.653182] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 2199.659950] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 2199.666925] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 2199.673514] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 2199.834465] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 2202.015510] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 2202.026415] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 2202.076615] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 2202.083902] [aurora-modem] UIM card present, USIM app ready after 0.0s
[ 2202.089211] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 2205.328833] [aurora-modem] DMS online after 3.2s
[ 2205.334184] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 2258.653866] [aurora-modem] registered: MCC: '250' MNC: '99' Description: 'Beeline' MCC: '250' MNC: '99' after 53.3s
[ 2258.659242] [aurora-modem] STATE RADIO_ONLINE -> REGISTERED
[ 2258.750795] [aurora-modem] ModemManager started pid 8949 (log mm-3.log)
[ 2310.130942] [aurora-modem] MM modem 0 detected after 51.4s
[ 2310.233879] [aurora-modem] STATE REGISTERED -> MM_READY
[ 2310.431170] [aurora-modem] MM state disabled after 0.2s
[ 2310.576187] [aurora-modem] mmcli -m 0 --simple-connect="apn=internet.beeline.ru,user=beeline,password=***,allowed-auth=pap,ip-type=ipv4"
[ 2322.529577] [aurora-modem] MM state connected, registration: home
[ 2322.609873] [aurora-modem] bearer 1: wwan0 10.36.235.65/30 gw 10.36.235.66 dns 10.10.22.3,194.186.191.1 mtu 1500
[ 2322.670505] [aurora-modem] STATE MM_READY -> BEARER_CONNECTED
[ 2322.684324] [aurora-modem] === START OK in 124.4s (wwan0 10.36.235.65/30, routes: 10.10.22.3 194.186.191.1 77.88.8.8 1.1.1.1 )
[ 2322.686688] [b6] CYCLE 1 start rc=0
[ 2328.450930] [b6] CYCLE 1 DATATEST PASS dns=1(ya=5.255.255.242 go=142.251.150.119) ping=3+3 http=code=302 https=[code=204 code=200 ](1) if=wwan0 addr=10.36.235.65 rc=0
[ 2328.508675] [aurora-modem] === STOP (from BEARER_CONNECTED: mss=running rmtfs=8420 mm=8949 bam=active)
[ 2329.144641] [aurora-modem] simple-disconnect rc=0 (bearers: 1 )
[ 2329.313029] [aurora-modem] no bearer connected
[ 2329.401426] [aurora-modem] wwan links down, addresses/routes removed
[ 2329.410401] [aurora-modem] STATE BEARER_CONNECTED -> WWAN_DOWN
[ 2332.104822] [aurora-modem] ModemManager stopped
[ 2332.143828] [aurora-modem] qmi-proxy stopped
[ 2332.149245] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 2332.173329] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 2332.190938] wwan wwan0: port wwan0at0 disconnected
[ 2332.191435] wwan wwan0: port wwan0at1 disconnected
[ 2332.191782] [aurora-modem] SIGTERM rmtfs 8420 (rmtfs stops MSS, then exits)
[ 2332.195507] wwan wwan0: port wwan0qmi0 disconnected
[ 2332.213489] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 2332.438717] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 2332.445370] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 2332.458953] [aurora-modem] rmtfs exited after 0.3s
[ 2332.475278] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 2332.526914] [aurora-modem] === STOP done rc=0 in 4.0s (mss=offline rmtfs='' mm='' bam=suspended)
[ 2332.527759] [b6] CYCLE 1 stop rc=0
[ 2338.204203] [b6] CYCLE 1 RESULT PASS (bam=suspended emmc=0/0 chan-already-open=8 dmesg-errs=0)
[ 2343.650674] [b6] B6-RUN-END
[ 2385.690129] [b6] CYCLE 2 begin: w=0 s=0 mss=offline
[ 2385.708648] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 2385.773421] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 2385.773855] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 2385.784800] [aurora-modem] STATE OFF -> RMTFS_READY
[ 2385.790146] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 2385.824527] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 2386.370326] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 2386.457804] [aurora-modem] MSS running after 0.7s
[ 2386.463139] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 2386.938441] wwan wwan0: port wwan0at0 attached
[ 2386.942680] wwan wwan0: port wwan0at1 attached
[ 2387.114856] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 2387.114906] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 2387.120821] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 2387.127468] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 2387.134192] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 2387.140961] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 2387.147729] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 2387.154499] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 2387.161653] wwan wwan0: port wwan0qmi0 attached
[ 2387.307177] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 2389.489536] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 2389.501984] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 2389.556193] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 2389.564004] [aurora-modem] UIM card present, USIM app ready after 0.1s
[ 2389.570548] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 2392.815126] [aurora-modem] DMS online after 3.2s
[ 2392.820130] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 2573.094092] [aurora-modem] FAIL in RADIO_ONLINE: not registered+PS attached after 180s (	Registration state: 'not-registered-searching')
[ 2573.171040] [aurora-modem] rollback: full stop
[ 2573.222957] [aurora-modem] === STOP (from RADIO_ONLINE: mss=running rmtfs=10409 mm= bam=suspended)
[ 2573.319382] [aurora-modem] wwan links down, addresses/routes removed
[ 2573.330612] [aurora-modem] STATE RADIO_ONLINE -> WWAN_DOWN
[ 2573.386561] [aurora-modem] qmi-proxy stopped
[ 2573.392470] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 2573.418767] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 2573.436649] wwan wwan0: port wwan0at0 disconnected
[ 2573.437128] wwan wwan0: port wwan0at1 disconnected
[ 2573.437309] [aurora-modem] SIGTERM rmtfs 10409 (rmtfs stops MSS, then exits)
[ 2573.442745] wwan wwan0: port wwan0qmi0 disconnected
[ 2573.458374] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 2573.682000] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 2573.689545] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 2573.706750] [aurora-modem] rmtfs exited after 0.3s
[ 2573.721349] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 2573.770522] [aurora-modem] === STOP done rc=0 in 0.6s (mss=offline rmtfs='' mm='' bam=suspended)
[ 2573.771287] [b6] CYCLE 2 start rc=1
[ 2574.033086] [b6] CYCLE 2 DATATEST not-run rc=9
[ 2574.041748] [b6] CYCLE 2 stop rc=0
[ 2579.696315] [b6] CYCLE 2 RESULT FAIL: start data (bam=suspended emmc=0/0 chan-already-open=8 dmesg-errs=0)
[ 2579.699488] [b6] STOPPING after failed cycle 2
[ 2580.149893] [b6] B6-RUN-END
[ 2679.662748] [b6] CYCLE 3 begin: w=0 s=0 mss=offline
[ 2679.682460] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 2679.742292] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 2679.742709] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 2679.753874] [aurora-modem] STATE OFF -> RMTFS_READY
[ 2679.758649] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 2679.788581] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 2680.333324] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 2680.427629] [aurora-modem] MSS running after 0.7s
[ 2680.433474] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 2680.905317] wwan wwan0: port wwan0at0 attached
[ 2680.908230] wwan wwan0: port wwan0at1 attached
[ 2681.058209] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 2681.058258] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 2681.064101] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 2681.071103] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 2681.077567] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 2681.084337] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 2681.091086] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 2681.097858] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 2681.104922] wwan wwan0: port wwan0qmi0 attached
[ 2681.276577] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 2683.457920] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 2683.468353] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 2683.522736] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 2683.530774] [aurora-modem] UIM card present, USIM app ready after 0.1s
[ 2683.537565] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 2686.782115] [aurora-modem] DMS online after 3.2s
[ 2686.788882] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 2695.030332] [aurora-modem] registered: MCC: '250' MNC: '99' Description: 'Beeline' MCC: '250' MNC: '99' after 8.2s
[ 2695.035636] [aurora-modem] STATE RADIO_ONLINE -> REGISTERED
[ 2695.122928] [aurora-modem] ModemManager started pid 12526 (log mm-4.log)
[ 2733.614214] [aurora-modem] MM modem 0 detected after 38.5s
[ 2733.717773] [aurora-modem] STATE REGISTERED -> MM_READY
[ 2733.909806] [aurora-modem] MM state disabled after 0.2s
[ 2734.055651] [aurora-modem] mmcli -m 0 --simple-connect="apn=internet.beeline.ru,user=beeline,password=***,allowed-auth=pap,ip-type=ipv4"
[ 2745.169275] [aurora-modem] MM state connected, registration: home
[ 2745.249349] [aurora-modem] bearer 1: wwan0 10.80.24.242/30 gw 10.80.24.241 dns 10.10.22.1,194.186.191.1 mtu 1430
[ 2745.318271] [aurora-modem] STATE MM_READY -> BEARER_CONNECTED
[ 2745.330836] [aurora-modem] === START OK in 65.6s (wwan0 10.80.24.242/30, routes: 10.10.22.1 194.186.191.1 77.88.8.8 1.1.1.1 )
[ 2745.331669] [b6] CYCLE 3 start rc=0
[ 2751.987652] [b6] CYCLE 3 DATATEST PASS dns=1(ya=5.255.255.242 go=142.251.150.119) ping=3+3 http=code=302 https=[code=204 code=200 ](1) if=wwan0 addr=10.80.24.242 rc=0
[ 2752.058891] [aurora-modem] === STOP (from BEARER_CONNECTED: mss=running rmtfs=12238 mm=12526 bam=active)
[ 2753.969401] [aurora-modem] simple-disconnect rc=0 (bearers: 1 )
[ 2754.162457] [aurora-modem] no bearer connected
[ 2757.178335] [aurora-modem] MM disable rc=0 -> state disabled (radio low-power, detached)
[ 2757.272027] [aurora-modem] wwan links down, addresses/routes removed
[ 2757.282040] [aurora-modem] STATE BEARER_CONNECTED -> WWAN_DOWN
[ 2758.908650] [aurora-modem] ModemManager stopped
[ 2758.951345] [aurora-modem] qmi-proxy stopped
[ 2758.958972] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 2758.985607] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 2759.003962] wwan wwan0: port wwan0at0 disconnected
[ 2759.004473] wwan wwan0: port wwan0at1 disconnected
[ 2759.004822] [aurora-modem] SIGTERM rmtfs 12238 (rmtfs stops MSS, then exits)
[ 2759.008777] wwan wwan0: port wwan0qmi0 disconnected
[ 2759.024817] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 2759.249917] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 2759.257182] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 2759.270968] [aurora-modem] rmtfs exited after 0.3s
[ 2759.286453] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 2759.334121] [aurora-modem] === STOP done rc=0 in 7.3s (mss=offline rmtfs='' mm='' bam=suspended)
[ 2759.334877] [b6] CYCLE 3 stop rc=0
[ 2765.016239] [b6] CYCLE 3 RESULT PASS (bam=suspended emmc=0/0 chan-already-open=8 dmesg-errs=0)
[ 2770.047074] [b6] CYCLE 4 begin: w=0 s=0 mss=offline
[ 2770.067251] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 2770.130454] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 2770.130897] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 2770.141481] [aurora-modem] STATE OFF -> RMTFS_READY
[ 2770.146986] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 2770.176514] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 2770.717387] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 2770.814757] [aurora-modem] MSS running after 0.7s
[ 2770.820094] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 2771.289491] wwan wwan0: port wwan0at0 attached
[ 2771.290549] wwan wwan0: port wwan0at1 attached
[ 2771.465752] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 2771.465798] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 2771.471672] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 2771.478366] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 2771.485097] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 2771.491856] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 2771.498627] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 2771.505395] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 2771.512865] wwan wwan0: port wwan0qmi0 attached
[ 2771.670076] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 2773.850455] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 2773.862087] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 2773.914374] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 2773.922520] [aurora-modem] UIM card present, USIM app ready after 0.1s
[ 2773.927850] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 2777.169373] [aurora-modem] DMS online after 3.2s
[ 2777.175153] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 2957.388250] [aurora-modem] FAIL in RADIO_ONLINE: not registered+PS attached after 180s (	Registration state: 'registration-denied')
[ 2957.468217] [aurora-modem] rollback: full stop
[ 2957.519193] [aurora-modem] === STOP (from RADIO_ONLINE: mss=running rmtfs=13909 mm= bam=suspended)
[ 2957.586081] [aurora-modem] qmicli low-power rc=0 (MM not running)
[ 2957.660934] [aurora-modem] wwan links down, addresses/routes removed
[ 2957.669642] [aurora-modem] STATE RADIO_ONLINE -> WWAN_DOWN
[ 2957.728663] [aurora-modem] qmi-proxy stopped
[ 2957.734755] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 2957.761768] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 2957.779983] wwan wwan0: port wwan0at0 disconnected
[ 2957.780397] [aurora-modem] SIGTERM rmtfs 13909 (rmtfs stops MSS, then exits)
[ 2957.780684] wwan wwan0: port wwan0at1 disconnected
[ 2957.791575] wwan wwan0: port wwan0qmi0 disconnected
[ 2957.802325] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 2958.022106] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 2958.030626] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 2958.044595] [aurora-modem] rmtfs exited after 0.3s
[ 2958.058831] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 2958.107043] [aurora-modem] === STOP done rc=0 in 0.6s (mss=offline rmtfs='' mm='' bam=suspended)
[ 2958.107812] [b6] CYCLE 4 start rc=1
[ 2958.373346] [b6] CYCLE 4 DATATEST not-run rc=9
[ 2958.382505] [b6] CYCLE 4 stop rc=0
[ 2964.075995] [b6] CYCLE 4 RESULT FAIL: start data (bam=suspended emmc=0/0 chan-already-open=8 dmesg-errs=0)
[ 2964.079298] [b6] STOPPING after failed cycle 4
[ 2964.657819] [b6] B6-RUN-END
[ 3024.376590] [b6] CYCLE 5 begin: w=0 s=0 mss=offline
[ 3024.395842] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 3024.458492] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 3024.458905] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 3024.470171] [aurora-modem] STATE OFF -> RMTFS_READY
[ 3024.474996] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 3024.508435] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 3025.049372] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 3025.142701] [aurora-modem] MSS running after 0.7s
[ 3025.148149] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 3025.618589] wwan wwan0: port wwan0at0 attached
[ 3025.619309] wwan wwan0: port wwan0at1 attached
[ 3025.804087] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 3025.804138] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 3025.810350] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 3025.816709] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 3025.823430] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 3025.830197] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 3025.836981] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 3025.843738] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 3025.850735] wwan wwan0: port wwan0qmi0 attached
[ 3025.993255] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 3028.180904] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 3028.191376] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 3028.242345] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 3028.251685] [aurora-modem] UIM card present, USIM app ready after 0.1s
[ 3028.259921] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 3031.501709] [aurora-modem] DMS online after 3.2s
[ 3031.506575] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 3047.943366] [aurora-modem] registered: MCC: '250' MNC: '99' Description: 'Beeline' MCC: '250' MNC: '99' after 16.4s
[ 3047.948812] [aurora-modem] STATE RADIO_ONLINE -> REGISTERED
[ 3048.042406] [aurora-modem] ModemManager started pid 16084 (log mm-5.log)
[ 3088.099127] [aurora-modem] MM modem 0 detected after 40.1s
[ 3088.206626] [aurora-modem] STATE REGISTERED -> MM_READY
[ 3088.406263] [aurora-modem] MM state disabled after 0.2s
[ 3088.551974] [aurora-modem] mmcli -m 0 --simple-connect="apn=internet.beeline.ru,user=beeline,password=***,allowed-auth=pap,ip-type=ipv4"
[ 3099.276065] [aurora-modem] MM state connected, registration: home
[ 3099.357574] [aurora-modem] bearer 1: wwan0 10.84.104.151/28 gw 10.84.104.152 dns 10.10.22.1,194.186.191.1 mtu 1430
[ 3099.416715] [aurora-modem] STATE MM_READY -> BEARER_CONNECTED
[ 3099.430053] [aurora-modem] === START OK in 75.0s (wwan0 10.84.104.151/28, routes: 10.10.22.1 194.186.191.1 77.88.8.8 1.1.1.1 )
[ 3099.430906] [b6] CYCLE 5 start rc=0
[ 3105.099232] [b6] CYCLE 5 DATATEST PASS dns=1(ya=5.255.255.242 go=142.251.150.119) ping=3+3 http=code=302 https=[code=204 code=200 ](1) if=wwan0 addr=10.84.104.151 rc=0
[ 3105.159867] [aurora-modem] === STOP (from BEARER_CONNECTED: mss=running rmtfs=15751 mm=16084 bam=active)
[ 3105.793047] [aurora-modem] simple-disconnect rc=0 (bearers: 1 )
[ 3105.968112] [aurora-modem] no bearer connected
[ 3107.613689] [aurora-modem] MM disable rc=0 -> state disabled (radio low-power, detached)
[ 3107.696592] [aurora-modem] wwan links down, addresses/routes removed
[ 3107.705663] [aurora-modem] STATE BEARER_CONNECTED -> WWAN_DOWN
[ 3109.340406] [aurora-modem] ModemManager stopped
[ 3109.383293] [aurora-modem] qmi-proxy stopped
[ 3109.389879] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 3109.416210] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 3109.446180] wwan wwan0: port wwan0at0 disconnected
[ 3109.446783] wwan wwan0: port wwan0at1 disconnected
[ 3109.446967] [aurora-modem] SIGTERM rmtfs 15751 (rmtfs stops MSS, then exits)
[ 3109.452075] wwan wwan0: port wwan0qmi0 disconnected
[ 3109.464864] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 3109.691492] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 3109.698851] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 3109.716113] [aurora-modem] rmtfs exited after 0.3s
[ 3109.733481] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 3109.782115] [aurora-modem] === STOP done rc=0 in 4.6s (mss=offline rmtfs='' mm='' bam=suspended)
[ 3109.782865] [b6] CYCLE 5 stop rc=0
[ 3115.462909] [b6] CYCLE 5 RESULT PASS (bam=suspended emmc=0/0 chan-already-open=8 dmesg-errs=0)
[ 3120.495331] [b6] CYCLE 6 begin: w=0 s=0 mss=offline
[ 3120.515790] [aurora-modem] === START (conf /tmp/aurora-modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 3120.589376] [aurora-modem] re-attach holdoff: last radio stop 11.1s ago, waiting 109s (MODEM_REATTACH_HOLDOFF=120)
[ 3229.600839] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 3229.601272] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 3229.613252] [aurora-modem] STATE OFF -> RMTFS_READY
[ 3229.618249] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 3229.648593] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 3230.190321] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 3230.291162] [aurora-modem] MSS running after 0.7s
[ 3230.296641] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 3230.760076] wwan wwan0: port wwan0at0 attached
[ 3230.763975] wwan wwan0: port wwan0at1 attached
[ 3230.940940] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 3230.940992] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 3230.946788] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 3230.953650] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 3230.960295] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 3230.967045] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 3230.973814] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 3230.980585] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 3230.988004] wwan wwan0: port wwan0qmi0 attached
[ 3231.145967] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 3233.326156] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 3233.337596] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 3233.385597] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 3233.393066] [aurora-modem] UIM card present, USIM app ready after 0.0s
[ 3233.399778] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 3236.632037] [aurora-modem] DMS online after 3.2s
[ 3236.637312] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 3416.980718] [aurora-modem] FAIL in RADIO_ONLINE: not registered+PS attached after 180s (	Registration state: 'not-registered-searching')
[ 3417.058116] [aurora-modem] rollback: full stop
[ 3417.111391] [aurora-modem] === STOP (from RADIO_ONLINE: mss=running rmtfs=17500 mm= bam=suspended)
[ 3417.170708] [aurora-modem] qmicli low-power rc=0 (MM not running)
[ 3417.245517] [aurora-modem] wwan links down, addresses/routes removed
[ 3417.258901] [aurora-modem] STATE RADIO_ONLINE -> WWAN_DOWN
[ 3417.320045] [aurora-modem] qmi-proxy stopped
[ 3417.329096] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 3417.360172] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 3417.392535] wwan wwan0: port wwan0at0 disconnected
[ 3417.392652] [aurora-modem] SIGTERM rmtfs 17500 (rmtfs stops MSS, then exits)
[ 3417.392943] wwan wwan0: port wwan0at1 disconnected
[ 3417.405759] wwan wwan0: port wwan0qmi0 disconnected
[ 3417.413352] qcom-q6v5-mss 4080000.remoteproc: port failed halt
[ 3417.413614] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 3417.635306] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 3417.642487] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 3417.658981] [aurora-modem] rmtfs exited after 0.3s
[ 3417.674598] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 3417.723739] [aurora-modem] === STOP done rc=0 in 0.6s (mss=offline rmtfs='' mm='' bam=suspended)
[ 3417.724759] [b6] CYCLE 6 start rc=1
[ 3417.973999] [b6] CYCLE 6 DATATEST not-run rc=9
[ 3417.983134] [b6] CYCLE 6 stop rc=0
[ 3423.644034] [b6] CYCLE 6 RESULT FAIL: start data (bam=suspended emmc=0/0 chan-already-open=8 dmesg-errs=0)
[ 3423.647335] [b6] STOPPING after failed cycle 6
[ 3424.341919] [b6] B6-RUN-END
[ 6694.516819] [j1] CYCLE 1 begin: emmc w=0 s=0 mss=offline rmtfs=''
[ 6694.540131] [aurora-modem] === START (conf /tmp/j1.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 6694.609472] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 6694.609845] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 6694.621199] [aurora-modem] STATE OFF -> RMTFS_READY
[ 6694.626527] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 6694.656524] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 6695.196652] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 6695.295360] [aurora-modem] MSS running after 0.7s
[ 6695.300998] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 6695.768859] wwan wwan0: port wwan0at0 attached
[ 6695.770830] wwan wwan0: port wwan0at1 attached
[ 6695.944345] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 6695.944408] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 6695.950196] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 6695.957056] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 6695.963699] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 6695.970458] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 6695.977228] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 6695.983997] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 6695.991201] wwan wwan0: port wwan0qmi0 attached
[ 6696.146297] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 6698.325929] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 6698.337186] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 6698.389759] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 6698.398560] [aurora-modem] UIM card present, USIM app ready after 0.1s
[ 6698.405794] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 6701.635963] [aurora-modem] DMS online after 3.2s
[ 6701.642542] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 6705.794748] [aurora-modem] registered: MCC: '250' MNC: '99' Description: 'Beeline' MCC: '250' MNC: '99' after 4.2s
[ 6705.800099] [aurora-modem] STATE RADIO_ONLINE -> REGISTERED
[ 6706.026185] [aurora-modem] ModemManager started pid 19880 (log mm-6.log)
[ 6754.376894] [aurora-modem] MM modem 0 detected after 48.3s
[ 6754.482620] [aurora-modem] STATE REGISTERED -> MM_READY
[ 6754.675973] [aurora-modem] MM state disabled after 0.2s
[ 6754.821610] [aurora-modem] mmcli -m 0 --simple-connect="apn=internet.beeline.ru,user=beeline,password=***,allowed-auth=pap,ip-type=ipv4"
[ 6765.521865] [aurora-modem] MM state connected, registration: home
[ 6765.607991] [aurora-modem] bearer 1: wwan0 10.45.73.171/29 gw 10.45.73.172 dns 10.10.22.3,194.186.191.1 mtu 1500
[ 6765.676981] [aurora-modem] STATE MM_READY -> BEARER_CONNECTED
[ 6765.687983] [aurora-modem] === START OK in 71.1s (wwan0 10.45.73.171/29, routes: 10.10.22.3 194.186.191.1 77.88.8.8 1.1.1.1 )
[ 6765.688979] [j1] CYCLE 1 start rc=0
[ 6771.459094] [j1] CYCLE 1 DATATEST PASS dns=1(ya=5.255.255.242 go=142.251.150.119) ping=3+3 http=code=302 https=[code=204 code=200 ](1) if=wwan0 addr=10.45.73.171 rc=0
[ 6771.520388] [aurora-modem] === STOP (from BEARER_CONNECTED: mss=running rmtfs=19591 mm=19880 bam=active)
[ 6772.157533] [aurora-modem] simple-disconnect rc=0 (bearers: 1 )
[ 6772.329859] [aurora-modem] no bearer connected
[ 6772.332249] [aurora-modem] MODEM_STOP_DISABLE=0: no MM disable
[ 6772.417401] [aurora-modem] wwan links down, addresses/routes removed
[ 6772.428158] [aurora-modem] STATE BEARER_CONNECTED -> WWAN_DOWN
[ 6775.118745] [aurora-modem] ModemManager stopped
[ 6775.166727] [aurora-modem] qmi-proxy stopped
[ 6775.171866] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 6775.196489] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 6775.223298] wwan wwan0: port wwan0at0 disconnected
[ 6775.224011] [aurora-modem] SIGTERM rmtfs 19591 (rmtfs stops MSS, then exits)
[ 6775.224476] wwan wwan0: port wwan0at1 disconnected
[ 6775.235952] wwan wwan0: port wwan0qmi0 disconnected
[ 6775.244669] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 6775.464920] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 6775.470654] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 6775.489193] [aurora-modem] rmtfs exited after 0.3s
[ 6775.503181] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 6775.553088] [aurora-modem] === STOP done rc=0 in 4.0s (mss=offline rmtfs='' mm='' bam=suspended)
[ 6775.553993] [j1] CYCLE 1 stop rc=0
[ 6779.085354] [j1] CYCLE 1 RESULT reg=PASS lat=4.2s data=PASS checks=ok rmtfs=19591-> writes=0 bam=suspended
[ 6784.139071] [j1] CYCLE 2 begin: emmc w=0 s=0 mss=offline rmtfs=''
[ 6784.164976] [aurora-modem] === START (conf /tmp/j1.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 6784.234163] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 6784.234547] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 6784.245718] [aurora-modem] STATE OFF -> RMTFS_READY
[ 6784.250991] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 6784.280534] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 6784.826326] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 6784.921974] [aurora-modem] MSS running after 0.7s
[ 6784.928709] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 6785.404117] wwan wwan0: port wwan0at0 attached
[ 6785.406458] wwan wwan0: port wwan0at1 attached
[ 6785.584861] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 6785.584912] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 6785.590967] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 6785.597477] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 6785.604207] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 6785.610966] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 6785.617736] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 6785.624509] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 6785.631749] wwan wwan0: port wwan0qmi0 attached
[ 6785.775637] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 6787.957073] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 6787.968468] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 6788.024646] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 6788.033177] [aurora-modem] UIM card present, USIM app ready after 0.1s
[ 6788.038094] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 6791.274373] [aurora-modem] DMS online after 3.2s
[ 6791.280981] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 6971.635238] [aurora-modem] FAIL in RADIO_ONLINE: not registered+PS attached after 180s (	Registration state: 'not-registered-searching')
[ 6971.713382] [aurora-modem] MODEM_KEEP_ON_FAIL=1: leaving stack as is
[ 6971.714252] [j1] CYCLE 2 start rc=1
[ 6971.986927] [j1] CYCLE 2 start FAILED in RADIO_ONLINE - snapshot BEFORE stop
[ 6971.996971] [j-snap] begin
[ 6995.422740] [j-snap] end
[ 6995.423349] [j1] CYCLE 2 snapshot done
[ 6995.435453] [j1] CYCLE 2 DATATEST not-run rc=9
[ 6995.499402] [aurora-modem] === STOP (from RADIO_ONLINE: mss=running rmtfs=21201 mm= bam=suspended)
[ 6995.584608] [aurora-modem] wwan links down, addresses/routes removed
[ 6995.593941] [aurora-modem] STATE RADIO_ONLINE -> WWAN_DOWN
[ 6995.650956] [aurora-modem] qmi-proxy stopped
[ 6995.657540] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 6995.684658] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 6995.715675] wwan wwan0: port wwan0at0 disconnected
[ 6995.716270] [aurora-modem] SIGTERM rmtfs 21201 (rmtfs stops MSS, then exits)
[ 6995.718439] wwan wwan0: port wwan0at1 disconnected
[ 6995.727345] wwan wwan0: port wwan0qmi0 disconnected
[ 6995.737971] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 6995.958694] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 6995.965910] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 6995.979812] [aurora-modem] rmtfs exited after 0.3s
[ 6995.999046] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 6996.048675] [aurora-modem] === STOP done rc=0 in 0.5s (mss=offline rmtfs='' mm='' bam=suspended)
[ 6996.049555] [j1] CYCLE 2 stop rc=0
[ 6999.600514] [j1] CYCLE 2 RESULT reg=FAIL lat=>180s data=not-run checks=ok rmtfs=21201-> writes=1 bam=suspended
[ 6999.606491] [j1] SERIES STOP: cycle 2 start/data failure
[ 7002.903193] [j1] FINAL: nv unchanged, emmc w=0 s=0, mss=offline, rmtfs='', mm='', bam=suspended, wwan-up=, usb ok
