random decryption errors with sun4i-ss on dm-crypt

[txsa...@gmail.com]

Hi

I have a Cubieboard2 device, is Allwinner A20 SOC, running and Armbian 5.00 with kernel 4.4.1.

As in the latest version the sun4i-ss module is added, i tried the hardware crypto acceleration with my 2 TB LUKS encrypted HDD, with 256bit AES-CBC-PLAIN64 encryption.

It was fast, but i noticed that when playing videos from that HDD, there are random errors coming from somewhere. As the same happened when streaming the video on DLNA, and SAMBA, i did some tests.

As the HDD is also used for a backup storage, i compared the original files with the backup on the encrypted HDD, and the most of the bigger files were different.

So i've unloaded sun4i-ss module with "rmmod sun4i_ss" and everything become OK, no video errors, the backup and the original files are identical.

So there is something wrong with this module, as i see only the decryption side is faulty, the encryption seems to be OK.

Any suggestions?

[Dmitriy B.]

2016-02-17 16:39 GMT+03:00 <txsa...@gmail.com>:

Hi

Hello,

 

Any suggestions?

Please, use the scripts/get_maintainer.pl script to get the maintainers of driver you have problems with and notify them about the bug. Author of sun4i-ss might not read this mailing list.

 

Best Regards,

Dmitriy Beykun

[LABBE Corentin]

Hello

Could you give me your cryptsetup version ?
Could you give me the output of "dmesg |grep sun4i-ss"

Furthermore, could you run my testsuite from https://github.com/montjoie/cryptotest

Regards

[txsa...@gmail.com]

Cryptsetup version 1.6.1

dmesg:

[ 5042.093569] sun4i-ss 1c15000.crypto-engine: no reset control found
[ 5042.095143] sun4i-ss 1c15000.crypto-engine: Die ID 0

@cubieboard2:~$ lsmod
Module Size Used by
sun4i_ss 14914 0
twofish_generic 6583 0
twofish_common 13322 1 twofish_generic
serpent_generic 21658 0
algif_skcipher 7280 0
af_alg 4666 1 algif_skcipher
cpufreq_userspace 1417 0
bnep 9892 2
rfcomm 30514 0
bluetooth 299193 10 bnep,rfcomm
rfkill 9328 2 bluetooth
dm_crypt 16841 1
dm_mod 82842 3 dm_crypt
sun4i_codec 10303 3
snd_soc_core 102678 1 sun4i_codec
snd_pcm_dmaengine 2943 1 snd_soc_core
dwmac_sunxi 2239 0
snd_pcm 69300 2 snd_soc_core,snd_pcm_dmaengine
evdev 11268 0
sun4i_ts 3798 0
nvmem_sunxi_sid 2359 0
nvmem_core 7504 1 nvmem_sunxi_sid
snd_timer 17780 1 snd_pcm
fuse 72800 0
snd 41799 5 snd_soc_core,snd_timer,snd_pcm
cpufreq_dt 4010 0
thermal_sys 36472 2 cpufreq_dt,sun4i_ts
soundcore 858 1 snd
uio_pdrv_genirq 2908 0
uio 6784 1 uio_pdrv_genirq
bonding 94395 0

I've compiled af_alg_test, now what params should i use?

i did this: /cryptotest-master/af_alg$ ./af_alg_test aes check
INFO: len=4096
INFO: len=8192
...

and this: cubieboard2:~/cryptotest-master/af_alg$ ./af_alg_test aes 5
INFO: ./af_alg_test will do 5.000000 request
aes 5.000000 requests of 16 in 1771.000000us (0.001771s) 0.002823r/us 2.823264r/ms 2823.263672r/s
aes 5.000000 requests of 32 in 1352.000000us (0.001352s) 0.003698r/us 3.698225r/ms 3698.224854r/s
aes 5.000000 requests of 64 in 1286.000000us (0.001286s) 0.003888r/us 3.888025r/ms 3888.024902r/s

[LABBE Corentin]

Hello

af_alg_test aes check is the good to test it.
Does "af_alg_test aes check" give you any error ?

