Rsync over ssh kills OSMC

dangelovich · 15 November 2015 17:26

So I’m rsyncing over ssh to backup /home/kodi (running from my NAS to pull the data):

rsync -axv --delete -e “ssh -l root” 192.168.1.108:/home/osmc/ /mnt/data/Backups/osmc-pi/root/home/osmc/

And it seems to consistently kill the OS. Pushing from OSMC has the same effect. Running it all on a Raspberry Pi 1 Model B…

Anyway, journalctl spits this out during the rsync:

`Nov 15 12:09:59 osmc sshd[401]: Accepted publickey for root from 192.168.1.110 port 43280 ssh2: RSA 22:10:9c:30:56:23:5b:92:fe:14:e7:05:31:bb:3f:75
Nov 15 12:09:59 osmc sshd[401]: pam_unix(sshd:session): session opened for user root by (uid=0)
Nov 15 12:09:59 osmc systemd-logind[182]: New session c2 of user root.
Nov 15 12:09:59 osmc systemd[403]: pam_unix(systemd-user:session): session opened for user root by (uid=0)
Nov 15 12:09:59 osmc systemd[403]: Starting Paths.
Nov 15 12:09:59 osmc systemd[403]: Reached target Paths.
Nov 15 12:09:59 osmc systemd[403]: Starting Timers.
Nov 15 12:09:59 osmc systemd[403]: Reached target Timers.
Nov 15 12:09:59 osmc systemd[403]: Starting Sockets.
Nov 15 12:09:59 osmc systemd[403]: Reached target Sockets.
Nov 15 12:09:59 osmc systemd[403]: Starting Basic System.
Nov 15 12:09:59 osmc systemd[403]: Reached target Basic System.
Nov 15 12:09:59 osmc systemd[403]: Starting Default.
Nov 15 12:09:59 osmc systemd[403]: Reached target Default.
Nov 15 12:09:59 osmc systemd[403]: Startup finished in 76ms.
Nov 15 12:10:11 osmc kernel: mmc0: Timeout waiting for hardware interrupt.
Nov 15 12:10:11 osmc kernel: mmcblk0: error -110 transferring data, sector 14471040, nr 104, cmd response 0x900, card status 0xb00
Nov 15 12:10:13 osmc kernel: mmc0: card never left busy state
Nov 15 12:10:13 osmc kernel: mmc0: tried to reset card
Nov 15 12:10:13 osmc kernel: mmcblk0: retrying using single block read
Nov 15 12:10:13 osmc kernel: mmcblk0: error -110 sending status command, retrying
Nov 15 12:10:13 osmc kernel: mmcblk0: error -110 sending status command, retrying
Nov 15 12:10:13 osmc kernel: mmcblk0: error -110 sending status command, aborting
Nov 15 12:10:13 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_end_bio:332: I/O error -5 writing to inode 263614 (offset 0 size 4096 starting block 1147515)
Nov 15 12:10:13 osmc kernel: Buffer I/O error on device mmcblk0p2, logical block 1084794
Nov 15 12:10:13 osmc kernel: mmc0: card 0007 removed
Nov 15 12:10:13 osmc kernel: Aborting journal on device mmcblk0p2-8.
Nov 15 12:10:13 osmc kernel: JBD2: Error -5 detected when updating journal superblock for mmcblk0p2-8.
Nov 15 12:10:14 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 4: comm rsync: error -5 reading directory block
Nov 15 12:10:14 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 2: comm rsync: error -5 reading directory block
Nov 15 12:10:14 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 8: comm rsync: error -5 reading directory block
Nov 15 12:10:14 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 1: comm rsync: error -5 reading directory block
Nov 15 12:10:14 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 2: comm rsync: error -5 reading directory block
Nov 15 12:10:14 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 5: comm rsync: error -5 reading directory block
Nov 15 12:10:14 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 2: comm rsync: error -5 reading directory block
Nov 15 12:10:14 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 4: comm rsync: error -5 reading directory block
Nov 15 12:10:14 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 4: comm rsync: error -5 reading directory block
Nov 15 12:10:14 osmc kernel: EXT4-fs error (device mmcblk0p2): __ext4_get_inode_loc:3927: inode #400156: block 1573521: comm rsync: unable to read itable block
Nov 15 12:10:14 osmc kernel: EXT4-fs error (device mmcblk0p2): __ext4_get_inode_loc:3927: inode #407196: block 1573961: comm rsync: unable to read itable block
Nov 15 12:10:14 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:10:14 osmc kernel: EXT4-fs error (device mmcblk0p2): __ext4_get_inode_loc:3927: inode #394999: block 1573199: comm rsync: unable to read itable block
Nov 15 12:10:14 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:10:14 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #12: comm systemd-udevd: reading directory lblock 0
Nov 15 12:10:14 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:10:14 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #132613: comm systemd-udevd: reading directory lblock 0
Nov 15 12:10:14 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:10:14 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #12: comm systemd-udevd: reading directory lblock 0
Nov 15 12:10:14 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:10:14 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #130105: comm systemd-udevd: reading directory lblock 0
Nov 15 12:10:14 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:10:14 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #130462: comm systemd-udevd: reading directory lblock 0
Nov 15 12:10:14 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:10:14 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #12: comm systemd-udevd: reading directory lblock 0
Nov 15 12:10:14 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:10:14 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #270331: comm systemd-udevd: reading directory lblock 0
Nov 15 12:10:14 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:10:14 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:10:14 osmc udisks-glue[254]: Device file /dev/mmcblk0p2 unmounted from /
Nov 15 12:10:14 osmc udisks-glue[254]: Device file /dev/mmcblk0p2 removed
Nov 15 12:10:14 osmc udisks-glue[254]: Device file /dev/mmcblk0p1 unmounted from /boot
Nov 15 12:10:14 osmc systemd[411]: Failed at step EXEC spawning /bin/umount: No such file or directory
Nov 15 12:10:14 osmc udisks-glue[254]: Device file /dev/mmcblk0p1 removed
Nov 15 12:10:14 osmc udisks-glue[254]: Device file /dev/mmcblk0 removed
Nov 15 12:10:15 osmc systemd[1]: boot.mount mount process exited, code=exited status=203
Nov 15 12:10:15 osmc systemd[1]: Failed unmounting /boot.
Nov 15 12:10:16 osmc kernel: mmc0: card never left busy state
Nov 15 12:10:16 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:10:16 osmc sshd[401]: Received disconnect from 192.168.1.110: 11: disconnected by user
Nov 15 12:10:16 osmc sshd[401]: pam_unix(sshd:session): session closed for user root
Nov 15 12:10:16 osmc sshd[401]: pam_systemd(sshd:session): Failed to connect to system bus: No such file or directory
Nov 15 12:10:16 osmc sshd[401]: pam_mail(sshd:session): user unknown
Nov 15 12:10:18 osmc kernel: mmc0: card never left busy state
Nov 15 12:10:18 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:10:20 osmc kernel: mmc0: card never left busy state
Nov 15 12:10:20 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:10:22 osmc kernel: mmc0: card never left busy state
Nov 15 12:10:22 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:10:24 osmc kernel: mmc0: card never left busy state
Nov 15 12:10:24 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:10:26 osmc kernel: mmc0: card never left busy state
Nov 15 12:10:26 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:10:28 osmc kernel: mmc0: card never left busy state
Nov 15 12:10:28 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:10:30 osmc kernel: mmc0: card never left busy state
Nov 15 12:10:30 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:10:33 osmc kernel: mmc0: card never left busy state
Nov 15 12:10:33 osmc kernel: mmc0: error -110 whilst initialising SD card
^Cosmc@osmc:~$ sudo reboot
-bash: /usr/bin/sudo: No such file or directory
osmc@osmc:~$ 
`

