Hi,
I have a device that’s showing weird a behavior… Almost nothing except BalenaVPN is starting on the device, not even Balena Engine.
There is not a lot to check except the DMESG logs below, which confirm the issues of the device.
[ 3.963396] input: Video Bus as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/LNXVIDEO:00/input/input5
[ 3.963405] libphy: r8169: probed
[ 3.963881] r8169 0000:02:00.0 eth1: RTL8168evl/8111evl, 40:62:31:14:06:91, XID 2c9, IRQ 121
[ 3.963889] r8169 0000:02:00.0 eth1: jumbo features [frames: 9194 bytes, tx checksumming: ko]
[ 3.964811] snd_hda_intel 0000:00:1b.0: bound 0000:00:02.0 (ops i915_audio_component_bind_ops [i915])
[ 3.985810] at24 0-0050: 256 byte spd EEPROM, read-only
[ 4.098388] snd_hda_codec_realtek hdaudioC0D0: autoconfig for ALC662 rev3: line_outs=1 (0x14/0x0/0x0/0x0/0x0) type:line
[ 4.098395] snd_hda_codec_realtek hdaudioC0D0: speaker_outs=0 (0x0/0x0/0x0/0x0/0x0)
[ 4.098398] snd_hda_codec_realtek hdaudioC0D0: hp_outs=1 (0x1b/0x0/0x0/0x0/0x0)
[ 4.098400] snd_hda_codec_realtek hdaudioC0D0: mono: mono_out=0x0
[ 4.098402] snd_hda_codec_realtek hdaudioC0D0: inputs:
[ 4.098405] snd_hda_codec_realtek hdaudioC0D0: Front Mic=0x19
[ 4.098408] snd_hda_codec_realtek hdaudioC0D0: Rear Mic=0x18
[ 4.126533] r8169 0000:01:00.0 enp1s0: renamed from eth0
[ 4.129106] zram: Can't change algorithm for initialized device
[ 4.140087] i915 0000:00:02.0: [drm] Cannot find any crtc or sizes
[ 4.149327] r8169 0000:02:00.0 enp2s0: renamed from eth1
[ 4.164312] input: HDA Intel PCH Front Mic as /devices/pci0000:00/0000:00:1b.0/sound/card0/input6
[ 4.164677] input: HDA Intel PCH Rear Mic as /devices/pci0000:00/0000:00:1b.0/sound/card0/input7
[ 4.164984] input: HDA Intel PCH Line Out as /devices/pci0000:00/0000:00:1b.0/sound/card0/input8
[ 4.165278] input: HDA Intel PCH Front Headphone as /devices/pci0000:00/0000:00:1b.0/sound/card0/input9
[ 4.165682] input: HDA Intel PCH HDMI/DP,pcm=3 as /devices/pci0000:00/0000:00:1b.0/sound/card0/input10
[ 4.165976] input: HDA Intel PCH HDMI/DP,pcm=7 as /devices/pci0000:00/0000:00:1b.0/sound/card0/input11
[ 4.166270] input: HDA Intel PCH HDMI/DP,pcm=8 as /devices/pci0000:00/0000:00:1b.0/sound/card0/input12
[ 4.343998] Adding 4030788k swap on /dev/zram0. Priority:-2 extents:1 across:4030788k SS
[ 4.379240] random: crng init done
[ 4.480714] i915 0000:00:02.0: [drm] Cannot find any crtc or sizes
[ 4.666068] i915 0000:00:02.0: [drm] Cannot find any crtc or sizes
[ 6.828058] r8169 0000:01:00.0: Direct firmware load for rtl_nic/rtl8168e-3.fw failed with error -2
[ 6.828069] r8169 0000:01:00.0: Unable to load firmware rtl_nic/rtl8168e-3.fw (-2)
[ 6.828578] RTL8211E Gigabit Ethernet r8169-100:00: attached PHY driver [RTL8211E Gigabit Ethernet] (mii_bus:phy_addr=r8169-100:00, irq=IGNORE)
[ 6.894692] r8169 0000:01:00.0 enp1s0: Link is Down
[ 6.901702] r8169 0000:02:00.0: Direct firmware load for rtl_nic/rtl8168e-3.fw failed with error -2
[ 6.901711] r8169 0000:02:00.0: Unable to load firmware rtl_nic/rtl8168e-3.fw (-2)
[ 6.902858] RTL8211E Gigabit Ethernet r8169-200:00: attached PHY driver [RTL8211E Gigabit Ethernet] (mii_bus:phy_addr=r8169-200:00, irq=IGNORE)
[ 6.967556] r8169 0000:02:00.0 enp2s0: Link is Down
[ 9.518380] r8169 0000:02:00.0 enp2s0: Link is Up - 1Gbps/Full - flow control off
[ 9.518400] IPv6: ADDRCONF(NETDEV_CHANGE): enp2s0: link becomes ready
[ 38.074009] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 38.074039] ata2.00: failed command: WRITE DMA EXT
[ 38.074076] ata2.00: cmd 35/00:40:50:f2:15/00:05:00:00:00/e0 tag 20 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 38.074090] ata2.00: status: { DRDY }
[ 38.074114] ata2: hard resetting link
[ 38.384970] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 38.391197] ata2.00: configured for UDMA/133
[ 38.391235] ata2.00: device reported invalid CHS sector 0
[ 38.391288] ata2: EH complete
[ 68.787024] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 68.787056] ata2.00: failed command: WRITE DMA EXT
[ 68.787095] ata2.00: cmd 35/00:40:50:f2:15/00:05:00:00:00/e0 tag 10 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 68.787110] ata2.00: status: { DRDY }
[ 68.787134] ata2: hard resetting link
[ 69.095722] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 69.102020] ata2.00: configured for UDMA/133
[ 69.102057] ata2.00: device reported invalid CHS sector 0
[ 69.102108] ata2: EH complete
[ 99.503005] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 99.503038] ata2.00: failed command: WRITE DMA EXT
[ 99.503078] ata2.00: cmd 35/00:40:50:f2:15/00:05:00:00:00/e0 tag 17 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 99.503094] ata2.00: status: { DRDY }
[ 99.503118] ata2: hard resetting link
[ 99.816729] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 99.822800] ata2.00: configured for UDMA/133
[ 99.822835] ata2.00: device reported invalid CHS sector 0
[ 99.822887] ata2: EH complete
[ 130.222996] ata2: limiting SATA link speed to 3.0 Gbps
[ 130.223024] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 130.223051] ata2.00: failed command: WRITE DMA EXT
[ 130.223089] ata2.00: cmd 35/00:40:50:f2:15/00:05:00:00:00/e0 tag 7 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 130.223103] ata2.00: status: { DRDY }
[ 130.223130] ata2: hard resetting link
[ 130.536795] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[ 130.543227] ata2.00: configured for UDMA/133
[ 130.543265] ata2.00: device reported invalid CHS sector 0
[ 130.543317] ata2: EH complete
[ 160.943002] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 160.943033] ata2.00: failed command: WRITE DMA EXT
[ 160.943074] ata2.00: cmd 35/00:40:50:f2:15/00:05:00:00:00/e0 tag 23 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 160.943089] ata2.00: status: { DRDY }
[ 160.943112] ata2: hard resetting link
[ 161.256061] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[ 161.261958] ata2.00: configured for UDMA/133
[ 161.261996] ata2.00: device reported invalid CHS sector 0
[ 161.262049] ata2: EH complete
[ 191.663004] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 191.663035] ata2.00: failed command: WRITE DMA EXT
[ 191.663075] ata2.00: cmd 35/00:40:50:f2:15/00:05:00:00:00/e0 tag 1 dma 688128 out
res 40/00:01:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 191.663091] ata2.00: status: { DRDY }
[ 191.663115] ata2: hard resetting link
[ 191.975647] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[ 191.982073] ata2.00: configured for UDMA/133
[ 191.982201] sd 1:0:0:0: [sdb] tag#1 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08 cmd_age=183s
[ 191.982225] sd 1:0:0:0: [sdb] tag#1 Sense Key : 0x5 [current]
[ 191.982241] sd 1:0:0:0: [sdb] tag#1 ASC=0x21 ASCQ=0x4
[ 191.982260] sd 1:0:0:0: [sdb] tag#1 CDB: opcode=0x2a 2a 00 00 15 f2 50 00 05 40 00
[ 191.982284] blk_update_request: I/O error, dev sdb, sector 1438288 op 0x1:(WRITE) flags 0x4800 phys_seg 168 prio class 0
[ 191.982308] Buffer I/O error on dev sdb6, logical block 1610, lost sync page write
[ 191.982594] ata2: EH complete
[ 222.394064] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 222.394095] ata2.00: failed command: WRITE DMA EXT
[ 222.394133] ata2.00: cmd 35/00:40:90:f7:15/00:05:00:00:00/e0 tag 13 dma 688128 out
res 40/00:01:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 222.394148] ata2.00: status: { DRDY }
[ 222.394172] ata2: hard resetting link
[ 222.704717] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 320)
[ 222.710749] ata2.00: configured for UDMA/133
[ 222.710823] ata2: EH complete
[ 253.102997] ata2: limiting SATA link speed to 1.5 Gbps
[ 253.103025] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 253.103051] ata2.00: failed command: WRITE DMA EXT
[ 253.103090] ata2.00: cmd 35/00:40:90:f7:15/00:05:00:00:00/e0 tag 3 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 253.103104] ata2.00: status: { DRDY }
[ 253.103131] ata2: hard resetting link
[ 253.416801] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 253.422888] ata2.00: configured for UDMA/133
[ 253.422969] ata2.00: device reported invalid CHS sector 0
[ 253.423019] ata2: EH complete
[ 283.823112] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 283.823144] ata2.00: failed command: WRITE DMA EXT
[ 283.823186] ata2.00: cmd 35/00:40:90:f7:15/00:05:00:00:00/e0 tag 18 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 283.823202] ata2.00: status: { DRDY }
[ 283.823226] ata2: hard resetting link
[ 284.136595] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 284.142454] ata2.00: configured for UDMA/133
[ 284.142488] ata2.00: device reported invalid CHS sector 0
[ 284.142539] ata2: EH complete
[ 314.543004] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 314.543037] ata2.00: failed command: WRITE DMA EXT
[ 314.543078] ata2.00: cmd 35/00:40:90:f7:15/00:05:00:00:00/e0 tag 8 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 314.543092] ata2.00: status: { DRDY }
[ 314.543117] ata2: hard resetting link
[ 314.854594] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 314.860461] ata2.00: configured for UDMA/133
[ 314.860497] ata2.00: device reported invalid CHS sector 0
[ 314.860544] ata2: EH complete
[ 332.969030] EXT4-fs (sdb6): error count since last fsck: 5
[ 332.969049] EXT4-fs (sdb6): initial error at time 1645124929: ext4_journal_check_start:83
[ 332.969060] EXT4-fs (sdb6): last error at time 1645124946: ext4_journal_check_start:83
[ 332.969069] EXT4-fs (sdb5): error count since last fsck: 2
[ 332.969073] EXT4-fs (sdb5): initial error at time 1645126697: ext4_validate_inode_bitmap:105
[ 332.969085] EXT4-fs (sdb5): last error at time 1645126727: ext4_journal_check_start:83
[ 345.263069] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 345.263102] ata2.00: failed command: WRITE DMA EXT
[ 345.263144] ata2.00: cmd 35/00:40:90:f7:15/00:05:00:00:00/e0 tag 15 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 345.263160] ata2.00: status: { DRDY }
[ 345.263186] ata2: hard resetting link
[ 345.576978] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 345.582833] ata2.00: configured for UDMA/133
[ 345.582868] ata2.00: device reported invalid CHS sector 0
[ 345.583026] ata2: EH complete
[ 375.982998] ata2.00: limiting speed to UDMA/100:PIO4
[ 375.983025] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 375.983052] ata2.00: failed command: WRITE DMA EXT
[ 375.983087] ata2.00: cmd 35/00:40:90:f7:15/00:05:00:00:00/e0 tag 24 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 375.983101] ata2.00: status: { DRDY }
[ 375.983125] ata2: hard resetting link
[ 376.295865] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 376.302001] ata2.00: configured for UDMA/100
[ 376.302035] ata2.00: device reported invalid CHS sector 0
[ 376.302125] sd 1:0:0:0: [sdb] tag#24 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08 cmd_age=184s
[ 376.302145] sd 1:0:0:0: [sdb] tag#24 Sense Key : 0x5 [current]
[ 376.302161] sd 1:0:0:0: [sdb] tag#24 ASC=0x21 ASCQ=0x4
[ 376.302181] sd 1:0:0:0: [sdb] tag#24 CDB: opcode=0x2a 2a 00 00 15 f7 90 00 05 40 00
[ 376.302201] blk_update_request: I/O error, dev sdb, sector 1439632 op 0x1:(WRITE) flags 0x4800 phys_seg 168 prio class 0
[ 376.302484] ata2: EH complete
[ 406.714056] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 406.714089] ata2.00: failed command: WRITE DMA EXT
[ 406.714127] ata2.00: cmd 35/00:40:d0:fc:15/00:05:00:00:00/e0 tag 27 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 406.714144] ata2.00: status: { DRDY }
[ 406.714169] ata2: hard resetting link
[ 407.024096] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 407.029979] ata2.00: configured for UDMA/100
[ 407.030014] ata2.00: device reported invalid CHS sector 0
[ 407.030062] ata2: EH complete
[ 437.423003] ata2.00: limiting speed to UDMA/33:PIO4
[ 437.423030] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 437.423054] ata2.00: failed command: WRITE DMA EXT
[ 437.423091] ata2.00: cmd 35/00:40:d0:fc:15/00:05:00:00:00/e0 tag 13 dma 688128 out
res 40/00:01:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 437.423108] ata2.00: status: { DRDY }
[ 437.423134] ata2: hard resetting link
[ 437.735844] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 437.741897] ata2.00: configured for UDMA/33
[ 437.742018] ata2: EH complete
[ 468.143007] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 468.143040] ata2.00: failed command: WRITE DMA EXT
[ 468.143081] ata2.00: cmd 35/00:40:d0:fc:15/00:05:00:00:00/e0 tag 22 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 468.143096] ata2.00: status: { DRDY }
[ 468.143119] ata2: hard resetting link
[ 468.456861] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 468.462800] ata2.00: configured for UDMA/33
[ 468.462836] ata2.00: device reported invalid CHS sector 0
[ 468.462886] ata2: EH complete
[ 498.863007] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 498.863039] ata2.00: failed command: WRITE DMA EXT
[ 498.863079] ata2.00: cmd 35/00:40:d0:fc:15/00:05:00:00:00/e0 tag 2 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 498.863094] ata2.00: status: { DRDY }
[ 498.863117] ata2: hard resetting link
[ 499.176835] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 499.182988] ata2.00: configured for UDMA/33
[ 499.183026] ata2.00: device reported invalid CHS sector 0
[ 499.183075] ata2: EH complete
[ 529.582997] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 529.583028] ata2.00: failed command: WRITE DMA EXT
[ 529.583067] ata2.00: cmd 35/00:40:d0:fc:15/00:05:00:00:00/e0 tag 20 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 529.583083] ata2.00: status: { DRDY }
[ 529.583107] ata2: hard resetting link
[ 529.896663] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 529.902951] ata2.00: configured for UDMA/33
[ 529.902986] ata2.00: device reported invalid CHS sector 0
[ 529.903036] ata2: EH complete
[ 560.302996] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[ 560.303029] ata2.00: failed command: WRITE DMA EXT
[ 560.303068] ata2.00: cmd 35/00:40:d0:fc:15/00:05:00:00:00/e0 tag 24 dma 688128 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[ 560.303086] ata2.00: status: { DRDY }
[ 560.303110] ata2: hard resetting link
[ 560.616797] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
[ 560.622812] ata2.00: configured for UDMA/33
[ 560.622847] ata2.00: device reported invalid CHS sector 0
[ 560.622990] sd 1:0:0:0: [sdb] tag#24 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=0x08 cmd_age=184s
[ 560.623014] sd 1:0:0:0: [sdb] tag#24 Sense Key : 0x5 [current]
[ 560.623030] sd 1:0:0:0: [sdb] tag#24 ASC=0x21 ASCQ=0x4
[ 560.623050] sd 1:0:0:0: [sdb] tag#24 CDB: opcode=0x2a 2a 00 00 15 fc d0 00 05 40 00
[ 560.623071] blk_update_request: I/O error, dev sdb, sector 1440976 op 0x1:(WRITE) flags 0x4800 phys_seg 168 prio class 0
[ 560.623352] ata2: EH complete
[ 560.625249] Aborting journal on device sdb6-8.
[ 560.750613] EXT4-fs error (device sdb6): ext4_journal_check_start:83: Detected aborted journal
[ 560.750622] EXT4-fs (sdb6): Remounting filesystem read-only
Could this be a corrupted OS Drive? Not sure… I mean I can access the HOST OS, so the device is booting and starting the VPN.
Please advice on possible device recovery.
Regards