ULPM does not work properly when USB CF3 not connected


#1

Hello,

I read somewhere, do not remember where, that there was a bug with USB and ULPM in some firmware version. I am experiencing this issue right now, the module does not want to enter ULPM properly, meaning sometimes it might enter for a few seconds but then wake up again. I have tried on both WP8548 (Release 14) and WP7702 (Release 8). Below are logs taken from serial (USB console):

WP8548:

[ 20.082008] mbim_open: Open mbim driver
[ 20.084846] mbim_open: Lock mbim_dev->open_excl for open
[ 20.091652] mbim_open: USB cable not connected
[ 20.095070] mbim_open: Exit, mbim file opened
[ 20.104135] mbim_read: Requests list is empty. Wait.
[ 21.178666] i2c i2c-0: Added multiplexed i2c bus 1
[ 21.198809] i2c i2c-0: Added multiplexed i2c bus 2
[ 21.228689] i2c i2c-0: Added multiplexed i2c bus 3
[ 21.244437] i2c i2c-0: Added multiplexed i2c bus 4
[ 21.248374] pca954x 0-0071: registered 4 multiplexed busses for I2C switch pca9546
[ 21.433267] 0-0076 supply vddd not found, using dummy regulator
[ 21.438425] 0-0076 supply vdda not found, using dummy regulator
[ 24.256249] softdog: Software Watchdog Timer: 0.08 initialized. soft_noboot=0 soft_margin=60 sec soft_panic=0 (nowayout=0)
[ 27.900289] gpio_sync_ri: RI owner is Modem
[ 28.608271] PM: Syncing filesystems … done.
[ 28.709507] Freezing user space processes …
[ 28.714512] mbim_read: Waiting failed
[ 28.752296] (elapsed 0.039 seconds) done.
[ 28.755287] Freezing remaining freezable tasks … (elapsed 0.001 seconds) done.
[ 28.763192] Suspending console(s) (use no_console_suspend to debug)

As soon as USB CF3 is connected:

[ 28.782511] msm_hsic_host msm_hsic_host: HSIC-USB in low power mode
[ 28.782847] PM: suspend of devices complete after 11.750 msecs
[ 28.784953] PM: late suspend of devices complete after 2.075 msecs
[ 28.786815] PM: noirq suspend of devices complete after 1.861 msecs
[ 28.787059] msm_pm_enter
[ 28.787059] msm_pm_enter: power collapse
[ 28.787059] msm_mpm_irqs_detectable: cannot monitor 000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000
[ 28.787059] msm_pm_enter: return
[ 28.788524] PM: noirq resume of devices complete after 1.373 msecs
[ 28.790599] PM: early resume of devices complete after 1.556 msecs
[ 28.792308] msm_otg msm_otg: USB exited from low power mode
[ 28.792430] msm_hsic_host msm_hsic_host: HSIC-USB exited from low power mode
[ 28.827987] PM: resume of devices complete after 37.387 msecs
[ 28.907950] Restarting tasks …
[ 28.916587] mbim_read: Requests list is empty. Wait.
[ 28.920860] ci_hdrc ci_hdrc.0: CI_HDRC_CONTROLLER_RESUME_EVENT received
[ 28.927361] android_disconnect: android_disconnect: Disconnected
[ 28.957668] android_work: android_work: sent uevent USB_STATE=DISCONNECTED
[ 28.966549] done.
[ 29.047398] android_setup: android_setup: Connected
[ 29.056432] android_disconnect: android_disconnect: Disconnected
[ 29.061620] android_work: android_work: did not send uevent (0 0 (null))
[ 29.199359] android_setup: android_setup: Connected
[ 29.204700] android_work: android_work: sent uevent USB_STATE=CONNECTED
[ 29.210407] android_usb gadget: high-speed config #1: android_usb
[ 29.216664] msm_otg msm_otg: Avail curr from USB = 500
[ 29.221516] android_setup: android_setup: Configured
[ 29.228078] sps:REVISION of BAM 0xd0360000 is 0x5.
[ 29.242362] IPv6: ADDRCONF(NETDEV_CHANGE): usb0: link becomes ready
[ 29.301480] android_work: android_work: sent uevent USB_STATE=CONFIGURED
[ 32.151045] NOHZ: local_softirq_pending 08
[ 32.233023] NOHZ: local_softirq_pending 08
[ 35.487990] NOHZ: local_softirq_pending 08
[ 36.706210] NOHZ: local_softirq_pending 08
[ 36.911887] NOHZ: local_softirq_pending 08
[ 37.105844] NOHZ: local_softirq_pending 08
[ 37.160323] qup_i2c qup_i2c.0: QUP: I2C status flags :0x1300c8, irq:187
[ 37.165969] qup_i2c qup_i2c.0: I2C slave addr:0x3a not connected
[ 37.180802] gpio_check_and_wake: wake-n_gpio77 STATE=WAKEUP
[ 37.202197] gpio_check_and_wake: wake-n_gpio77 STATE=SLEEP
[ 37.421883] NOHZ: local_softirq_pending 08
[ 37.615840] NOHZ: local_softirq_pending 08
[ 44.262994] nmea: smd opened
[ 47.204211] qup_i2c qup_i2c.0: QUP: I2C status flags :0x1300c8, irq:187
[ 47.210376] qup_i2c qup_i2c.0: I2C slave addr:0x3a not connected
[ 51.873828] SysRq : Emergency Sync
[ 51.877826] SysRq : Power Off
[ 51.882740] reboot: Power down
[ 51.884785] Powering of