Could you try kernel 4.4.2 ?

Regards

[txsa...@gmail.com]

2016. február 17., szerda 18:16:09 UTC+1 időpontban txsa...@gmail.com a következőt írta:

af_alg_test aes check writes only "info:" lines, but never errors.

I never compiled kernel, just using apt-get upgrade, so until the next armbian release with 4.4.2 kernel i can't try.

BTW i've forgot something: the errors with decryption only happens with big files (hundreds of mbytes), but not with small few kbyte files. Which file decrpyted wrongly and which is OK seems to always the same.

The errors are in ~10-~40 byte blocks, usually look like this: a block of errors, then few mbytes are perfect, then again a block with errors, again perfect, then error block again ...

[txsa...@gmail.com]

There was a dev, compiled kernel for the device, so i could install and try 4.4.2 kernel, but the result is the same, the problem is still there :(

[m.sile...@gmail.com]

Hi,

If there are any easy-to-setup tests I could run to help identify this issue, I'd be happy to run some tests on a spare Banana Pi I have. If there really is a bug in the sun4i-ss driver or in the accelerator itself that causes data corruption, I'd rather have it found as soon as possible.

@Correntin: Is it possible to let your cryptotest testsuite run tests specifically for large data blocks?

Regards,

Timo

[LABBE Corentin]

Hello

Changing the cryptotest is useless since cryptsetup/dm-crypt cipher data by blocks of 512.
So the length of data changes only the statistic to hit the bug.
So I have writed a test (lukstest) which use cryptsetup, create files on a cipherered partiton and checked it.
If you could test it for knowing if it find the issue. (Just uploaded it on github).

Actualy all my works is to try to reproduce this issue on my setup.
I also try to know if this thread https://www.mail-archive.com/linux-...@vger.kernel.org/msg17926.html is related.

Regards

[txsa...@gmail.com]

This happens:

cubieboard2:~/cryptotest-master/luks$ ./lukstest
ERROR: /mnt/lukstest does not exists

[Corentin LABBE]

Just mkdir /mnt/lukstest

[txsa...@gmail.com]

@cubieboard2:~/cryptotest-master/luks$ sudo ./lukstest
DEBUG: Generate image
DEBUG: Format
Command successful.
DEBUG: open
Key slot 0 unlocked.
Command successful.
/dev/mapper/ctest is active.
type: LUKS1
cipher: aes-cbc-plain
keysize: 256 bits
device: /dev/loop0
loop: /tmp/bench.img
offset: 4096 sectors
size: 315904 sectors
mode: read/write
DEBUG: mkfs
mke2fs 1.42.9 (4-Feb-2014)
END 1 / 10
END 2 / 10
END 3 / 10
END 4 / 10
END 5 / 10
END 6 / 10
END 7 / 10
END 8 / 10
END 9 / 10
END 10 / 10
DEBUG: umount
DEBUG: close

[Timo S.]

Hi Correntin,

Thanks, I installed your cryptotest suite including your new lukstest
tool and ran some tests on a Banana Pi tonight. The results were all
good. After a first successful run of lukstest, I modified the script
and increased the sample size by a factor of 100 (and the image file,
too). Even with the increased sample size, I didn't see any errors
(because of the increased test duration, I ran only 5 iterations,
though). Tests were done on an Armbian installation with Kernel 4.4.1
(with your patch "Add missing state size" on top of it) in order to
resemble the original reporters conditions more closely. I was
planning to do tests with 4.4.2 as well, but since all tests succeeded
so far, I don't think that would change anything.

Regards,

Timo

[Stefan Monnier]

> Thanks, I installed your cryptotest suite including your new lukstest
> tool and ran some tests on a Banana Pi tonight. The results were all
> good. After a first successful run of lukstest, I modified the script
> and increased the sample size by a factor of 100 (and the image file,
> too). Even with the increased sample size, I didn't see any errors
> (because of the increased test duration, I ran only 5 iterations,
> though). Tests were done on an Armbian installation with Kernel 4.4.1
> (with your patch "Add missing state size" on top of it) in order to
> resemble the original reporters conditions more closely. I was
> planning to do tests with 4.4.2 as well, but since all tests succeeded
> so far, I don't think that would change anything.

[ Just a random shot in the dark from someone who knows nothing about
these things. ]

My guess is that to reproduce the problem, you need to have maybe the
same intertwined sequence of decryption and disk access (who I have no
idea what kind of disk he's using).
IOW it could be linked to some interference from the disk's interrupts
or something.


Stefan

[txsa...@gmail.com]

I'm using a Toshiba 2.5" 5400 rpm SATA3, 2 TB disk, of course it's attached on the SATA connector.

[txsa...@gmail.com]

2016. február 17., szerda 18:16:09 UTC+1 időpontban txsa...@gmail.com a következőt írta:

Should i try this with other? HDD? USB is enough, or i should use the SATA?

[Timo S.]

Hi,

I probably know less about these things than you - but I sounds interesting.
I will give it another try lathr this week and set up a samba share on
that drive
to put some stress on the drive while the lukstest is running. Then we should
have interrupts from both the SATA controller and the ehternet controller at the
same time.

Regards,

Timo

[txsa...@gmail.com]

2016. február 17., szerda 18:16:09 UTC+1 időpontban txsa...@gmail.com a következőt írta:

What if caching prevents the error to come up? As if some file is created on the disk, it's automatically cached into RAM, so the read and decryption isn't actually happens.

[txsa...@gmail.com]

2016. február 17., szerda 18:16:09 UTC+1 időpontban txsa...@gmail.com a következőt írta:

I mean at first test, when i've noticed that the files are wrong, i've copied some originial and overwritten the wrongly decrypted files. Then i've compared them and were identical. But after a restart of cubieboard, re-mount, re-check the diff showed differences again, probably because first time the file is read from cache, and not from the disk.

[LABBE Corentin]

Hello

I have added sync/dropcache in my lukstest tool.
But I still didnt trigger the problem.

Regards

LABBE Corentin

[txsa...@gmail.com]

2016. február 17., szerda 18:16:09 UTC+1 időpontban txsa...@gmail.com a következőt írta:

It's not sata related.

I've just connected an USB card reader to cb2, and an SD card, created an aes-cbc-plain64 256 LUKS storage, and copied an 1,5 gbyte ISO file on it. The sha1 checkssum wasn't match when i tested it.
So it's not SATA related.

[Juan Jesús García de Soria Lucena]

Just in the interest of discarding the possibility... Is your power source stable enough? Did you try with a different one?

[txsa...@gmail.com]

2016. február 26., péntek 10:02:53 UTC+1 időpontban Juan Jesús García de Soria Lucena a következőt írta:
> Just in the interest of discarding the possibility... Is your power source stable enough? Did you try with a different one?

If it wouldn't be enough, i would hear the HDD clicking, instability, etc. But i don't, and happens with SD card too. Also is the power wouldn't be stable, then why would it work correctly with SW crypto, and not with HW crypto?

[txsa...@gmail.com]

First i've copied two 1.5-1.8 gbyte files on the luks test microSD, with samba, then see the checksums:

cubie@cubieboard2:~$ sha1sum "/mnt/lukstest/dvdmasol.iso" af645bcb47a0c6ab41e3c95a380fa839394a2dc9 /mnt/lukstest/dvdmasol.iso
cubie@cubieboard2:~$ sha1sum "/mnt/lukstest/xpeee.vdi"
bac8cb2601fb07985436b745f67d25c98e7d7e02 /mnt/lukstest/xpeee.vdi
cubie@cubieboard2:~$ sudo umount /mnt/lukstest
umount: /mnt/lukstest: device is busy.
(In some cases useful info about processes that use
the device is found by lsof(8) or fuser(1))
cubie@cubieboard2:~$ sudo umount /mnt/lukstest
cubie@cubieboard2:~$ sudo cryptsetup luksClose testik
cubie@cubieboard2:~$ sudo sh -c 'echo 3 >/proc/sys/vm/drop_caches'
cubie@cubieboard2:~$ sudo cryptsetup luksOpen /dev/sdb testik
Enter passphrase for /dev/sdb:
cubie@cubieboard2:~$ sudo mount -t ext4 /dev/mapper/testik /mnt/lukstest
cubie@cubieboard2:~$ sha1sum "/mnt/lukstest/dvdmasol.iso"
af645bcb47a0c6ab41e3c95a380fa839394a2dc9 /mnt/lukstest/dvdmasol.iso
cubie@cubieboard2:~$ sha1sum "/mnt/lukstest/xpeee.vdi"
9a81183ffe4cdb6a75688f8786bfb3f061c9121a /mnt/lukstest/xpeee.vdi
cubie@cubieboard2:~$ sha1sum "/mnt/lukstest/dvdmasol.iso"
76e4603badbe853e4cbe11c6ea2dc53d7b0d1285 /mnt/lukstest/dvdmasol.iso
cubie@cubieboard2:~$

[m.sile...@gmail.com]

Hi,

Am Donnerstag, 25. Februar 2016 14:03:52 UTC+1 schrieb clabbe.montjoie:

so, I tried something else today and I did trigger the issue!

I created a 5GB container file on an external harddrive with the same settings your lukstest script does:
cryptsetup luksFormat --verbose -c aes-cbc-plain -h sha1 --key-file=container.key --batch-mode /media/extdisk/container.img
(Of course I formatted and mounted it as well, etc.)

Then I downloaded a Debian DVD image file to the mounted encrypted container:
wget http://cdimage.debian.org/debian-cd/8.3.0/amd64/iso-dvd/debian-8.3.0-amd64-DVD-1.iso
I then compared the md5sum and sha512sum of the downloaded file with the ones Debian provides:
http://cdimage.debian.org/debian-cd/8.3.0/amd64/iso-dvd/MD5SUMS
http://cdimage.debian.org/debian-cd/8.3.0/amd64/iso-dvd/SHA512SUMS

And the checksums DID NOT match!

Now, of course that might have just been a transmission error. So, I went and downloaded the same file again, but this time not to the encrypted container, but directly to the external (unencrypted) harddrive. This time the checksums matched.

Then I copied the downloaded iso file from the unencrypted external disk to the encrypted container. Checking the checksums of the file in the container revealed that they don't match anymore. I repeated this a few times just to see that the resulting checksums are always different.

I tried with other iso files from Debian as well and it seems that it really depends on the specific file whether the issue is triggered or not. I tried e.g. the smaller netinst iso as well and with that everything works as it is supposed to.

Now, there are two more interesting observations:
1) If I repeatedly call md5sum for the same file in the encrypted container, it will always give a different checksum even though the file has not been modified between the commands. So the decryption result really seems random.

2) The issue is not limited to decryption. The file is already corrupted during encryption when it is created. I tested this by unloading the sun4i-ss module after the file has been written to the encrypted container, remounting the container and checking the checksum again (no match).

