Skip to content
Snippets Groups Projects

SD card is unwritable after resume from suspend

    • Closed Issue created by Jonathan Brielmaier @jonsger

    I'm using suspend on battery for some weeks now. One big issue is, that sometimes (once a day or more often) the SD card is non-writable after resuming from suspend. My /home partition is on the SD card so I need to reboot in order to resolve this issue.

    I tried on Sebastian's advice the kernel from !711 (closed) but it didn't resolve the problem nor mitigated it.

    The kernel log when this happens has entries like this:

    Jun 17 11:21:13 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Jun 17 11:21:13 claudii kernel: I/O error, dev sda, sector 50403224 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Jun 17 11:21:13 claudii kernel: EXT4-fs warning (device dm-0): ext4_dx_find_entry:1791: inode #1586190: lblock 2: comm pool-org.gnome.: error -5 reading directory block
Jun 17 11:21:13 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Jun 17 11:21:13 claudii kernel: I/O error, dev sda, sector 50403480 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Jun 17 11:21:13 claudii kernel: EXT4-fs warning (device dm-0): ext4_dx_find_entry:1791: inode #1586190: lblock 6: comm gnome-clocks: error -5 reading directory block
Jun 17 11:22:11 claudii kernel: edt_ft5x06 2-0038: Unable to fetch data, error: -6
Jun 17 11:23:05 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
    $ lsblk /dev/sda
NAME              MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
sda                 8:0    1 119,1G  0 disk 
├─vg_home-lv_home 254:0    0    80G  0 lvm  /home
├─vg_home-lv_boot 254:1    0     1G  0 lvm  
└─vg_home-lv_root 254:2    0  38,1G  0 lvm

$ uname -r
6.3.0-1-librem5

