iMX8MM CAAM errors when using 'tk(cbc(aes))' for filesystem encryption

[djs2]

I'm getting the following error when writing to a filesystem using the CAAM for filesystem encryption with `tk(cbc(aes))`.

caam_jr 30902000.jr: 4000141c: DECO: desc idx 20: DECO Watchdog timer timeout error

This only happens occasionally but seems to be more prevalent when running with all cores enabled.

[djs2]

Unfortunately, I've been unable to reproduce with other tools

I have added logging of last 2048 CAAM log messages on failure and we are now waiting for failure to re-occur in CI.  I'll send logs as soon as I get them

[Harvey021]

Can you please share the version of BSP you're working and the Steps and logs when problems occur?

Regards

Harvey

[djs2]

Sorry for the delay in replying.

We are using `linux-imx_5.15.71_2.2.2-phy5` from Phytec with patches from https://github.com/Freescale/linux-fslc/tree/5.15-2.2.x-imx up until 5.15.183.  Unfortunately the problem only occurs occasionally (less than 1 instance every 500 hours or so of CI testing across multiple units) and I haven't been able to create a simple reproducer.

An initial attempt to enable `CONFIG_CRYPTO_DEV_FSL_CAAM_DEBUG` prevents our device from booting as we are using the CAAM to encrypt the root filesystem along with various data partitions and this generates too much logging.

I'm looking at adding log information to a circular buffer and emitting this when the error occurs.  As this will only result in the last 1000 or so records being emitted, I'd like to know whether there are any setup messages that we should always log to support analysis.

Thanks

Daniel

[Harvey021]

Watchdog timeout error was triggered by DECO halt on but there were multi case to make DECO halt on, such as input/output buffer address, length or etc.
Can you reproduce this with stress test with "dd" or "fio" tool?

If the issue can be reproduced stably, it can help us to find the root cause.

Regards

Harvey

[djs2]

Finally had it fail with logging.  This should include the last 2048 log records from the CAAM subsystem.  Only difference to standard logging is that `src` and `dst` buffer data is not included.

[AldoG]

Hello,

were you able to reproduce using dd or fio as harvey recommended?
In your last test how easy is to reproduce?

Best regards/Saludos,
Aldo.

[djs2]

No, I haven't been able to reproduce with dd or fio.  On the system I captured the previous log from, it only happens very occasionally (once in 2 months so far). 

On another system it with slightly different code, it happens at least once a day.  We believe this is when loading a large set of shared libraries during startup (which aren't used on the system I got logs from).  Unfortunately, we are not able to easily collect logs from this version - however we would be able to test a patch relatively quickly to see if the issue is resolved.

Do the previous logs contain enough information for investigation purposes?  If not then what else would be required?

[djs2]

From a brief look at my log, it appears that at the point of failure, the 8th of 8 queued requests for a sequence of offsets is what generates the DECO watchdog timeout error.  In the earlier portions of the log, it appears that there are rarely any queued requests (possibly sometimes one?) even when handling other sequences of offsets.  Is this a clue?

The 7 queued requests before this do seem to complete correctly so could one of the following the cause...

1. The queue actually only supports 7 entries - in which case reducing the number of queued entries may help (where can I change this?)
2. The DECO watchdog timeout starts when entries are added to the queue and simply expires due to the time taken to handle 8 entries - in which case extending the timeout period may help (again, if possible, where can I change this?)
3. This specific request actually has a problem - but to me it looks equivalent to the 7 previous requests so this seems unlikely

Thanks

Daniel

[djs2]

Note we are running the CPU and DDR at reduced speed for power saving reasons - which may impact this

[djs2]

Having got the logs, I decided to dig in further myself.  It appears that when the system is under high memory load but still has the DDR running at 400MT/s (or in our case sometimes 100MT/s), the CAAM will sometimes generate a watchdog error.

The eMMC driver forces the DDR to 3000MT/s, but for writes, this doesn't necessarily occur until after the encryption has been performed.

We have fixed this for our use case by requesting `BUS_FREQ_HIGH` in `caam_jr_enqueue()` and releasing it again via scheduled work from `caam_jr_dequeue()`.

This fixes filesystem accesses, however it causes problems when called from the network stack (via xfrm for example) as `request_bus_freq()` ends up being called in atomic context (from much further up the network stack) and both `request_bus_freq()` and `clk_xxx()` calls utilise mutex's

We have worked around this by disabling use of CAAM for everything but the filesystem, but a better solution would be required if upstreamed.