Basically, it kills the pi, it unmounts / and I have to power cycle it. Thought it might be a memory issue at first, so I set up a 100M swapfile, but it doesn’t even get used. From the logs, it’s some kind of IO issue… changing memory card doesn’t help.
Just not sure if this is a hardware or software issue… The software is fully up to date.
I’m not really sure what to do about it - maybe upgrade to Vero/Pi 2…

sam_nazarko · 15 November 2015 17:40

This could be a SD card issue. The ext4 errors would initially suggest some filesystem corruption, but this is a little bit more alarming:

mmc0: error -110 whilst initialising SD card

You can try the new Raspberry Pi SD card driver.

Plug your SD card in to a computer
Open ‘config.txt’
Add this line:

dtoverlay=sdhost

It would be good if you could let us know what type of card you have – a photo of the front and if there is a serial number on the back, that would help too.

Sam

dangelovich · 15 November 2015 18:01

Thanks for the quick response!

I made the config change, and there’s a little more output but the same overall result:

 `Nov 15 12:59:38 osmc sshd[397]: Accepted publickey for root from 192.168.1.110 port 44216 ssh2: RSA 22:10:9c:30:56:23:5b:92:fe:14:e7:05:31:bb:3f:75
Nov 15 12:59:38 osmc sshd[397]: pam_unix(sshd:session): session opened for user root by (uid=0)
Nov 15 12:59:38 osmc systemd-logind[182]: New session c2 of user root.
Nov 15 12:59:38 osmc systemd[399]: pam_unix(systemd-user:session): session opened for user root by (uid=0)
Nov 15 12:59:38 osmc systemd[399]: Starting Paths.
Nov 15 12:59:38 osmc systemd[399]: Reached target Paths.
Nov 15 12:59:38 osmc systemd[399]: Starting Timers.
Nov 15 12:59:38 osmc systemd[399]: Reached target Timers.
Nov 15 12:59:38 osmc systemd[399]: Starting Sockets.
Nov 15 12:59:38 osmc systemd[399]: Reached target Sockets.
Nov 15 12:59:38 osmc systemd[399]: Starting Basic System.
Nov 15 12:59:38 osmc systemd[399]: Reached target Basic System.
Nov 15 12:59:38 osmc systemd[399]: Starting Default.
Nov 15 12:59:38 osmc systemd[399]: Reached target Default.
Nov 15 12:59:38 osmc systemd[399]: Startup finished in 67ms.
Nov 15 12:59:50 osmc kernel: mmc0: timeout waiting for hardware interrupt.
Nov 15 12:59:50 osmc kernel: mmc0: cmd op 18 arg 0xdccf80 flags 0xb5 - resp 00000900 00000000 00000000 00000000, err 0
Nov 15 12:59:50 osmc kernel: mmc0: data blocks 68 blksz 200 - err 0
Nov 15 12:59:50 osmc kernel: mmc0: stop op 12 arg 0x0 flags 0x95 - resp 00000000 00000000 00000000 00000000, err 0
Nov 15 12:59:50 osmc kernel: mmc0: =========== REGISTER DUMP ===========
Nov 15 12:59:50 osmc kernel: mmc0: SDCMD  0x00004052
Nov 15 12:59:50 osmc kernel: mmc0: SDARG  0x00dccf80
Nov 15 12:59:50 osmc kernel: mmc0: SDTOUT 0x0165a0bc
Nov 15 12:59:50 osmc kernel: mmc0: SDCDIV 0x00000006
Nov 15 12:59:50 osmc kernel: mmc0: SDRSP0 0x00000900
Nov 15 12:59:50 osmc kernel: mmc0: SDRSP1 0x00001269
Nov 15 12:59:50 osmc kernel: mmc0: SDRSP2 0xffffffff
Nov 15 12:59:50 osmc kernel: mmc0: SDRSP3 0x0002c01f
Nov 15 12:59:50 osmc kernel: mmc0: SDHSTS 0x00000080
Nov 15 12:59:50 osmc kernel: mmc0: SDVDD  0x00000001
Nov 15 12:59:50 osmc kernel: mmc0: SDEDM  0x00010801
Nov 15 12:59:50 osmc kernel: mmc0: SDHCFG 0x0000040e
Nov 15 12:59:50 osmc kernel: mmc0: SDHBCT 0x00000200
Nov 15 12:59:50 osmc kernel: mmc0: SDHBLC 0x00000018
Nov 15 12:59:50 osmc kernel: mmc0: ===========================================
Nov 15 12:59:50 osmc kernel: mmcblk0: error -110 transferring data, sector 14471040, nr 104, cmd response 0x900, card status 0xb00
Nov 15 12:59:52 osmc kernel: mmc0: card never left busy state
Nov 15 12:59:52 osmc kernel: mmc0: tried to reset card
Nov 15 12:59:52 osmc kernel: mmcblk0: retrying using single block read
Nov 15 12:59:52 osmc kernel: mmc0: command timeout
Nov 15 12:59:52 osmc kernel: mmc0: command timeout
Nov 15 12:59:52 osmc kernel: mmcblk0: error -110 sending status command, retrying
Nov 15 12:59:52 osmc kernel: mmc0: command timeout
Nov 15 12:59:52 osmc kernel: mmcblk0: error -110 sending status command, retrying
Nov 15 12:59:52 osmc kernel: mmc0: command timeout
Nov 15 12:59:52 osmc kernel: mmcblk0: error -110 sending status command, aborting
Nov 15 12:59:52 osmc kernel: mmc0: command timeout
Nov 15 12:59:52 osmc kernel: mmc0: command timeout
Nov 15 12:59:52 osmc kernel: mmc0: command timeout
Nov 15 12:59:52 osmc kernel: mmc0: command timeout
Nov 15 12:59:52 osmc kernel: mmc0: card 0007 removed
Nov 15 12:59:53 osmc kernel: EXT4-fs error (device mmcblk0p2): __ext4_get_inode_loc:3927: inode #397075: block 1573329: comm rsync: unable to read itable block
Nov 15 12:59:53 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #12: comm systemd-udevd: reading directory lblock 0
Nov 15 12:59:53 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:59:53 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #132613: comm systemd-udevd: reading directory lblock 0
Nov 15 12:59:53 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:59:53 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #12: comm systemd-udevd: reading directory lblock 0
Nov 15 12:59:53 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:59:53 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #130105: comm systemd-udevd: reading directory lblock 0
Nov 15 12:59:53 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:59:53 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #130462: comm systemd-udevd: reading directory lblock 0
Nov 15 12:59:53 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:59:53 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #12: comm systemd-udevd: reading directory lblock 0
Nov 15 12:59:53 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:59:53 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #270331: comm systemd-udevd: reading directory lblock 0
Nov 15 12:59:53 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:59:53 osmc kernel: EXT4-fs error (device mmcblk0p2): ext4_find_entry:1451: inode #130402: comm systemd-udevd: reading directory lblock 0
Nov 15 12:59:53 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:59:53 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 7: comm rsync: error -5 reading directory block
Nov 15 12:59:53 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 4: comm rsync: error -5 reading directory block
Nov 15 12:59:53 osmc kernel: EXT4-fs error (device mmcblk0p2): __ext4_get_inode_loc:3927: inode #394601: block 1573174: comm rsync: unable to read itable block
Nov 15 12:59:53 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:59:53 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 8: comm rsync: error -5 reading directory block
Nov 15 12:59:53 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 1: comm rsync: error -5 reading directory block
Nov 15 12:59:53 osmc kernel: EXT4-fs (mmcblk0p2): previous I/O error to superblock detected
Nov 15 12:59:53 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 5: comm rsync: error -5 reading directory block
Nov 15 12:59:53 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 4: comm rsync: error -5 reading directory block
Nov 15 12:59:53 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 4: comm rsync: error -5 reading directory block
Nov 15 12:59:53 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 4: comm rsync: error -5 reading directory block
Nov 15 12:59:53 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 8: comm rsync: error -5 reading directory block
Nov 15 12:59:53 osmc kernel: EXT4-fs warning (device mmcblk0p2): ext4_dx_find_entry:1520: inode #390789: lblock 4: comm rsync: error -5 reading directory block
Nov 15 12:59:53 osmc udisks-glue[241]: Device file /dev/mmcblk0p2 unmounted from /
Nov 15 12:59:53 osmc udisks-glue[241]: Device file /dev/mmcblk0p2 removed
Nov 15 12:59:53 osmc udisks-glue[241]: Device file /dev/mmcblk0p1 unmounted from /boot
Nov 15 12:59:53 osmc udisks-glue[241]: Device file /dev/mmcblk0p1 removed
Nov 15 12:59:53 osmc systemd[407]: Failed at step EXEC spawning /bin/umount: No such file or directory
Nov 15 12:59:53 osmc udisks-glue[241]: Device file /dev/mmcblk0 removed
Nov 15 12:59:54 osmc systemd[1]: boot.mount mount process exited, code=exited status=203
Nov 15 12:59:54 osmc systemd[1]: Failed unmounting /boot.
Nov 15 12:59:55 osmc sshd[397]: Received disconnect from 192.168.1.110: 11: disconnected by user
Nov 15 12:59:55 osmc sshd[397]: pam_unix(sshd:session): session closed for user root
Nov 15 12:59:55 osmc sshd[397]: pam_systemd(sshd:session): Failed to connect to system bus: No such file or directory
Nov 15 12:59:55 osmc sshd[397]: pam_mail(sshd:session): user unknown
Nov 15 12:59:55 osmc kernel: mmc0: card never left busy state
Nov 15 12:59:55 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:59:55 osmc kernel: mmc0: command timeout
Nov 15 12:59:57 osmc kernel: mmc0: card never left busy state
Nov 15 12:59:57 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:59:57 osmc kernel: mmc0: command timeout
Nov 15 12:59:59 osmc kernel: mmc0: card never left busy state
Nov 15 12:59:59 osmc kernel: mmc0: error -110 whilst initialising SD card
Nov 15 12:59:59 osmc kernel: mmc0: command timeout
^Cosmc@osmc:~$ sudo reboot
-bash: /usr/bin/sudo: No such file or directory
osmc@osmc:~$

Also, SD card images: http://imgur.com/a/EUhYu

sam_nazarko · 15 November 2015 18:07

The card may be old then. If you can, try another SD card with a fresh install and let us know how you get on.

Cheers

Sam

DBMandrake · 15 November 2015 21:23

Most likely a faulty SD card.

I’m not a fan of Kingston cards at all, I’d suggest getting a Samsung card or even the official 8GB Raspberry Pi noobs card if 8GB is enough space for you as it performs well for a very reasonable price, and is known to be fully compatible with the Pi.

Toast · 15 November 2015 22:48

small fyi please use the codetag or use the pastelog command when supplying logs

dangelovich · 18 November 2015 00:54

Looks like it may well have been an SD card issue. I replaced the card with a new Samsung 16GB Pro model and rsync is working fine now.
Never seen an SD card fail/cause issues like that before… Didn’t really cross my mind that it could be that simple.

Thankyou to those who responded for your help!