$ sudo journalctl --since=2023-06-17 | grep Librem
Jun 17 10:29:07 claudii kernel: Machine model: Purism Librem 5r4

    If you need more debug information, just let me know how to obtain/collect them.

    Designs

      Child items ...

      2. Activity

      • Jonathan Brielmaier
        Jonathan Brielmaier @jonsger ·
        Author

        I migrated /home back to the internal eMMC. This issue is too annoying when using the L5 as daily driver...

      • Zwarf
        Zwarf @Zwarf ·

        This bug is really annoying because it does not only happen when the whole /home is mounted on the SD card. I only bind mounted my /home/Documents, Music and /home/.var folder to the SD card but even then the SD card is sometimes read only. I also can't figure out why it sometimes happens and sometimes not.

      • inx
        inx @inx ·

        Uh, the sdcard storage failing on resume is quite a grave breakage.

        May this be the same issue as what reproducibly happens as mentioned at the end of: https://wiki.postmarketos.org/wiki/Purism_Librem5_(purism-librem5)#SD_Card_booting ?

        Would somebody here know and be able to provide some instructions (or a link) for enabling relevant debug logs in order to try finding the cause of this problem when it happens? usb, sdcard, scsi, ... driver?

      • inx
        inx @inx ·

        Related forum thread which makes this seem a regression and confirms breakage for some more users: https://forums.puri.sm/t/sdcard-becomes-read-only-after-waking-up-from-suspend/20767/

        Edited by inx
      • inx mentioned in issue OS-issues#337

        mentioned in issue OS-issues#337

      • inx
        inx @inx ·

        The SD card breakage could be tied to modem power saving workarounds (OS-issues#337 (comment 253981)), because the SD card controller chip is, at the same time, an USB hub and used in wiring up and power controlling the modem.

        That chip has documented usb hardware suspend "errata" https://ww1.microchip.com/downloads/aemDocuments/documents/OTH/ProductDocuments/Errata/80000643A.pdf and requires global suspending of the usb. It may e.g. be useful to observe if there are differences in the SD card breakage depending on whether the modem is active or not (kill switches).

        Could be something like the chip getting suspended twice, if modem is enabled?, once completely as workaround for usb suspend, and once again (failing) only the sdcard? But maybe somehow not resumed in proper order? Or maybe resumed twice, but failing on second try and thus hard-reset?

        Edited by inx
        • inx
          inx @inx ·

          If you can enable this, maybe it can produce useful logs: https://www.kernel.org/doc/html/latest/usb/usbmon.html

        • Jonathan Brielmaier
          Jonathan Brielmaier @jonsger ·
          Author

          I finally hit this bug while collecting logs via usbmon via cat /sys/kernel/debug/usb/usbmon/0u > /tmp/usb.log.

          Journalctl log when SD card became unwritable 
          Dez 22 14:33:41 claudii kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s
Dez 22 14:33:41 claudii kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x6 [current] 
Dez 22 14:33:41 claudii kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x28 ASCQ=0x0 
Dez 22 14:33:41 claudii kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 06 3f e7 28 00 00 20 00
Dez 22 14:33:41 claudii kernel: I/O error, dev sda, sector 104851240 op 0x0:(READ) flags 0x80700 phys_seg 4 prio class 2
Dez 22 14:33:41 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:41 claudii kernel: I/O error, dev sda, sector 104851248 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Dez 22 14:33:41 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:41 claudii kernel: I/O error, dev sda, sector 104851248 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Dez 22 14:33:41 claudii ModemManager[729]: <info>  [modem0/bearer1] QMI IPv4 Settings:
Dez 22 14:33:41 claudii ModemManager[729]: <info>  [modem0/bearer1]     address: 10.166.26.130/30
Dez 22 14:33:41 claudii ModemManager[729]: <info>  [modem0/bearer1]     gateway: 10.166.26.129
Dez 22 14:33:41 claudii ModemManager[729]: <info>  [modem0/bearer1]     DNS #1: 10.74.210.210
Dez 22 14:33:41 claudii ModemManager[729]: <info>  [modem0/bearer1]     DNS #2: 10.74.210.211
Dez 22 14:33:41 claudii ModemManager[729]: <info>  [modem0/bearer1]        MTU: 1500
Dez 22 14:33:41 claudii systemd[1]: Created slice system-systemd\x2dcoredump.slice.
Dez 22 14:33:41 claudii systemd[1]: Started Process Core Dump (PID 2969/UID 0).
Dez 22 14:33:42 claudii ModemManager[729]: <info>  [modem0/bearer1] QMI IPv6 Settings:
Dez 22 14:33:42 claudii ModemManager[729]: <info>  [modem0/bearer1]     address: 2a01:599:b40:7953:ddc:9296:69bb:3659/64
Dez 22 14:33:42 claudii ModemManager[729]: <info>  [modem0/bearer1]     gateway: 2a01:599:b40:7953:9c1d:660e:2656:106f/64
Dez 22 14:33:42 claudii ModemManager[729]: <info>  [modem0/bearer1]     DNS #1: 2a01:598:7ff:0:10:74:210:210
Dez 22 14:33:42 claudii ModemManager[729]: <info>  [modem0/bearer1]     DNS #2: 2a01:598:7ff:0:10:74:210:211
Dez 22 14:33:42 claudii ModemManager[729]: <info>  [modem0/bearer1]        MTU: 1500
Dez 22 14:33:42 claudii ModemManager[729]: <info>  [modem0] state changed (connecting -> connected)
Dez 22 14:33:42 claudii ModemManager[729]: <info>  [modem0] simple connect state (8/8): all done
Dez 22 14:33:42 claudii mmsdtng[790]: ../plugins/modemmanager.c:modem_state_changed_cb() State Change: Old State: 10 New State: 11, Reason: 1
Dez 22 14:33:42 claudii mmsdtng[790]: ../plugins/modemmanager.c:mmsd_mm_get_modem_state() MM_MODEM_GOOD_STATE: 11
Dez 22 14:33:42 claudii mmsdtng[790]: ../plugins/modemmanager.c:mmsd_mm_state() MMSD_MM_STATE_READY
Dez 22 14:33:42 claudii mmsdtng[790]: ../plugins/modemmanager.c:mmsd_mm_state() Setting Bearer Handler
Dez 22 14:33:42 claudii mmsdtng[790]: ../src/service.c:mms_service_set_bearer_handler() service 0xaaaaed6c5ba0 handler 0xaaaabd1f5a20
Dez 22 14:33:42 claudii mmsdtng[790]: ../plugins/modemmanager.c:process_mms_process_message_queue() Processing any unsent/unreceived MMS messages.
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3229] modem["cdc-wdm0"]: modem state changed, 'connecting' --> 'connected' (reason: user-requested)
Dez 22 14:33:42 claudii systemd-networkd[420]: wwan0: Link UP
Dez 22 14:33:42 claudii systemd-networkd[420]: wwan0: Gained carrier
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3459] device (cdc-wdm0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3474] device (cdc-wdm0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3484] modem-broadband[cdc-wdm0]: IPv4 static configuration:
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3485] modem-broadband[cdc-wdm0]:   address 10.166.26.130/30
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3486] modem-broadband[cdc-wdm0]:   gateway 10.166.26.129
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3486] modem-broadband[cdc-wdm0]:   DNS 10.74.210.210
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3487] modem-broadband[cdc-wdm0]:   DNS 10.74.210.211
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3487] modem-broadband[cdc-wdm0]:   MTU 1500
Dez 22 14:33:42 claudii systemd-timesyncd[517]: Network configuration changed, trying to establish connection.
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3688] modem-broadband[cdc-wdm0]: IPv6 base configuration:
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3690] modem-broadband[cdc-wdm0]:   address 2a01:599:b40:7953:ddc:9296:69bb:3659/64
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3690] modem-broadband[cdc-wdm0]:   gateway 2a01:599:b40:7953:9c1d:660e:2656:106f
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3691] modem-broadband[cdc-wdm0]:   DNS 2a01:598:7ff:0:10:74:210:210
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3691] modem-broadband[cdc-wdm0]:   DNS 2a01:598:7ff:0:10:74:210:211
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.3893] device (cdc-wdm0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.4406] device (cdc-wdm0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.4415] device (cdc-wdm0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.4432] manager: NetworkManager state is now CONNECTED_LOCAL
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.4472] manager: NetworkManager state is now CONNECTED_SITE
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.4477] policy: set 'Prepaid Contracts' (wwan0) as default for IPv4 routing and DNS
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.4485] policy: set 'Prepaid Contracts' (wwan0) as default for IPv6 routing and DNS
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.4502] device (cdc-wdm0): Activation: successful, device activated.
Dez 22 14:33:42 claudii NetworkManager[559]: <info>  [1703252022.4524] manager: NetworkManager state is now CONNECTED_GLOBAL
Dez 22 14:33:43 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:43 claudii kernel: I/O error, dev sda, sector 86493288 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 2
Dez 22 14:33:43 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:43 claudii kernel: I/O error, dev sda, sector 86493288 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Dez 22 14:33:43 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:43 claudii kernel: I/O error, dev sda, sector 86493288 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Dez 22 14:33:43 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:43 claudii kernel: I/O error, dev sda, sector 86493288 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Dez 22 14:33:43 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:43 claudii kernel: I/O error, dev sda, sector 86493288 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Dez 22 14:33:44 claudii mmsdtng[790]: ../src/service.c:activate_bearer() service 0xaaaaed6c5ba0 setup 0 active 0
Dez 22 14:33:44 claudii mmsdtng[790]: ../src/service.c:activate_bearer() service 0xaaaaed6c5ba0 waiting for 20 seconds
Dez 22 14:33:44 claudii mmsdtng[790]: ../plugins/modemmanager.c:set_context() Setting Context...
Dez 22 14:33:44 claudii mmsdtng[790]: ../src/service.c:mms_service_set_mmsc() service 0xaaaaed6c5ba0 mmsc http://mms.t-mobile.de/servlets/mms
Dez 22 14:33:44 claudii mmsdtng[790]: ../plugins/modemmanager.c:set_context() Max number of bearers: 1
Dez 22 14:33:44 claudii mmsdtng[790]: ../plugins/modemmanager.c:set_context() Current Context APN: internet.t-mobile, mmsd-tng settings MMS APN: internet.t-mobile
Dez 22 14:33:44 claudii mmsdtng[790]: ../plugins/modemmanager.c:set_context() You are connected to the correct APN! Enabling context...
Dez 22 14:33:44 claudii mmsdtng[790]: ../src/service.c:mms_service_set_apn() Service APN Set to internet.t-mobile
Dez 22 14:33:44 claudii mmsdtng[790]: ../src/service.c:mms_service_set_resolvers() service 0xaaaaed6c5ba0 resolvers: ipv4: 10.74.210.210,10.74.210.211, ipv6: 2a01:598:7ff:0:10:74:210:210,2a01:598:7ff:0:10:74:21>
Dez 22 14:33:44 claudii mmsdtng[790]: ../plugins/modemmanager.c:set_context() DNS from modemmanager IPv6: 2a01:598:7ff:0:10:74:210:210,2a01:598:7ff:0:10:74:210:211, IPv4: 10.74.210.210,10.74.210.211
Dez 22 14:33:44 claudii mmsdtng[790]: ../plugins/modemmanager.c:bearer_handler() At Bearer Handler: path /org/freedesktop/ModemManager1/Modem/0 active 1 context_active 1
Dez 22 14:33:44 claudii mmsdtng[790]: ../plugins/modemmanager.c:bearer_handler() active and context_active, bearer_notify
Dez 22 14:33:44 claudii mmsdtng[790]: ../src/service.c:mms_service_bearer_notify() service=0xaaaaed6c5ba0 active=1 iface=wwan0 proxy=172.28.23.131:8008
Dez 22 14:33:44 claudii mmsdtng[790]: ../src/service.c:mms_service_bearer_notify() interface wwan0 proxy 172.28.23.131:8008
Dez 22 14:33:44 claudii mmsdtng[790]: ../src/service.c:mms_service_bearer_notify() Proxy URL: http://172.28.23.131:8008
Dez 22 14:33:44 claudii mmsdtng[790]: ../src/service.c:mms_service_bearer_notify() Proxy is set to 1
Dez 22 14:33:44 claudii mmsdtng[790]: ../src/service.c:process_request_queue() service 0xaaaaed6c5ba0
Dez 22 14:33:45 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:45 claudii kernel: I/O error, dev sda, sector 111172792 op 0x0:(READ) flags 0x80700 phys_seg 16 prio class 2
Dez 22 14:33:45 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:45 claudii kernel: I/O error, dev sda, sector 111172792 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Dez 22 14:33:45 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:45 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:45 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:46 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:48 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:48 claudii kernel: blk_print_req_error: 63 callbacks suppressed
Dez 22 14:33:48 claudii kernel: I/O error, dev sda, sector 86200752 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:33:48 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151934: comm phosh: reading directory lblock 0
Dez 22 14:33:48 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:48 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:33:48 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm phosh: reading directory lblock 0
Dez 22 14:33:48 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:48 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:33:48 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm phosh: reading directory lblock 0
Dez 22 14:33:49 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:49 claudii kernel: I/O error, dev sda, sector 86200752 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:33:49 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151934: comm phosh: reading directory lblock 0
Dez 22 14:33:49 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:49 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:33:49 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm phosh: reading directory lblock 0
Dez 22 14:33:49 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:49 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:33:49 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm phosh: reading directory lblock 0
Dez 22 14:33:49 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:49 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:33:49 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm feedbackd: reading directory lblock 0
Dez 22 14:33:49 claudii feedbackd[1000]: Feedback 0xffff78004ab0 already present
Dez 22 14:33:53 claudii systemd[1]: NetworkManager-dispatcher.service: Succeeded.
Dez 22 14:33:54 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:54 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:33:54 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm chatty: reading directory lblock 0
Dez 22 14:33:54 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:54 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:33:54 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm chatty: reading directory lblock 0
Dez 22 14:33:54 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:58 claudii kernel: I/O error, dev sda, sector 124574936 op 0x1:(WRITE) flags 0x800 phys_seg 2 prio class 2
Dez 22 14:33:58 claudii kernel: Aborting journal on device dm-3-8.
Dez 22 14:33:58 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:33:58 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:33:58 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm chatty: reading directory lblock 0
Dez 22 14:33:58 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 124127232 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 5275648, lost sync page write
Dez 22 14:34:03 claudii kernel: JBD2: I/O error when updating journal superblock for dm-3-8.
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 81922048 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 113296696 op 0x0:(READ) flags 0x84700 phys_seg 30 prio class 2
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 113296936 op 0x0:(READ) flags 0x80700 phys_seg 2 prio class 2
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 113296824 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 113296840 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: EXT4-fs warning (device dm-3): htree_dirblock_to_tree:1082: inode #151932: lblock 0: comm chatty: error -5 reading directory block
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151932: comm chatty: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151932: comm chatty: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151932: comm chatty: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151932: comm chatty: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151932: comm chatty: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: blk_print_req_error: 12 callbacks suppressed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 86200752 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151934: comm phosh: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 81922048 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm phosh: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 81922048 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm phosh: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 81922048 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 86200752 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151934: comm phosh: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 81922048 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 86200728 op 0x0:(READ) flags 0x3000 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm phosh: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: I/O error, dev sda, sector 81922048 op 0x1:(WRITE) flags 0x3800 phys_seg 1 prio class 2
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm phosh: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
Dez 22 14:34:03 claudii kernel: EXT4-fs (dm-3): I/O error while writing superblock
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:03 claudii kernel: EXT4-fs error (device dm-3): __ext4_find_entry:1682: inode #151931: comm feedbackd: reading directory lblock 0
Dez 22 14:34:03 claudii kernel: sd 0:0:0:0: [sda] tag#0 device offline or changed
Dez 22 14:34:04 claudii kernel: Buffer I/O error on dev dm-3, logical block 0, lost sync page write
[...]
          ~ > lsusb
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 004: ID 2020:2060 Qualcomm, Incorporated Qualcomm CDMA Technologies MSM
Bus 001 Device 003: ID 0424:4041 Microchip Technology, Inc. (formerly SMSC) Hub and media card controller
Bus 001 Device 002: ID 0424:2640 Microchip Technology, Inc. (formerly SMSC) USB 2.0 Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
~ > sudo ls /sys/kernel/debug/usb/usbmon
0s  0u	1s  1t	1u  2s	2t  2u
          cat /sys/kernel/debug/usb/devices 
          ~ > sudo cat /sys/kernel/debug/usb/devices
