Hey Loic and Carl, I wanted to test the EM120 setup I have with latest MM git master and kernel 5.13.0-rc2, but unfortunately there is some issue, not sure if in device or in kernel driver. These are the kernel logs I get as output when the issue happens:
[ 263.458712] mhi-pci-generic 0000:01:00.0: can't change power state from D3cold to D0 (config space inaccessible) [ 263.458727] mhi-pci-generic 0000:01:00.0: can't change power state from D3cold to D0 (config space inaccessible) [ 263.458736] mhi-pci-generic 0000:01:00.0: failed to resume device: -22 [ 263.458742] mhi-pci-generic 0000:01:00.0: device recovery started [ 263.516090] mhi-pci-generic 0000:01:00.0: can't change power state from D3cold to D0 (config space inaccessible) [ 263.577411] mhi-pci-generic 0000:01:00.0: reset [ 264.102575] mhi-pci-generic 0000:01:00.0: can't change power state from D3cold to D0 (config space inaccessible) [ 264.822555] mhi-pci-generic 0000:01:00.0: timed out waiting for pending transaction; performing function level reset anyway [ 266.049177] mhi-pci-generic 0000:01:00.0: not ready 1023ms after FLR; waiting [ 267.089191] mhi-pci-generic 0000:01:00.0: not ready 2047ms after FLR; waiting [ 269.302577] mhi-pci-generic 0000:01:00.0: not ready 4095ms after FLR; waiting [ 273.569404] mhi-pci-generic 0000:01:00.0: not ready 8191ms after FLR; waiting [ 281.889737] mhi-pci-generic 0000:01:00.0: not ready 16383ms after FLR; waiting [ 298.743574] mhi-pci-generic 0000:01:00.0: not ready 32767ms after FLR; waiting [ 332.224729] kauditd_printk_skb: 1 callbacks suppressed [ 332.877464] mhi-pci-generic 0000:01:00.0: not ready 65535ms after FLR; giving up [ 333.980714] mhi-pci-generic 0000:01:00.0: reset failed There is one interesting thing in the MM log, though, maybe it's MM the one causing the issue. See this list of ports and the details for each port reported via udev/sysfs. The first port we find is the net port as we scan net subsystem first: ModemManager[2490]: <debug> [1621709598.546715] [mhi_mbim0] port contents loaded: ModemManager[2490]: <debug> [1621709598.546823] [mhi_mbim0] bus: pci ModemManager[2490]: <debug> [1621709598.546974] [mhi_mbim0] device: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 ModemManager[2490]: <debug> [1621709598.547071] [mhi_mbim0] driver: mhi_net ModemManager[2490]: <debug> [1621709598.547175] [mhi_mbim0] vendor: 1eac ModemManager[2490]: <debug> [1621709598.547275] [mhi_mbim0] product: 1001 ModemManager[2490]: <debug> [1621709598.547375] [base-manager] adding port mhi_mbim0 at sysfs path: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0/mhi0/mhi0_IP_HW0_MBIM/net/mhi_mbim0 ModemManager[2490]: <debug> [1621709598.548559] [filter] (net/mhi_mbim0) port allowed: net device ModemManager[2490]: <debug> [1621709598.548785] [base-manager] port mhi_mbim0 is first in device /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 ModemManager[2490]: <debug> [1621709598.549024] [plugin-manager] task 4: new support task for device: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 ModemManager[2490]: <debug> [1621709598.549359] [plugin-manager] task 4: port grabbed: mhi_mbim0 ModemManager[2490]: <debug> [1621709598.549489] [plugin-manager] task 4,mhi_mbim0: new support task for port ModemManager[2490]: <debug> [1621709598.549585] [plugin-manager] task 4,mhi_mbim0: deferred until min wait time elapsed Then we find all these ports in the wwan subsystem: ModemManager[2490]: <debug> [1621709598.566894] [wwan0] port contents loaded: ModemManager[2490]: <debug> [1621709598.567007] [wwan0] bus: pci ModemManager[2490]: <debug> [1621709598.567104] [wwan0] device: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 ModemManager[2490]: <debug> [1621709598.567195] [wwan0] driver: mhi-pci-generic ModemManager[2490]: <debug> [1621709598.567285] [wwan0] vendor: 1eac ModemManager[2490]: <debug> [1621709598.567390] [wwan0] product: 1001 ModemManager[2490]: <debug> [1621709598.567488] [base-manager] adding port wwan0 at sysfs path: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0/mhi0/wwan/wwan0 ModemManager[2490]: <debug> [1621709598.568261] [filter] (wwan/wwan0) port allowed: wwan device ModemManager[2490]: <debug> [1621709598.568542] [base-manager] additional port wwan0 in device /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 ModemManager[2490]: <debug> [1621709598.568823] [plugin-manager] task 4: port grabbed: wwan0 ModemManager[2490]: <debug> [1621709598.568968] [plugin-manager] task 4,wwan0: new support task for port ModemManager[2490]: <debug> [1621709598.569059] [plugin-manager] task 4,wwan0: deferred until min wait time elapsed What is this "wwan0" port exposed by the wwan subsystem? It doesn't have a protocol reported, still, it's exposed in the system. Due to this, we attempt to probe with all known protocols we may have in the subsystem: ModemManager[2490]: <debug> [1621709600.082522] [plugin/generic] probes required for port wwan0: 'at, qcdm, qmi, mbim' Maybe this port probing is the one causing the crash, as it seems the timing could explain it. Not sure I understand what this port is, I thought it was assumed all ports to be known modem control protocol ports? The next list of ports is expected: ModemManager[2490]: <debug> [1621709598.570470] [wwan0p1QCDM] port contents loaded: ModemManager[2490]: <debug> [1621709598.570583] [wwan0p1QCDM] bus: pci ModemManager[2490]: <debug> [1621709598.570678] [wwan0p1QCDM] device: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 ModemManager[2490]: <debug> [1621709598.570778] [wwan0p1QCDM] driver: mhi-pci-generic ModemManager[2490]: <debug> [1621709598.570882] [wwan0p1QCDM] vendor: 1eac ModemManager[2490]: <debug> [1621709598.570971] [wwan0p1QCDM] product: 1001 ModemManager[2490]: <debug> [1621709598.571068] [base-manager] adding port wwan0p1QCDM at sysfs path: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0/mhi0/wwan/wwan0/wwan0p1QCDM ModemManager[2490]: <debug> [1621709598.571850] [filter] (wwan/wwan0p1QCDM) port allowed: wwan device ModemManager[2490]: <debug> [1621709598.572139] [base-manager] additional port wwan0p1QCDM in device /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 ModemManager[2490]: <debug> [1621709598.572411] [plugin-manager] task 4: port grabbed: wwan0p1QCDM ModemManager[2490]: <debug> [1621709598.572572] [plugin-manager] task 4,wwan0p1QCDM: new support task for port ModemManager[2490]: <debug> [1621709598.572662] [plugin-manager] task 4,wwan0p1QCDM: deferred until min wait time elapsed ModemManager[2490]: <debug> [1621709598.574070] [wwan0p2MBIM] port contents loaded: ModemManager[2490]: <debug> [1621709598.574182] [wwan0p2MBIM] bus: pci ModemManager[2490]: <debug> [1621709598.574295] [wwan0p2MBIM] device: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 ModemManager[2490]: <debug> [1621709598.574387] [wwan0p2MBIM] driver: mhi-pci-generic ModemManager[2490]: <debug> [1621709598.574479] [wwan0p2MBIM] vendor: 1eac ModemManager[2490]: <debug> [1621709598.574569] [wwan0p2MBIM] product: 1001 ModemManager[2490]: <debug> [1621709598.574679] [base-manager] adding port wwan0p2MBIM at sysfs path: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0/mhi0/wwan/wwan0/wwan0p2MBIM ModemManager[2490]: <debug> [1621709598.575501] [filter] (wwan/wwan0p2MBIM) port allowed: wwan device ModemManager[2490]: <debug> [1621709598.575782] [base-manager] additional port wwan0p2MBIM in device /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 ModemManager[2490]: <debug> [1621709598.576076] [plugin-manager] task 4: port grabbed: wwan0p2MBIM ModemManager[2490]: <debug> [1621709598.576231] [plugin-manager] task 4,wwan0p2MBIM: new support task for port ModemManager[2490]: <debug> [1621709598.576320] [plugin-manager] task 4,wwan0p2MBIM: deferred until min wait time elapsed ModemManager[2490]: <debug> [1621709598.577736] [wwan0p3AT] port contents loaded: ModemManager[2490]: <debug> [1621709598.577848] [wwan0p3AT] bus: pci ModemManager[2490]: <debug> [1621709598.577945] [wwan0p3AT] device: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 ModemManager[2490]: <debug> [1621709598.578034] [wwan0p3AT] driver: mhi-pci-generic ModemManager[2490]: <debug> [1621709598.578121] [wwan0p3AT] vendor: 1eac ModemManager[2490]: <debug> [1621709598.578209] [wwan0p3AT] product: 1001 ModemManager[2490]: <debug> [1621709598.578305] [base-manager] adding port wwan0p3AT at sysfs path: /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0/mhi0/wwan/wwan0/wwan0p3AT ModemManager[2490]: <debug> [1621709598.579113] [filter] (wwan/wwan0p3AT) port allowed: wwan device ModemManager[2490]: <debug> [1621709598.579402] [base-manager] additional port wwan0p3AT in device /sys/devices/pci0000:00/0000:00:1b.0/0000:01:00.0 -- Aleksander https://aleksander.es _______________________________________________ ModemManager-devel mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/modemmanager-devel