WP7702:

[ 24.899398] msm-pcm-routing soc:qcom,msm-pcm-routing: ASoC: mux SLIM_0_RX AANC MUX has no paths
[ 24.997222] msm-dai-stub-dev soc:qcom,msm-dai-stub:qcom,msm-dai-stub-dtmf-tx: ASoC: no sink widget found for STUB_DTMF_TX
[ 25.025138] msm-dai-stub-dev soc:qcom,msm-dai-stub:qcom,msm-dai-stub-dtmf-tx: ASoC: Failed to add route DTMF TX -> direct -> STUB_DTMF_TX
[ 25.052593] msm-dai-stub-dev soc:qcom,msm-dai-stub:qcom,msm-dai-stub-host-rx-capture-tx: ASoC: no sink widget found for STUB_HOST_RX_CAPTURE_TX
[ 25.075378] msm-dai-stub-dev soc:qcom,msm-dai-stub:qcom,msm-dai-stub-host-rx-capture-tx: ASoC: Failed to add route CS-VOICE HOST RX CAPTURE -> direct -> STUB_HOST_RX_CAPTURE_TX
[ 25.090487] msm-dai-stub-dev soc:qcom,msm-dai-stub:qcom,msm-dai-stub-host-rx-playback-rx: ASoC: no source widget found for STUB_HOST_RX_PLAYBACK_RX
[ 25.103743] msm-dai-stub-dev soc:qcom,msm-dai-stub:qcom,msm-dai-stub-host-rx-playback-rx: ASoC: Failed to add route STUB_HOST_RX_PLAYBACK_RX -> direct -> CS-VOICE HOST RX PLAYBACK
[ 25.123122] msm-dai-stub-dev soc:qcom,msm-dai-stub:qcom,msm-dai-stub-host-tx-capture-tx: ASoC: no sink widget found for STUB_HOST_TX_CAPTURE_TX
[ 25.160301] msm-dai-stub-dev soc:qcom,msm-dai-stub:qcom,msm-dai-stub-host-tx-capture-tx: ASoC: Failed to add route CS-VOICE HOST TX CAPTURE -> direct -> STUB_HOST_TX_CAPTURE_TX
[ 25.198738] msm-dai-stub-dev soc:qcom,msm-dai-stub:qcom,msm-dai-stub-host-tx-playback-rx: ASoC: no source widget found for STUB_HOST_TX_PLAYBACK_RX
[ 25.230340] msm-dai-stub-dev soc:qcom,msm-dai-stub:qcom,msm-dai-stub-host-tx-playback-rx: ASoC: Failed to add route STUB_HOST_TX_PLAYBACK_RX -> direct -> CS-VOICE HOST TX PLAYBACK
[ 25.932646] adm_callback: cmd = 0x10322 returned error = 0x16
[ 25.937359] adm_callback: ADM map error, resuming
[ 25.944754] adm_memory_map_regions: DSP returned error[ADSP_ERR_MAX]
[ 25.962667] adm_map_cal_data: map did not work! cal_type 0 ret -68
[ 25.967818] map_memory: map_cal failed, cal type 10, ret = -19!
[ 25.990218] adm_alloc_cal: cal_utils_alloc_block failed, ret = -19, cal type = 10!
[ 25.996756] call_allocs: alloc failed!
[ 30.139542] i2c-msm-v2 78b8000.i2c: NACK: slave not responding, ensure its powered: msgs(n:1 cur:0 tx) bc(rx:0 tx:18) mode:FIFO slv_addr:0x3a MSTR_STS:0x0c1300c8 OPER:0x00000090
[ 36.224052] sierra_pm_resume, total sleep time = 77, startup_timer expired

After USB CF3 connected:

