Disrupted suspend sequence
I often get problems with the modem disappearing around suspend, running the free firmware version 0.4.5-2. While looking at today's log I found that the suspend sequence executed before the suspend was directly followed by a wake sequence and an attempt of uploading GNSS data shortly before the kernel suspended the system. I wonder if this is the cause that it modem got lost.
The kernel has the mmc_sdio_suspend
traceback as usual but I think it's unrelated as it happens later.
1153 │ Dez 02 21:39:24 mobian eg25manager[6792]: Executed soft sleep sequence
1154 │ Dez 02 21:39:24 mobian eg25manager[6792]: Executed suspend sequence
1155 │ Dez 02 21:39:24 mobian eg25manager[6792]: suspend sequence is over, drop inhibitor
1156 │ Dez 02 21:39:24 mobian eg25manager[6792]: Initiate GNSS assistance data upload: "RAM:xtra2.bin",58746,10
1157 │ Dez 02 21:39:24 mobian eg25manager[6792]: Executed soft wake sequence
1158 │ Dez 02 21:39:24 mobian eg25manager[6792]: Successfully sent command: AT+QFUPL="RAM:xtra2.bin",58746,10
1159 │ Dez 02 21:39:24 mobian eg25manager[6792]: Response: [CONNECT]
1160 │ Dez 02 21:39:24 mobian eg25manager[6792]: Modem ready for GNSS assistance data upload
1161 │ Dez 02 21:39:24 mobian eg25manager[6792]: GNSS assistance upload step (5/9): uploading assistance data
1162 │ Dez 02 23:02:38 mobian eg25manager[6792]: Successfully uploaded 58746 bytes to the modem
1163 │ Dez 02 23:02:38 mobian eg25manager[6792]: system is resuming
1164 │ Dez 02 23:02:38 mobian eg25manager[6792]: taking systemd sleep inhibitor
1165 │ Dez 02 23:02:38 mobian eg25manager[6792]: Executed resume sequence
1166 │ Dez 02 23:02:38 mobian eg25manager[6792]: Successfully sent command: AT+QFUPL="RAM:xtra2.bin",58746,10
1167 │ Dez 02 23:02:38 mobian eg25manager[6792]: ModemManager object `/org/freedesktop/ModemManager1/Modem/14' removed
1168 │ Dez 02 23:02:38 mobian eg25manager[6792]: Lost modem, resetting...
ModemManager:
1594 │ Dez 02 21:39:24 mobian ModemManager[689]: <info> [sleep-monitor] system is about to suspend
1595 │ Dez 02 21:39:24 mobian ModemManager[689]: <info> [modem14] state changed (connected -> disconnecting)
Kernel:
3034 │ Dez 02 21:39:29 mobian kernel: PM: suspend entry (deep)
3035 │ Dez 02 21:39:29 mobian kernel: Filesystems sync: 0.075 seconds
3036 │ Dez 02 23:02:37 mobian kernel: Freezing user space processes ... (elapsed 0.007 seconds) done.
3037 │ Dez 02 23:02:37 mobian kernel: OOM killer disabled.
3038 │ Dez 02 23:02:37 mobian kernel: Freezing remaining freezable tasks ... (elapsed 0.002 seconds) done.
3039 │ Dez 02 23:02:37 mobian kernel: printk: Suspending console(s) (use no_console_suspend to debug)
3040 │ Dez 02 23:02:37 mobian kernel: ------------[ cut here ]------------
3041 │ Dez 02 23:02:37 mobian kernel: WARNING: CPU: 2 PID: 6258 at drivers/mmc/core/sdio.c:1024 mmc_sdio_suspend+0x28/0x120
3042 │ Dez 02 23:02:37 mobian kernel: Modules linked in: snd_seq_dummy(E) snd_hrtimer(E) snd_seq(E) snd_seq_device(E) option(E) qmi_wwan(E) cdc_wdm(
│ E) usb_wwan(E) usbnet(E) usbserial(E) mii(E) algif_hash(E) algif_skcipher(E) af_alg(E) bnep(E) overlay(E) lz4(E) lz4_compress(E) zram(E) zsma
│ lloc(E) usb_f_ecm(E) u_ether(E) libcomposite(E) cpufreq_powersave(E) hci_uart(E) btrtl(E) btbcm(E) bluetooth(E) sha512_generic(E) sha512_arm6
│ 4(E) gpio_vibra(E) 8723cs(CE) drbg(E) st_magn_spi(E) st_sensors_spi(E) regmap_spi(E) axp20x_pek(E) ansi_cprng(E) axp20x_battery(E) axp20x_adc
│ (E) ext4(E) st_magn_i2c(E) st_magn(E) inv_mpu6050_i2c(E) st_sensors_i2c(E) st_sensors(E) inv_mpu6050(E) stk3310(E) ecdh_generic(E) mbcache(E)
│ jbd2(E) ecc(E) joydev(E) crc16(E) industrialio_triggered_buffer(E) sun50i_codec_analog(E) snd_soc_hdmi_codec(E) sun8i_adda_pr_regmap(E) kfif
│ o_buf(E) sun6i_csi(E) sun8i_di(E) ecb(E) cfg80211(E) des_generic(E) libdes(E) cbc(E) sunxi_cedrus(CE) sun8i_rotate(E) rfkill(E) v4l2_mem2mem(
│ E) videobuf2_dma_contig(E)
3043 │ Dez 02 23:02:38 mobian kernel: sun8i_codec(E) gc2145(E) leds_sgm3140(E) ov5640(E) videobuf2_memops(E) sun4i_i2s(E) v4l2_flash_led_class(E) v
│ 4l2_fwnode(E) videobuf2_v4l2(E) snd_soc_simple_card(E) videobuf2_common(E) sun8i_ce(E) v4l2_async(E) crypto_engine(E) snd_soc_simple_card_uti
│ ls(E) rng_core(E) snd_soc_ec25(E) snd_soc_simple_amplifier(E) snd_soc_bt_sco(E) snd_soc_core(E) snd_pcm_dmaengine(E) snd_pcm(E) videodev(E) s
│ nd_timer(E) snd(E) mc(E) soundcore(E) leds_gpio(E) tcp_bbr(E) sch_fq(E) pkcs8_key_parser(E) ledtrig_pattern(E) fuse(E) configfs(E) binfmt_mis
│ c(E) ip_tables(E) x_tables(E) autofs4(E) btrfs(E) xor(E) xor_neon(E) zstd_compress(E) raid6_pq(E) crc32c_generic(E) libcrc32c(E) dm_crypt(E)
│ dm_mod(E) dw_hdmi_cec(E) dw_hdmi_i2s_audio(E) aes_ce_blk(E) crypto_simd(E) cryptd(E) ghash_ce(E) gf128mul(E) sha2_ce(E) sha1_ce(E) axp20x_usb
│ _power(E) industrialio(E) kb151(E) crc8(E) matrix_keymap(E) goodix(E) sunxi(E) phy_generic(E) sun4i_lradc_keys(E) musb_hdrc(E) udc_core(E) ar
│ m_scpi(E) evdev(E) i2c_gpio(E)
3044 │ Dez 02 23:02:38 mobian kernel: CPU: 2 PID: 6258 Comm: kworker/u8:6 Tainted: G WC E 5.15-sunxi64 #1
3045 │ Dez 02 23:02:38 mobian kernel: Hardware name: Pine64 PinePhone (1.2) (DT)
3046 │ Dez 02 23:02:38 mobian kernel: Workqueue: events_unbound async_run_entry_fn
3047 │ Dez 02 23:02:38 mobian kernel: pstate: 60400005 (nZCv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
3048 │ Dez 02 23:02:38 mobian kernel: pc : mmc_sdio_suspend+0x28/0x120
3049 │ Dez 02 23:02:38 mobian kernel: lr : mmc_bus_suspend+0x3c/0x74
3050 │ Dez 02 23:02:38 mobian kernel: sp : ffffffc0143c3c40
3051 │ Dez 02 23:02:38 mobian kernel: x29: ffffffc0143c3c40 x28: 0000000000000000 x27: 0000000000000000
3052 │ Dez 02 23:02:38 mobian kernel: x26: ffffff800dff1374 x25: ffffff8001827005 x24: 0000000000000000
3053 │ Dez 02 23:02:38 mobian kernel: x23: ffffffc011335000 x22: 0000000000000002 x21: ffffff8015e54000
3054 │ Dez 02 23:02:38 mobian kernel: x20: ffffff8015e50008 x19: ffffff8015e54000 x18: ffffffffffffffff
3055 │ Dez 02 23:02:38 mobian kernel: x17: 0000000000000000 x16: 0000000000000001 x15: 00000000000c8000
3056 │ Dez 02 23:02:38 mobian kernel: x14: 0000000000000000 x13: 0000000000000030 x12: 0101010101010101
3057 │ Dez 02 23:02:38 mobian kernel: x11: 7f7f7f7f7f7f7f7f x10: feff636d746e616d x9 : ffffffc01078814c
3058 │ Dez 02 23:02:38 mobian kernel: x8 : fefefefefefefeff x7 : 000000000000000f x6 : 0000005c88cb81b5
3059 │ Dez 02 23:02:38 mobian kernel: x5 : 0000000000000163 x4 : ffffffc01139a780 x3 : ffffffc010c9ba50
3060 │ Dez 02 23:02:38 mobian kernel: x2 : ffffffc010c9ba50 x1 : ffffffc010791f50 x0 : 0000000000000000
3061 │ Dez 02 23:02:38 mobian kernel: Call trace:
3062 │ Dez 02 23:02:38 mobian kernel: mmc_sdio_suspend+0x28/0x120
3063 │ Dez 02 23:02:38 mobian kernel: mmc_bus_suspend+0x3c/0x74
3064 │ Dez 02 23:02:38 mobian kernel: dpm_run_callback+0x5c/0x170
3064 │ Dez 02 23:02:38 mobian kernel: dpm_run_callback+0x5c/0x170
3065 │ Dez 02 23:02:38 mobian kernel: __device_suspend+0x114/0x520
3066 │ Dez 02 23:02:38 mobian kernel: async_suspend+0x2c/0xa0
3067 │ Dez 02 23:02:38 mobian kernel: async_run_entry_fn+0x38/0x160
3068 │ Dez 02 23:02:38 mobian kernel: process_one_work+0x1ec/0x450
3069 │ Dez 02 23:02:38 mobian kernel: worker_thread+0x198/0x4d0
3070 │ Dez 02 23:02:38 mobian kernel: kthread+0x124/0x130
3071 │ Dez 02 23:02:38 mobian kernel: ret_from_fork+0x10/0x20
3072 │ Dez 02 23:02:38 mobian kernel: ---[ end trace 26ecd29f60320b36 ]---
3073 │ Dez 02 23:02:38 mobian kernel: Disabling non-boot CPUs ...
3074 │ Dez 02 23:02:38 mobian kernel: psci: CPU1 killed (polled 0 ms)
3075 │ Dez 02 23:02:38 mobian kernel: psci: CPU2 killed (polled 4 ms)
3076 │ Dez 02 23:02:38 mobian kernel: psci: CPU3 killed (polled 0 ms)
3077 │ Dez 02 23:02:38 mobian kernel: Enabling non-boot CPUs ...
3078 │ Dez 02 23:02:38 mobian kernel: Detected VIPT I-cache on CPU1
3079 │ Dez 02 23:02:38 mobian kernel: arch_timer: CPU1: Trapping CNTVCT access
3080 │ Dez 02 23:02:38 mobian kernel: CPU1: Booted secondary processor 0x0000000001 [0x410fd034]
3081 │ Dez 02 23:02:38 mobian kernel: CPU1 is up
3082 │ Dez 02 23:02:38 mobian kernel: Detected VIPT I-cache on CPU2
3083 │ Dez 02 23:02:38 mobian kernel: arch_timer: CPU2: Trapping CNTVCT access
3084 │ Dez 02 23:02:38 mobian kernel: CPU2: Booted secondary processor 0x0000000002 [0x410fd034]
3085 │ Dez 02 23:02:38 mobian kernel: CPU2 is up
3086 │ Dez 02 23:02:38 mobian kernel: Detected VIPT I-cache on CPU3
3087 │ Dez 02 23:02:38 mobian kernel: arch_timer: CPU3: Trapping CNTVCT access
3088 │ Dez 02 23:02:38 mobian kernel: CPU3: Booted secondary processor 0x0000000003 [0x410fd034]
3089 │ Dez 02 23:02:38 mobian kernel: CPU3 is up
3090 │ Dez 02 23:02:38 mobian kernel: sunxi-rsb 1f03400.rsb: RSB running at 4000000 Hz
3091 │ Dez 02 23:02:38 mobian kernel: PM: dpm_run_callback(): usb_dev_resume+0x0/0x20 returns -5
3092 │ Dez 02 23:02:38 mobian kernel: usb 2-1: PM: failed to resume async: error -5
3093 │ Dez 02 23:02:38 mobian kernel: OOM killer enabled.
3094 │ Dez 02 23:02:38 mobian kernel: Restarting tasks ...
3095 │ Dez 02 23:02:38 mobian kernel: usb 2-1: USB disconnect, device number 19
3096 │ Dez 02 23:02:38 mobian kernel: done.
3097 │ Dez 02 23:02:38 mobian kernel: PM: suspend exit