T:  Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480  MxCh= 1
B:  Alloc=  0/800 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=01 MxPS=64 #Cfgs=  1
P:  Vendor=1d6b ProdID=0002 Rev= 6.05
S:  Manufacturer=Linux 6.5.0-1-librem5 xhci-hcd
S:  Product=xHCI Host Controller
S:  SerialNumber=xhci-hcd.4.auto
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   4 Ivl=256ms

T:  Bus=01 Lev=01 Prnt=01 Port=00 Cnt=01 Dev#=  2 Spd=480  MxCh= 3
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=01 MxPS=64 #Cfgs=  1
P:  Vendor=0424 ProdID=2640 Rev= 9.02
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  2mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   1 Ivl=256ms

T:  Bus=01 Lev=02 Prnt=02 Port=00 Cnt=01 Dev#=  3 Spd=480  MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=0424 ProdID=4041 Rev= 2.09
S:  Manufacturer=Generic
S:  Product=Ultra Fast Media Reader
S:  SerialNumber=000008264001
C:* #Ifs= 1 Cfg#= 1 Atr=80 MxPwr= 96mA
I:* If#= 0 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage
E:  Ad=02(O) Atr=02(Bulk) MxPS= 512 Ivl=125us
E:  Ad=82(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms

T:  Bus=01 Lev=02 Prnt=02 Port=01 Cnt=02 Dev#=  4 Spd=480  MxCh= 0
D:  Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=2020 ProdID=2060 Rev= 0.00
S:  Manufacturer=Qualcomm, Incorporated
S:  Product=Qualcomm CDMA Technologies MSM
C:* #Ifs= 5 Cfg#= 1 Atr=e0 MxPwr=500mA
I:* If#= 0 Alt= 0 #EPs= 2 Cls=ff(vend.) Sub=ff Prot=ff Driver=option
E:  Ad=81(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=01(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
I:* If#= 1 Alt= 0 #EPs= 2 Cls=ff(vend.) Sub=ff Prot=ff Driver=option
E:  Ad=82(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=02(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
I:* If#= 2 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=ff Prot=ff Driver=option
E:  Ad=83(I) Atr=03(Int.) MxPS=  64 Ivl=2ms
E:  Ad=84(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=03(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
I:* If#= 3 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=fe Prot=ff Driver=option
E:  Ad=85(I) Atr=03(Int.) MxPS=  64 Ivl=2ms
E:  Ad=86(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=04(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms
I:* If#= 4 Alt= 0 #EPs= 3 Cls=ff(vend.) Sub=ff Prot=ff Driver=qmi_wwan
E:  Ad=87(I) Atr=03(Int.) MxPS=  64 Ivl=2ms
E:  Ad=88(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=05(O) Atr=02(Bulk) MxPS= 512 Ivl=0ms

T:  Bus=02 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=5000 MxCh= 1
B:  Alloc=  0/800 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 3.00 Cls=09(hub  ) Sub=00 Prot=03 MxPS= 9 #Cfgs=  1
P:  Vendor=1d6b ProdID=0003 Rev= 6.05
S:  Manufacturer=Linux 6.5.0-1-librem5 xhci-hcd
S:  Product=xHCI Host Controller
S:  SerialNumber=xhci-hcd.4.auto
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   4 Ivl=256ms

          Here is the actual output log from usbmon: usb.log.zst

          As far as I understand is the SD card on Bus=001 and device Device=003, so I searched for it (grep --line-number ":1:003" usb.log |less). There are some prominent disappears of the SD card on following lines:

          28944
247890
268784
349629
487563
        • Please register or sign in to reply
        • Sebastian Krzyszkowiak
          Sebastian Krzyszkowiak @sebastian.krzyszkowiak ·
          Owner

          It appears that there's a time window of approximately 1.5s after resuming from system suspend when trying to access the SD card will result in errors. What I still don't understand is how is system suspend different from runtime suspend from the card reader's perspective when !711 (closed) is applied.

        • Kyle Evans
          Kyle Evans @fuzzy7k ·

          It appears that there's a time window of approximately 1.5s after resuming from system suspend when trying to access the SD card will result in errors.

          If that is the case, I suspect that calling the device while suspended may be a good way to trigger this. That assumes that .local/share/calls/records.db is on the sdcard.

          What I still don't understand is how is system suspend different from runtime suspend from the card reader's perspective when !711 (closed) is applied.

          I ran some tests recently while attempting to bring the sdcard back without rebooting. I was not able to do it with just sd_en, but with sd_en & suspend I was able to get a new kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk

          journalctl _TRANSPORT=kernel -g '^sd 0:0:0:0: \[sda\]|^PM:' -p 4..7 
          -- Boot 3a8496fdc18a48f7a29079f110b35e24 --
Jul 01 08:40:36 liby kernel: sd 0:0:0:0: [sda] 499744768 512-byte logical blocks: (256 GB/238 GiB)
Jul 01 08:40:36 liby kernel: sd 0:0:0:0: [sda] Write Protect is off
Jul 01 08:40:36 liby kernel: sd 0:0:0:0: [sda] Mode Sense: 23 00 00 00
Jul 01 08:40:36 liby kernel: sd 0:0:0:0: [sda] No Caching mode page found
Jul 01 08:40:36 liby kernel: sd 0:0:0:0: [sda] Assuming drive cache: write through
Jul 01 08:40:36 liby kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk
Jul 01 11:25:23 liby kernel: PM: suspend entry (deep)
Jul 01 11:32:28 liby kernel: PM: suspend exit
Jul 01 11:41:37 liby kernel: PM: suspend entry (deep)
Jul 01 12:30:06 liby kernel: PM: suspend exit
Jul 01 12:39:08 liby kernel: PM: suspend entry (deep)
Jul 01 13:27:09 liby kernel: PM: suspend exit
Jul 01 19:16:40 liby kernel: PM: suspend entry (deep)
Jul 01 20:04:22 liby kernel: PM: suspend exit
Jul 01 20:10:01 liby kernel: PM: suspend entry (deep)
Jul 01 20:20:05 liby kernel: PM: suspend exit
Jul 01 20:53:39 liby kernel: PM: suspend entry (deep)
Jul 01 22:07:19 liby kernel: PM: suspend exit
Jul 01 22:20:23 liby kernel: PM: suspend entry (deep)
Jul 02 00:11:51 liby kernel: PM: suspend exit
Jul 02 00:30:17 liby kernel: PM: suspend entry (deep)
Jul 02 00:30:40 liby kernel: PM: suspend exit
Jul 02 07:24:44 liby kernel: PM: suspend entry (deep)
Jul 02 07:40:08 liby kernel: PM: suspend exit
Jul 02 07:49:12 liby kernel: PM: suspend entry (deep)
Jul 02 07:53:56 liby kernel: PM: suspend exit
Jul 02 08:56:05 liby kernel: PM: suspend entry (deep)
Jul 02 09:27:06 liby kernel: PM: suspend exit
Jul 02 09:38:16 liby kernel: PM: suspend entry (deep)
Jul 02 09:52:20 liby kernel: PM: suspend exit
Jul 02 10:14:43 liby kernel: PM: suspend entry (deep)
Jul 02 12:03:30 liby kernel: PM: suspend exit
Jul 02 12:12:34 liby kernel: PM: suspend entry (deep)
Jul 02 12:28:20 liby kernel: PM: suspend exit
Jul 02 12:34:27 liby kernel: PM: suspend entry (deep)
Jul 02 12:46:56 liby kernel: PM: suspend exit
Jul 02 12:56:10 liby kernel: PM: suspend entry (deep)
Jul 02 12:56:52 liby kernel: PM: suspend exit
Jul 02 12:56:52 liby kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s
Jul 02 12:56:52 liby kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x6 [current] 
Jul 02 12:56:52 liby kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x28 ASCQ=0x0 
Jul 02 12:56:52 liby kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x2a 2a 00 18 4e e4 80 00 00 28 00
Jul 02 13:02:15 liby kernel: PM: suspend entry (deep)
Jul 02 13:26:45 liby kernel: PM: suspend exit
Jul 02 13:35:50 liby kernel: PM: suspend entry (deep)
Jul 02 13:54:00 liby kernel: PM: suspend exit
Jul 02 14:03:59 liby kernel: PM: suspend entry (deep)
Jul 02 14:24:24 liby kernel: PM: suspend exit
Jul 02 14:33:26 liby kernel: PM: suspend entry (deep)
Jul 02 16:07:19 liby kernel: PM: suspend exit
Jul 02 16:12:58 liby kernel: PM: suspend entry (deep)
Jul 02 20:59:55 liby kernel: PM: suspend exit
Jul 03 10:24:26 liby kernel: PM: suspend entry (deep)
Jul 03 10:36:40 liby kernel: PM: suspend exit
Jul 03 10:48:09 liby kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s
Jul 03 10:48:09 liby kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x2 [current] 
Jul 03 10:48:09 liby kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x3a ASCQ=0x0 
Jul 03 10:48:09 liby kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 00 00 00 00 08 00
Jul 03 10:48:09 liby kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s
Jul 03 10:48:09 liby kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x2 [current] 
Jul 03 10:48:09 liby kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x3a ASCQ=0x0 
Jul 03 10:48:09 liby kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 00 00 00 00 08 00
Jul 03 13:41:05 liby kernel: PM: suspend entry (deep)
Jul 03 13:41:37 liby kernel: PM: suspend exit
Jul 03 13:42:13 liby kernel: sd 0:0:0:0: [sda] Media removed, stopped polling
Jul 03 13:42:13 liby kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk
Jul 03 14:15:13 liby kernel: sd 0:0:0:0: [sda] 499744768 512-byte logical blocks: (256 GB/238 GiB)
Jul 03 14:15:13 liby kernel: sd 0:0:0:0: [sda] Write Protect is off
Jul 03 14:15:13 liby kernel: sd 0:0:0:0: [sda] Mode Sense: 23 00 00 00
Jul 03 14:15:13 liby kernel: sd 0:0:0:0: [sda] No Caching mode page found
Jul 03 14:15:13 liby kernel: sd 0:0:0:0: [sda] Assuming drive cache: write through
Jul 03 14:15:13 liby kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk
Jul 03 16:20:30 liby kernel: PM: suspend entry (deep)
Jul 03 16:37:22 liby kernel: PM: suspend exit
Jul 03 16:37:23 liby kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s
Jul 03 16:37:23 liby kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x6 [current] 
Jul 03 16:37:23 liby kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x28 ASCQ=0x0 
Jul 03 16:37:23 liby kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0b 49 7f 60 00 00 20 00
Jul 03 16:47:21 liby kernel: PM: suspend entry (deep)
Jul 03 17:45:32 liby kernel: PM: suspend exit
-- Boot 53a89474e80f416b9ef4369c8f87d185 --

          I figured this was because vdd_1v8 is being shut down in suspend.

          &usdhc1 {
        pinctrl-names = "default", "state_100mhz", "state_200mhz";
        pinctrl-0 = <&pinctrl_usdhc1>;
        pinctrl-1 = <&pinctrl_usdhc1_100mhz>;                                                                                                                  
        pinctrl-2 = <&pinctrl_usdhc1_200mhz>;
        bus-width = <8>; 
        vmmc-supply = <&reg_vdd_3v3>;
        power-supply = <&reg_vdd_1v8>;
        non-removable;
        status = "okay";
};

          Maybe you have more insight on this?

          Edited by Kyle Evans
        • Sebastian Krzyszkowiak
          Sebastian Krzyszkowiak @sebastian.krzyszkowiak ·
          Owner

          usdhc1 is irrelevant to the SD card - that's where eMMC is connected to; usdhc2 is Wi-Fi card. SD card reader is a USB device integrated into the USB hub (USB2642).

        • Kyle Evans
          Kyle Evans @fuzzy7k ·

          Well I feel dumb. There was a time when I knew that. Maybe it is another hub issue, upstream of sd_en?

          As a hack until this bug is resolved, I installed the following script in /lib/systemd/system-sleep/wait-resume.

          #!/bin/sh
/usr/bin/systemd-cat -p5 /usr/bin/echo ${1} ${2}

case "${1}" in
        post)
                sleep 1.5
                systemd-cat -p4 /usr/bin/echo "hack, wait for sdcard"
        ;;
esac
        • Please register or sign in to reply
      • Sebastian Krzyszkowiak mentioned in issue #503 (closed)

        mentioned in issue #503 (closed)

      • Sebastian Krzyszkowiak added 2h 30m of time spent

        added 2h 30m of time spent

      • Sebastian Krzyszkowiak
        Sebastian Krzyszkowiak @sebastian.krzyszkowiak ·
        Owner

        Turns out this is completely unrelated to USB suspend and it isn't even specific to Librem 5 - it's reproducible on a PC with a USB card reader as long as /sys/module/block/parameters/events_dfl_poll_msecs is set to 0 or a high value.

        Note to self: a device specific poll rate can be set at /sys/class/block/sda/events_poll_msecs

        Edited by Sebastian Krzyszkowiak
      • Sebastian Krzyszkowiak added 5h 50m of time spent

        added 5h 50m of time spent

      • Sebastian Krzyszkowiak mentioned in merge request !788 (closed)

        mentioned in merge request !788 (closed)

      • Sebastian Krzyszkowiak mentioned in commit 0c6033f2

        mentioned in commit 0c6033f2

      • Sebastian Krzyszkowiak closed with commit 66cb423b

        closed with commit 66cb423b

      Please register or sign in to reply