[ 38.092096] msm_otg 78d9000.usb: SM WORK: USB is in LPM
[ 38.518961] gbam_connect_work: gbam_connect_work: Bam channel is not ready
[ 40.208761] i2c-msm-v2 78b8000.i2c: NACK: slave not responding, ensure its powered: msgs(n:1 cur:0 tx) bc(rx:0 tx:18) mode:FIFO slv_addr:0x3a MSTR_STS:0x0c1300c8 OPER:0x00000090
rcK: Executing run_K_scripts…
Stopping linkmon: no linkmon found; none killed
done
Stopping port_bridge: no port_bridge found; none killed
Stopping qmi_ip: no qmi_ip_multiclient found; none killed
Stopping netmgrd: stopped netmgrd (pid 926)
done
Stopping qmuxd: stopped qmuxd (pid 880)
done
no QCMAP_ConnectionManager found; none killed
Stopping fs-scrub-daemon: no fs-scrub-daemon found; none killed
Stopping thermal-engine: stopped thermal-engine (pid 887)
done
stopped qti (pid 1172)
Stopping reboot daemon: stopped reboot-daemon (pid 711)
done
Legato shutdown sequence
Stopping Legato…rmmod: can’t unload ‘2_iio_triggered_buffer’: unknown symbol in module, or unknown parameter
rmmod: can’t unload ‘1_iio_kfifo_buf’: unknown symbol in module, or unknown parameter
rmmod: can’t unload ‘0_iio’: unknown symbol in module, or unknown parameter
DONE.
Finished Legato stop Sequence
stopping time daemon
Stopping time_services: stopped time_daemon (pid 586)
done
stopping ntpd
no ntpd found; none killed
Stopping diagrebootapp: stopped diagrebootapp (pid 576)
done
stopping DNS forwarder and DHCP server: dnsmasq… stopped /usr/bin/dnsmasq (pid 1151)
done.
Deconfiguring network interfaces… ifdown: interface eth0 not configured
done.
Stopping syslogd/klogd: stopped syslogd (pid 559)
stopped klogd (pid 565)
done
Stopping Dropbear SSH server: stopped /usr/sbin/dropbear (pid 1114)
dropbear.
K96mount_unionfs: RO rootfs fudge allowed.
Stopping system message bus: dbus.
K98mount_early: Executing mount_early_user_stop…
K98mount_early: RO rootfs fudge allowed.
sh: /mnt/flash: unknown operand
K98mount_early: Executing mount_early_legato_stop…
K98mount_early: Executing mount_early_userrw_stop…
rcK: Executing kill_all_proc…
rcK: Executing umount_fs_generic…
rcK: Executing print_shutdown_msg…
** SYSTEM SHUTDOWN COMPLETE **
The system is going down NOW!
Sent SIGTERM to all processes
[ 49.416163] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister rmnet0
[ 50.063960] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister rmnet_data0
[ 50.189397] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister rmnet0
[ 50.284050] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister rmnet_data0
[ 50.381231] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister rmnet_data1
[ 50.461524] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister bridge0
[ 50.520163] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister rmnet_data1
[ 50.527797] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister rmnet_data2
Sent SIGKILL to all processes
Requesting system poweroff
[ 50.650927] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister bridge0
[ 50.679524] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister rmnet_data2
[ 50.687184] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister rmnet_data3
[ 50.839483] [RMNET:HI] rmnet_config_notify_cb(): Kernel is trying to unregister rmnet_data3
[ 51.558360] i2c-msm-v2 78b8000.i2c: NACK: slave not responding, ensure its powered: msgs(n:1 cur:0 tx) bc(rx:0 tx:14) mode:FIFO slv_addr:0x3a MSTR_STS:0x0c1300c8 OPER:0x00000090
[ 51.587763] reboot: Power down
[ 51.589973] Failed to disable secure wdog debug: -4
[ 51.595246] Calling SCM to disable SPMI PMI


#2

Hi

Have you fix your problem?
Could you try again with latest version?

I tried and success(~10uA) recently with module alone.
Also, the module have another jobs in a time beside of MPSS.
You need to sure no any other job blocking module to enter ULPM.

And isolate current consumption of peripheral circuit in managOH board.
It is because the ULPM current is quite small. Some components will affect it such E-cap., reverse input protection diode.


#3

Hi,

Unfortunately I have not access to a mangOH anymore. Did it for work,
and have switched work place.

lching kirjoitti 23.10.2018 09:52:


#4

Hi Basti

Initially I guess you using managOH board for ULPM testing.
In my side, the module was mounted on simple test board and to provide USB connection & power supply only.

How about your setup?

Sorry my module is WP7607.