I'm not done with all my testing yet. I will compile a Linux kernel 4.4.3 image probably on Sunday and see if the error persists. But maybe this helps already to at least reproduce the issue.

Regards,

Timo

[txsa...@gmail.com]

So not my board is faulty. Same happens for me, with cryptotest-master apps i couldn't trigger the problem, only by copying bigger files. Sometimes it happens with 70 mbyte files too, but it's rare. With >1gb files, it's nearly sure.

[txsa...@gmail.com]

2016. február 17., szerda 18:16:09 UTC+1 időpontban txsa...@gmail.com a következőt írta:
> Hi
>
> I have a Cubieboard2 device, is Allwinner A20 SOC, running and Armbian 5.00 with kernel 4.4.1.
>
> As in the latest version the sun4i-ss module is added, i tried the hardware crypto acceleration with my 2 TB LUKS encrypted HDD, with 256bit AES-CBC-PLAIN64 encryption.
>
> It was fast, but i noticed that when playing videos from that HDD, there are random errors coming from somewhere. As the same happened when streaming the video on DLNA, and SAMBA, i did some tests.
>
> As the HDD is also used for a backup storage, i compared the original files with the backup on the encrypted HDD, and the most of the bigger files were different.
>
> So i've unloaded sun4i-ss module with "rmmod sun4i_ss" and everything become OK, no video errors, the backup and the original files are identical.
>
> So there is something wrong with this module, as i see only the decryption side is faulty, the encryption seems to be OK.
>
> Any suggestions?

