[ 2965.822458] [m] CYCLE 2 begin: emmc w=0 s=0 mss=offline rmtfs=''
[ 2965.846637] [aurora-modem] === START (conf /tmp/m.conf, apn 'internet.beeline.ru', ip-type ipv4)
[ 2965.919249] remoteproc remoteproc0: powering up 4080000.remoteproc
[ 2965.919671] remoteproc remoteproc0: Booting fw image mba.mbn, size 234176
[ 2965.931205] [aurora-modem] STATE OFF -> RMTFS_READY
[ 2965.935883] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
[ 2965.964631] qcom-q6v5-mss 4080000.remoteproc: MBA booted without debug policy, loading mpss
[ 2966.505179] remoteproc remoteproc0: remote processor 4080000.remoteproc is now up
[ 2966.613925] [aurora-modem] MSS running after 0.7s
[ 2966.620839] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
[ 2967.066322] wwan wwan0: port wwan0at0 attached
[ 2967.068149] wwan wwan0: port wwan0at1 attached
[ 2967.254771] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 0
[ 2967.254825] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 1
[ 2967.260661] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 2
[ 2967.267637] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 3
[ 2967.274125] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 4
[ 2967.280888] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 5
[ 2967.287651] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 6
[ 2967.294440] bam-dmux 4080000.remoteproc:bam-dmux: Channel already open: 7
[ 2967.301709] wwan wwan0: port wwan0qmi0 attached
[ 2967.468821] [aurora-modem] wwan0qmi0 + wwan0 present after 0.8s; +2 s (JZ02 rpmsg_wwan_ctrl port-race guard, proven start_post)
[ 2969.654448] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
[ 2969.665223] [aurora-modem] DMS Mode: 'shutting-down' after 0.2s
[ 2969.715051] [aurora-modem] STATE QMI_READY -> SIM_READY
[ 2969.722243] [aurora-modem] UIM card present, USIM app ready after 0.1s
[ 2969.727500] [aurora-modem] SET: qmicli -p -d /dev/wwan0qmi0 --dms-set-operating-mode=online (retried only on DeviceNotReady, <= 30s)
[ 2972.957860] [aurora-modem] DMS online after 3.2s
[ 2972.963400] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
[ 2973.283230] [aurora-modem] REG t+0.3s: not-registered-searching / PS detached / none (none, ) - pci= si=/ cl=/
[ 2976.562880] [aurora-modem] REG t+3.6s: not-registered-searching / PS detached / limited (limited-regional, camped) 250-99 pci=55 si=/156465929 cl=7661/156465929
[ 3017.865586] [aurora-modem] REG t+44.9s: registration-denied / PS detached / limited (none, none) 250-01 pci=47 si=41028/135972149 cl=41028/135972149
[ 3040.238480] [aurora-modem] REG t+67.2s: not-registered-searching / PS detached / limited (limited-regional, camped) 250-99 pci=55 si=41028/156465929 cl=7661/156465929
[ 3132.321564] [aurora-modem] REG t+159.3s: not-registered-searching / PS detached / limited (none, none) 250-20 pci=64 si=26366/156182544 cl=65535/4294967295
[ 3145.089683] [aurora-modem] REG t+172.1s: not-registered-searching / PS detached / limited (limited-regional, camped) 250-99 pci=55 si=26366/156465929 cl=7661/156465929
[ 3240.323649] [aurora-modem] REG t+267.3s: not-registered-searching / PS detached / limited (none, none) 250-99 pci=149 si=7661/157614181 cl=7661/157614181
[ 3243.679583] [aurora-modem] REG t+270.7s: not-registered-searching / PS detached / limited (none, none) 250-99 pci=147 si=7661/157614183 cl=7661/157614183
[ 3262.877722] [aurora-modem] REG t+289.9s: not-registered-searching / PS detached / limited (none, none) 250-99 pci=55 si=7661/156465929 cl=7661/156465929
[ 3294.776835] [aurora-modem] REG t+321.8s: not-registered-searching / PS detached / limited (none, none) 250-99 pci=187 si=7661/158607205 cl=7661/158607205
[ 3317.105899] [aurora-modem] REG t+344.1s: not-registered-searching / PS detached / limited (none, none) 250-99 pci=149 si=7661/157614181 cl=7661/157614181
[ 3333.149751] [aurora-modem] REG t+360.2s: not-registered-searching / PS detached / limited (none, none) 250-99 pci=55 si=7661/156465929 cl=7661/156465929
[ 3333.166730] [aurora-modem] FAIL in RADIO_ONLINE: REGISTRATION_TIMEOUT after 360s (not-registered-searching, PS detached)
[ 3333.245247] [aurora-modem] MODEM_KEEP_ON_FAIL=1: leaving stack as is
[ 3333.246123] [m] CYCLE 2 start rc=1
[ 3333.522336] [m] CYCLE 2 start FAILED in RADIO_ONLINE - snapshot BEFORE stop
[ 3333.530098] [j-snap] begin
[ 3356.999929] [j-snap] end
[ 3357.000667] [m] CYCLE 2 snapshot done
[ 3357.009303] [m] CYCLE 2 DATATEST not-run rc=9
[ 3357.070818] [aurora-modem] === STOP (from RADIO_ONLINE: mss=running rmtfs=16520 mm= bam=suspended)
[ 3357.152769] [aurora-modem] wwan links down, addresses/routes removed
[ 3357.163079] [aurora-modem] STATE RADIO_ONLINE -> WWAN_DOWN
[ 3357.219007] [aurora-modem] qmi-proxy stopped
[ 3357.225241] [aurora-modem] STATE WWAN_DOWN -> MM_STOPPED
[ 3357.252594] [aurora-modem] BAM-DMUX suspended after 0.0s
[ 3357.285086] [aurora-modem] SIGTERM rmtfs 16520 (rmtfs stops MSS, then exits)
[ 3357.285401] wwan wwan0: port wwan0at0 disconnected
[ 3357.291854] wwan wwan0: port wwan0at1 disconnected
[ 3357.296525] wwan wwan0: port wwan0qmi0 disconnected
[ 3357.305816] remoteproc remoteproc0: stopped remote processor 4080000.remoteproc
[ 3357.523980] [aurora-modem] MSS offline after 0.2s (rmtfs alive: no)
[ 3357.531004] [aurora-modem] STATE MM_STOPPED -> MPSS_STOPPED
[ 3357.546229] [aurora-modem] rmtfs exited after 0.3s
[ 3357.560090] [aurora-modem] STATE MPSS_STOPPED -> OFF
[ 3357.609003] [aurora-modem] === STOP done rc=0 in 0.5s (mss=offline rmtfs='' mm='' bam=suspended)
[ 3357.609882] [m] CYCLE 2 stop rc=0