Any news?

[Corentin LABBE]

Hello

Sorry, due to my main workstation dying, I cannot make any progress.
I am planning to install the same armbian for testing.

Regards

[Timo S.]

Hi,

In the meantime, I re-ran my tests with a fresh kernel 4.4.4 (clean
mainline/stable build, no additional patches). The problem still
persists. With sun4i-ss the data is corrupted, without it, everything
is ok.

Regards,

Timo

[txsa...@gmail.com]

http://irclog.whitequark.org/linux-sunxi/2016-03-11

Chat from timestamp 18:25

[Corentin LABBE]

Le 13/03/2016 16:21, txsa...@gmail.com a écrit :
> http://irclog.whitequark.org/linux-sunxi/2016-03-11
>
> Chat from timestamp 18:25
>

Hello

And I have just sent an email asking for help https://lkml.org/lkml/2016/3/13/64.

Regards

[Timo S.]

Hi Corentin,

Thanks for the update and work on this.

Are you sure that the issue occurs only when deciphering?

When I ran my tests, I was under the impression, that this also happens during encryption or ciphering. Because when I downloaded a large iso image to the encrypted container, unmounted it immediately after, unloaded the sun4i-ss module, mounted the container again and then verified the checksum, it showed a corrupted file. I thought that means something went wrong during encryption already. But my knowledge of all this is little, so I might be wrong.

Regards,

Timo

[Corentin LABBE]

Le 13/03/2016 23:35, Timo S. a écrit :
> Hi Corentin,
>

> Am 13.03.2016 17:32 schrieb "Corentin LABBE" <clabbe....@gmail.com <mailto:clabbe....@gmail.com>>:

>>
>> Le 13/03/2016 16:21, txsa...@gmail.com <mailto:txsa...@gmail.com> a écrit :
>> > http://irclog.whitequark.org/linux-sunxi/2016-03-11
>> >
>> > Chat from timestamp 18:25
>> >
>>
>> Hello
>>
>> And I have just sent an email asking for help https://lkml.org/lkml/2016/3/13/64.
>>
>> Regards
>
> Thanks for the update and work on this.
>
> Are you sure that the issue occurs only when deciphering?
>
> When I ran my tests, I was under the impression, that this also happens during encryption or ciphering. Because when I downloaded a large iso image to the encrypted container, unmounted it immediately
> after, unloaded the sun4i-ss module, mounted the container again and then verified the checksum, it showed a corrupted file. I thought that means something went wrong during encryption already. But my
> knowledge of all this is little, so I might be wrong.
>
> Regards,
>
> Timo
>

Hello

You are right, the current issue seems to be in both way.
But by testing that, I found something strange:
I ran lukstest and got "BAD 2 1048576 338e26f322194e1a56f2cb68c640f0b2fe403936 6c63ea074c38445b248caa00d5ecca051e020e55"
I checked both file (original and copied) and got two 512byte sector different (sectors 339 and 697).
I stopped the LUKS mount, rmmod sun4i-ss and remount it.
Now I got only one bad sector (the last one).
If I clean all and re-use sun4i-ss, still the last one.
Interesting...

Regards

PS: list of commands done
./luks/lukstest

DEBUG: Generate image
DEBUG: Format
Command successful.
DEBUG: open
Key slot 0 unlocked.
Command successful.
/dev/mapper/ctest is active.
type: LUKS1
cipher: aes-cbc-plain
keysize: 256 bits
device: /dev/loop0
loop: /tmp/bench.img
offset: 4096 sectors
size: 315904 sectors
mode: read/write
DEBUG: mkfs

mke2fs 1.42.13 (17-May-2015)
END 1 / 10
BAD 2 1048576 338e26f322194e1a56f2cb68c640f0b2fe403936 6c63ea074c38445b248caa00d5ecca051e020e55

bindiff /dev/shm/test_1048576 /mnt/lukstest/test_1048576
Compare /dev/shm/test_1048576 and /mnt/lukstest/test_1048576
339 diff at 400 89 68
339 diff at 401 0e ef
[snip]
339 diff at 507 68 ad
339 diff at 508 03 59
339 diff at 509 35 eb
339 diff at 510 36 a6
339 diff at 511 ea ec
697 diff at 400 a1 d9
697 diff at 401 c9 44
697 diff at 402 0a ef
697 diff at 403 d7 95
[snip]
697 diff at 508 2b 07
697 diff at 509 e1 ee
697 diff at 510 57 1c
697 diff at 511 e6 f0

umount /mnt/lukstest
cryptsetup luksClose ctest
rmmod sun4i-ss
cryptsetup luksOpen /tmp/bench.img ctest --key-file=/tmp/bench.img.key
mount /dev/mapper/ctest /mnt/lukstest
bindiff /dev/shm/test_1048576 /mnt/lukstest/test_1048576
Compare /dev/shm/test_1048576 and /mnt/lukstest/test_1048576
697 diff at 400 a1 d9
697 diff at 401 c9 44
697 diff at 402 0a ef
697 diff at 403 d7 95
[snip]
697 diff at 508 2b 07
697 diff at 509 e1 ee
697 diff at 510 57 1c
697 diff at 511 e6 f0

[Michal Suchanek]

Hello,

On 14 March 2016 at 07:58, Corentin LABBE <clabbe....@gmail.com> wrote:
> Le 13/03/2016 23:35, Timo S. a écrit :
>> Hi Corentin,
>>
>> Am 13.03.2016 17:32 schrieb "Corentin LABBE" <clabbe....@gmail.com <mailto:clabbe....@gmail.com>>:
>>>
>>> Le 13/03/2016 16:21, txsa...@gmail.com <mailto:txsa...@gmail.com> a écrit :
>>> > http://irclog.whitequark.org/linux-sunxi/2016-03-11
>>> >
>>> > Chat from timestamp 18:25
>>> >
>>>
>>> Hello
>>>
>>> And I have just sent an email asking for help https://lkml.org/lkml/2016/3/13/64.
>>>

Since you can reproduce the issue it might be worth trying to mod
sun4i-ss to also process the same data with software crypto in
parallel and log any differences the moment they appear together with
some data like the input to the crypto device and the number of
encrypted/decrypted/total processed blocks so far.

Thanks

Michal

[txsa...@gmail.com]

Can't be this workaround that eliminates the problem is used until a real fix is possible?

[txsa...@gmail.com]

Still nothing :( it seems i can convert my encrypted storage back to XTS, as i've only converted it to CBC for the hw encryption.

[LABBE Corentin]

On Tue, Apr 19, 2016 at 08:29:23AM -0700, txsa...@gmail.com wrote:
> Still nothing :( it seems i can convert my encrypted storage back to XTS, as i've only converted it to CBC for the hw encryption.
>

I hàve sent the patch (https://lkml.org/lkml/2016/3/23/302) solving this issue, but it is not present in any tree.
Anywày, XTS is the recommended wày for disk encryption and it have nearly the same speed than CBC with hw.

Regards

[Timo S.]

Short update:

Corentin's fix (crypto: sun4i-ss - Replace spinlock_bh by
spin_lock_irq{save|restore}) finally made it into the stable/longterm
updates: Greg has just released the versions 4.4.12, 4.5.6 and 4.6.1 -
all of which contain the patch.

Regards,

Timo

> --
> You received this message because you are subscribed to a topic in the Google Groups "linux-sunxi" group.
> To unsubscribe from this topic, visit https://groups.google.com/d/topic/linux-sunxi/InsDjSm3J6A/unsubscribe.
> To unsubscribe from this group and all its topics, send an email to linux-sunxi...@googlegroups.com.
> For more options, visit https://groups.google.com/d/optout.