2022-04-27 11:43:21

by Steffen Trumtrar

[permalink] [raw]
Subject: [BUG] Layerscape CAAM+kTLS+io_uring


Hi all,

I have a Layerscape-1046a based board where I'm trying to use a
combination of liburing (v2.0) with splice, kTLS and CAAM (kernel
v5.17). The problem I see is that on shutdown the last bytes are
missing. It looks like io_uring is not waiting for all completions
from the CAAM driver.

With ARM-ASM instead of the CAAM, the setup works fine.

I tried to debug with ftrace and see where it goes wrong. Here is what
seems to be (at least to me) some of the last bytes:

webserver-612 [002] ..... 135.300350: io_uring_file_get: ring 0000000078f4a859, fd 6 00078f4a859, fd 7
webserver-612 [002] ..... 135.300352: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000fbb9b849, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300353: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000ff858bdf, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300353: io_uring_link: ring 0000000078f4a859, request 00000000ff858bdf linked after 00000000fbb9b849
webserver-612 [002] ..... 135.300354: io_uring_queue_async_work: ring 0000000078f4a859, request 00000000fbb9b849, flags 798724, normal queue, work 0000000060cd323f
webserver-612 [002] ..... 135.300358: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
iou-wrk-612-647 [003] ...1. 135.300375: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4352, cflags 0
iou-wrk-612-647 [003] d..2. 135.300379: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
webserver-612 [002] ..... 135.300388: io_uring_file_get: ring 0000000078f4a859, fd 6
webserver-612 [002] ..... 135.300389: io_uring_file_get: ring 0000000078f4a859, fd 7 0000078f4a859, req 000000008c2bf2be, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300390: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000fe4e50d1, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300391: io_uring_link: ring 0000000078f4a859, request 00000000fe4e50d1 linked after 000000008c2bf2be
webserver-612 [002] ..... 135.300392: io_uring_queue_async_work: ring 0000000078f4a859, request 000000008c2bf2be, flags 798724, normal queue, work 00000000f2b434fc
webserver-612 [002] ..... 135.300396: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
iou-wrk-612-647 [003] ...1. 135.300410: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4352, cflags 0
iou-wrk-612-647 [003] d..2. 135.300414: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
webserver-612 [002] ..... 135.300423: io_uring_file_get: ring 0000000078f4a859, fd 6
webserver-612 [002] ..... 135.300424: io_uring_file_get: ring 0000000078f4a859, fd 7
webserver-612 [002] ..... 135.300424: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000e48f3098, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300426: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000ec67d53c, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300426: io_uring_link: ring 0000000078f4a859, request 00000000ec67d53c linked after 00000000e48f3098
webserver-612 [002] ..... 135.300427: io_uring_queue_async_work: ring 0000000078f4a859, request 00000000e48f3098, flags 798724, normal queue, work 000000009e3701da
webserver-612 [002] ..... 135.300431: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
iou-wrk-612-647 [003] ...1. 135.300447: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4352, cflags 0
iou-wrk-612-647 [003] d..2. 135.300452: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
webserver-612 [002] ..... 135.300461: io_uring_file_get: ring 0000000078f4a859, fd 6
webserver-612 [002] ..... 135.300462: io_uring_file_get: ring 0000000078f4a859, fd 7
webserver-612 [002] ..... 135.300462: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000f658f96f, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0, sq_thread 0
webserver-612 [002] ..... 135.300464: io_uring_link: ring 0000000078f4a859, request 000000006c29e721 linked after 00000000f658f96f
webserver-612 [002] ..... 135.300465: io_uring_queue_async_work: ring 0000000078f4a859, request 00000000f658f96f, flags 798724, normal queue, work 000000007434c68b
webserver-612 [002] ..... 135.300469: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
iou-wrk-612-647 [003] ...1. 135.300479: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4608, cflags 0
iou-wrk-612-647 [003] d..2. 135.300483: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
webserver-612 [002] ..... 135.300492: io_uring_file_get: ring 0000000078f4a859, fd 6
webserver-612 [002] ..... 135.300493: io_uring_file_get: ring 0000000078f4a859, fd 7
webserver-612 [002] ..... 135.300494: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000757ef148, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300495: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000e5c82137, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0 8f4a859, request 00000000e5c82137 linked after 00000000757ef148
webserver-612 [002] ..... 135.300496: io_uring_queue_async_work: ring 0000000078f4a859, request 00000000757ef148, flags 798724, normal queue, work 00000000b55630dd
webserver-612 [002] ..... 135.300500: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
iou-wrk-612-647 [003] ...1. 135.300516: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4608, cflags 0
iou-wrk-612-647 [003] d..2. 135.300520: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
webserver-612 [002] ..... 135.300529: io_uring_file_get: ring 0000000078f4a859, fd 6
webserver-612 [002] ..... 135.300530: io_uring_file_get: ring 0000000078f4a859, fd 7
webserver-612 [002] ..... 135.300531: io_uring_submit_sqe: ring 0000000078f4a859, req 0000000085e5cac4, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300532: io_uring_submit_sqe: ring 0000000078f4a859, req 0000000008e6a863, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300532: io_uring_link: ring 0000000078f4a859, request 0000000008e6a863 linked after 0000000085e5cac4 ng 0000000078f4a859, request 0000000085e5cac4, flags 798724, normal queue, work 0000000036c4ff52
webserver-612 [002] ..... 135.300537: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
iou-wrk-612-647 [003] ...1. 135.300553: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4608, cflags 0
iou-wrk-612-647 [003] d..2. 135.300557: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
webserver-612 [002] ..... 135.300566: io_uring_file_get: ring 0000000078f4a859, fd 6
webserver-612 [002] ..... 135.300567: io_uring_file_get: ring 0000000078f4a859, fd 7
webserver-612 [002] ..... 135.300567: io_uring_submit_sqe: ring 0000000078f4a859, req 000000000f7fdd39, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300568: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000741c64e1, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300569: io_uring_link: ring 0000000078f4a859, request 00000000741c64e1 linked after 000000000f7fdd39
webserver-612 [002] ..... 135.300570: io_uring_queue_async_work: ring 0000000078f4a859, request 000000000f7fdd39, flags 798724, normal queue, work 00000000fc4accf1
webserver-612 [002] ..... 135.300574: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
iou-wrk-612-647 [003] ...1. 135.300594: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4352, cflags 0
iou-wrk-612-647 [003] d..2. 135.300598: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
webserver-612 [002] ..... 135.300607: io_uring_file_get: ring 0000000078f4a859, fd 6
webserver-612 [002] ..... 135.300608: io_uring_file_get: ring 0000000078f4a859, fd 7
webserver-612 [002] ..... 135.300608: io_uring_submit_sqe: ring 0000000078f4a859, req 0000000052b47765, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300610: io_uring_submit_sqe: ring 0000000078f4a859, req 000000003904ded9, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
webserver-612 [002] ..... 135.300611: io_uring_link: ring 0000000078f4a859, request 000000003904ded9 linked after 0000000052b47765
webserver-612 [002] ..... 135.300612: io_uring_queue_async_work: ring 0000000078f4a859, request 0000000052b47765, flags 798724, normal queue, work 00000000e11c8599
webserver-612 [002] ..... 135.300615: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
iou-wrk-612-647 [003] ...1. 135.300631: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 768, cflags 0
iou-wrk-612-647 [003] d..2. 135.300634: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
webserver-612 [002] ..... 135.301668: io_uring_file_get: ring 0000000078f4a859, fd 6
webserver-612 [002] ..... 135.301669: io_uring_submit_sqe: ring 0000000078f4a859, req 0000000012863980, op 34, data 0x0, flags 8, non block 1, sq_thread 0
webserver-612 [002] ..... 135.301670: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000f4b07ff9, op 19, data 0x0, flags 0, non block 1, sq_thread 0
webserver-612 [002] ..... 135.301671: io_uring_link: ring 0000000078f4a859, request 00000000f4b07ff9 linked after 0000000012863980
webserver-612 [002] ..... 135.301672: io_uring_queue_async_work: ring 0000000078f4a859, request 0000000012863980, flags 262152, normal queue, work 00000000102270ed
webserver-612 [002] ..... 135.301740: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
iou-wrk-612-648 [000] ...1. 135.301757: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result 0, cflags 0
iou-wrk-612-648 [000] ...1. 135.301767: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result 0, cflags 0
webserver-612 [002] ..... 135.301769: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1


Userspace said that 768 bytes where missing.

Any ideas for how to debug this or why the async work queue doesn't work with
the CAMM but does with ARM-ASM?
If I can provide more info that might help, I'll try to produce and
provide it. As there are multiple components involved, I'm not sure
where to start or what information is useful. Currently looks like CAAM
is the culprit.


Thanks,
Steffen Trumtrar

--
Pengutronix e.K. | Dipl.-Inform. Steffen Trumtrar |
Steuerwalder Str. 21 | https://www.pengutronix.de/ |
31137 Hildesheim, Germany | Phone: +49-5121-206917-0 |
Amtsgericht Hildesheim, HRA 2686| Fax: +49-5121-206917-5555 |


2022-05-06 07:14:05

by Marc Kleine-Budde

[permalink] [raw]
Subject: Re: [BUG] Layerscape CAAM+kTLS+io_uring

Hello,

no one seems to care about this problem. :/

Maybe too many components are involved, I'm the respective maintainers
on Cc.

Cc += the CAAM maintainers
Cc += the io_uring maintainers
Cc += the kTLS maintainers

On 27.04.2022 10:20:40, Steffen Trumtrar wrote:
> Hi all,
>
> I have a Layerscape-1046a based board where I'm trying to use a
> combination of liburing (v2.0) with splice, kTLS and CAAM (kernel
> v5.17). The problem I see is that on shutdown the last bytes are
> missing. It looks like io_uring is not waiting for all completions
> from the CAAM driver.
>
> With ARM-ASM instead of the CAAM, the setup works fine.

What's the difference between the CAAM and ARM-ASM crypto? Without
looking into the code I think the CAAM is asynchron while ARM-ASM is
synchron. Is this worth investigating?

> I tried to debug with ftrace and see where it goes wrong. Here is what
> seems to be (at least to me) some of the last bytes:
>
> webserver-612 [002] ..... 135.300350: io_uring_file_get: ring 0000000078f4a859, fd 6 00078f4a859, fd 7
> webserver-612 [002] ..... 135.300352: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000fbb9b849, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300353: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000ff858bdf, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300353: io_uring_link: ring 0000000078f4a859, request 00000000ff858bdf linked after 00000000fbb9b849
> webserver-612 [002] ..... 135.300354: io_uring_queue_async_work: ring 0000000078f4a859, request 00000000fbb9b849, flags 798724, normal queue, work 0000000060cd323f
> webserver-612 [002] ..... 135.300358: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
> iou-wrk-612-647 [003] ...1. 135.300375: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4352, cflags 0
> iou-wrk-612-647 [003] d..2. 135.300379: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
> webserver-612 [002] ..... 135.300388: io_uring_file_get: ring 0000000078f4a859, fd 6
> webserver-612 [002] ..... 135.300389: io_uring_file_get: ring 0000000078f4a859, fd 7 0000078f4a859, req 000000008c2bf2be, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300390: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000fe4e50d1, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300391: io_uring_link: ring 0000000078f4a859, request 00000000fe4e50d1 linked after 000000008c2bf2be
> webserver-612 [002] ..... 135.300392: io_uring_queue_async_work: ring 0000000078f4a859, request 000000008c2bf2be, flags 798724, normal queue, work 00000000f2b434fc
> webserver-612 [002] ..... 135.300396: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
> iou-wrk-612-647 [003] ...1. 135.300410: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4352, cflags 0
> iou-wrk-612-647 [003] d..2. 135.300414: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
> webserver-612 [002] ..... 135.300423: io_uring_file_get: ring 0000000078f4a859, fd 6
> webserver-612 [002] ..... 135.300424: io_uring_file_get: ring 0000000078f4a859, fd 7
> webserver-612 [002] ..... 135.300424: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000e48f3098, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300426: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000ec67d53c, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300426: io_uring_link: ring 0000000078f4a859, request 00000000ec67d53c linked after 00000000e48f3098
> webserver-612 [002] ..... 135.300427: io_uring_queue_async_work: ring 0000000078f4a859, request 00000000e48f3098, flags 798724, normal queue, work 000000009e3701da
> webserver-612 [002] ..... 135.300431: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
> iou-wrk-612-647 [003] ...1. 135.300447: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4352, cflags 0
> iou-wrk-612-647 [003] d..2. 135.300452: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
> webserver-612 [002] ..... 135.300461: io_uring_file_get: ring 0000000078f4a859, fd 6
> webserver-612 [002] ..... 135.300462: io_uring_file_get: ring 0000000078f4a859, fd 7
> webserver-612 [002] ..... 135.300462: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000f658f96f, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0, sq_thread 0
> webserver-612 [002] ..... 135.300464: io_uring_link: ring 0000000078f4a859, request 000000006c29e721 linked after 00000000f658f96f
> webserver-612 [002] ..... 135.300465: io_uring_queue_async_work: ring 0000000078f4a859, request 00000000f658f96f, flags 798724, normal queue, work 000000007434c68b
> webserver-612 [002] ..... 135.300469: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
> iou-wrk-612-647 [003] ...1. 135.300479: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4608, cflags 0
> iou-wrk-612-647 [003] d..2. 135.300483: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
> webserver-612 [002] ..... 135.300492: io_uring_file_get: ring 0000000078f4a859, fd 6
> webserver-612 [002] ..... 135.300493: io_uring_file_get: ring 0000000078f4a859, fd 7
> webserver-612 [002] ..... 135.300494: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000757ef148, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300495: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000e5c82137, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0 8f4a859, request 00000000e5c82137 linked after 00000000757ef148
> webserver-612 [002] ..... 135.300496: io_uring_queue_async_work: ring 0000000078f4a859, request 00000000757ef148, flags 798724, normal queue, work 00000000b55630dd
> webserver-612 [002] ..... 135.300500: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
> iou-wrk-612-647 [003] ...1. 135.300516: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4608, cflags 0
> iou-wrk-612-647 [003] d..2. 135.300520: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
> webserver-612 [002] ..... 135.300529: io_uring_file_get: ring 0000000078f4a859, fd 6
> webserver-612 [002] ..... 135.300530: io_uring_file_get: ring 0000000078f4a859, fd 7
> webserver-612 [002] ..... 135.300531: io_uring_submit_sqe: ring 0000000078f4a859, req 0000000085e5cac4, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300532: io_uring_submit_sqe: ring 0000000078f4a859, req 0000000008e6a863, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300532: io_uring_link: ring 0000000078f4a859, request 0000000008e6a863 linked after 0000000085e5cac4 ng 0000000078f4a859, request 0000000085e5cac4, flags 798724, normal queue, work 0000000036c4ff52
> webserver-612 [002] ..... 135.300537: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
> iou-wrk-612-647 [003] ...1. 135.300553: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4608, cflags 0
> iou-wrk-612-647 [003] d..2. 135.300557: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
> webserver-612 [002] ..... 135.300566: io_uring_file_get: ring 0000000078f4a859, fd 6
> webserver-612 [002] ..... 135.300567: io_uring_file_get: ring 0000000078f4a859, fd 7
> webserver-612 [002] ..... 135.300567: io_uring_submit_sqe: ring 0000000078f4a859, req 000000000f7fdd39, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300568: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000741c64e1, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300569: io_uring_link: ring 0000000078f4a859, request 00000000741c64e1 linked after 000000000f7fdd39
> webserver-612 [002] ..... 135.300570: io_uring_queue_async_work: ring 0000000078f4a859, request 000000000f7fdd39, flags 798724, normal queue, work 00000000fc4accf1
> webserver-612 [002] ..... 135.300574: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
> iou-wrk-612-647 [003] ...1. 135.300594: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 4352, cflags 0
> iou-wrk-612-647 [003] d..2. 135.300598: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
> webserver-612 [002] ..... 135.300607: io_uring_file_get: ring 0000000078f4a859, fd 6
> webserver-612 [002] ..... 135.300608: io_uring_file_get: ring 0000000078f4a859, fd 7
> webserver-612 [002] ..... 135.300608: io_uring_submit_sqe: ring 0000000078f4a859, req 0000000052b47765, op 30, data 0xf3e096f0, flags 8196, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300610: io_uring_submit_sqe: ring 0000000078f4a859, req 000000003904ded9, op 15, data 0x0, flags 2097152, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.300611: io_uring_link: ring 0000000078f4a859, request 000000003904ded9 linked after 0000000052b47765
> webserver-612 [002] ..... 135.300612: io_uring_queue_async_work: ring 0000000078f4a859, request 0000000052b47765, flags 798724, normal queue, work 00000000e11c8599
> webserver-612 [002] ..... 135.300615: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
> iou-wrk-612-647 [003] ...1. 135.300631: io_uring_complete: ring 0000000078f4a859, user_data 0xf3e096f0, result 768, cflags 0
> iou-wrk-612-647 [003] d..2. 135.300634: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result -125, cflags 0
> webserver-612 [002] ..... 135.301668: io_uring_file_get: ring 0000000078f4a859, fd 6
> webserver-612 [002] ..... 135.301669: io_uring_submit_sqe: ring 0000000078f4a859, req 0000000012863980, op 34, data 0x0, flags 8, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.301670: io_uring_submit_sqe: ring 0000000078f4a859, req 00000000f4b07ff9, op 19, data 0x0, flags 0, non block 1, sq_thread 0
> webserver-612 [002] ..... 135.301671: io_uring_link: ring 0000000078f4a859, request 00000000f4b07ff9 linked after 0000000012863980
> webserver-612 [002] ..... 135.301672: io_uring_queue_async_work: ring 0000000078f4a859, request 0000000012863980, flags 262152, normal queue, work 00000000102270ed
> webserver-612 [002] ..... 135.301740: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
> iou-wrk-612-648 [000] ...1. 135.301757: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result 0, cflags 0
> iou-wrk-612-648 [000] ...1. 135.301767: io_uring_complete: ring 0000000078f4a859, user_data 0x0, result 0, cflags 0
> webserver-612 [002] ..... 135.301769: io_uring_cqring_wait: ring 0000000078f4a859, min_events 1
>
>
> Userspace said that 768 bytes where missing.
>
> Any ideas for how to debug this or why the async work queue doesn't work with
> the CAMM but does with ARM-ASM?
> If I can provide more info that might help, I'll try to produce and
> provide it. As there are multiple components involved, I'm not sure
> where to start or what information is useful. Currently looks like CAAM
> is the culprit.

Can you provide test code or at least illustrate with code how you plug
the components together?

Marc

--
Pengutronix e.K. | Marc Kleine-Budde |
Embedded Linux | https://www.pengutronix.de |
Vertretung West/Dortmund | Phone: +49-231-2826-924 |
Amtsgericht Hildesheim, HRA 2686 | Fax: +49-5121-206917-5555 |


Attachments:
(No filename) (12.39 kB)
signature.asc (499.00 B)
Download all attachments

2022-05-06 18:17:10

by Jakub Kicinski

[permalink] [raw]
Subject: Re: [BUG] Layerscape CAAM+kTLS+io_uring

On Thu, 5 May 2022 21:20:46 +0200 Marc Kleine-Budde wrote:
> Hello,
>
> no one seems to care about this problem. :/
>
> Maybe too many components are involved, I'm the respective maintainers
> on Cc.
>
> Cc += the CAAM maintainers
> Cc += the io_uring maintainers
> Cc += the kTLS maintainers
>
> On 27.04.2022 10:20:40, Steffen Trumtrar wrote:
> > Hi all,
> >
> > I have a Layerscape-1046a based board where I'm trying to use a
> > combination of liburing (v2.0) with splice, kTLS and CAAM (kernel
> > v5.17). The problem I see is that on shutdown the last bytes are
> > missing. It looks like io_uring is not waiting for all completions
> > from the CAAM driver.
> >
> > With ARM-ASM instead of the CAAM, the setup works fine.
>
> What's the difference between the CAAM and ARM-ASM crypto? Without
> looking into the code I think the CAAM is asynchron while ARM-ASM is
> synchron. Is this worth investigating?

Sounds like
20ffc7adf53a ("net/tls: missing received data after fast remote close")

2022-05-16 16:08:37

by Steffen Trumtrar

[permalink] [raw]
Subject: Re: [BUG] Layerscape CAAM+kTLS+io_uring


Jakub Kicinski <[email protected]> writes:

> On Thu, 5 May 2022 21:20:46 +0200 Marc Kleine-Budde wrote:
>> Hello,
>>
>> no one seems to care about this problem. :/
>>
>> Maybe too many components are involved, I'm the respective maintainers
>> on Cc.
>>
>> Cc += the CAAM maintainers
>> Cc += the io_uring maintainers
>> Cc += the kTLS maintainers
>>
>> On 27.04.2022 10:20:40, Steffen Trumtrar wrote:
>> > Hi all,
>> >
>> > I have a Layerscape-1046a based board where I'm trying to use a
>> > combination of liburing (v2.0) with splice, kTLS and CAAM (kernel
>> > v5.17). The problem I see is that on shutdown the last bytes are
>> > missing. It looks like io_uring is not waiting for all completions
>> > from the CAAM driver.
>> >
>> > With ARM-ASM instead of the CAAM, the setup works fine.
>>
>> What's the difference between the CAAM and ARM-ASM crypto? Without
>> looking into the code I think the CAAM is asynchron while ARM-ASM is
>> synchron. Is this worth investigating?
>
> Sounds like
> 20ffc7adf53a ("net/tls: missing received data after fast remote close")

That fixes something in tls_sw. I have a kernel that includes this
patch. So this sounds right, but can't be it, right?


Best regards,
Steffen

--
Pengutronix e.K. | Dipl.-Inform. Steffen Trumtrar |
Steuerwalder Str. 21 | https://www.pengutronix.de/ |
31137 Hildesheim, Germany | Phone: +49-5121-206917-0 |
Amtsgericht Hildesheim, HRA 2686| Fax: +49-5121-206917-5555 |

2022-05-17 07:49:08

by Gaurav Jain

[permalink] [raw]
Subject: RE: [EXT] Re: [BUG] Layerscape CAAM+kTLS+io_uring

Hello Steffen

> -----Original Message-----
> From: Steffen Trumtrar <[email protected]>
> Sent: Monday, May 16, 2022 3:36 PM
> To: Jakub Kicinski <[email protected]>
> Cc: Marc Kleine-Budde <[email protected]>; [email protected];
> [email protected]; [email protected]; Horia Geanta
> <[email protected]>; Pankaj Gupta <[email protected]>; Gaurav Jain
> <[email protected]>; Jens Axboe <[email protected]>; Pavel Begunkov
> <[email protected]>; Boris Pismenny <[email protected]>; John
> Fastabend <[email protected]>; Daniel Borkmann
> <[email protected]>; [email protected]
> Subject: [EXT] Re: [BUG] Layerscape CAAM+kTLS+io_uring
>
> Caution: EXT Email
>
> Jakub Kicinski <[email protected]> writes:
>
> > On Thu, 5 May 2022 21:20:46 +0200 Marc Kleine-Budde wrote:
> >> Hello,
> >>
> >> no one seems to care about this problem. :/
> >>
> >> Maybe too many components are involved, I'm the respective
> >> maintainers on Cc.
> >>
> >> Cc += the CAAM maintainers
> >> Cc += the io_uring maintainers
> >> Cc += the kTLS maintainers
> >>
> >> On 27.04.2022 10:20:40, Steffen Trumtrar wrote:
> >> > Hi all,
> >> >
> >> > I have a Layerscape-1046a based board where I'm trying to use a
> >> > combination of liburing (v2.0) with splice, kTLS and CAAM (kernel
> >> > v5.17). The problem I see is that on shutdown the last bytes are
> >> > missing. It looks like io_uring is not waiting for all completions
> >> > from the CAAM driver.
> >> >
> >> > With ARM-ASM instead of the CAAM, the setup works fine.
> >>
> >> What's the difference between the CAAM and ARM-ASM crypto? Without
> >> looking into the code I think the CAAM is asynchron while ARM-ASM is
> >> synchron. Is this worth investigating?
> >
> > Sounds like
> > 20ffc7adf53a ("net/tls: missing received data after fast remote
> > close")
>
> That fixes something in tls_sw. I have a kernel that includes this patch. So this
> sounds right, but can't be it, right?
>
To understand more on problem, can you share how you are offloading ktls to CAAM?

Gaurav
>
> Best regards,
> Steffen
>
> --
> Pengutronix e.K. | Dipl.-Inform. Steffen Trumtrar |
> Steuerwalder Str. 21 |
> https://eur01.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwww.pe
> ngutronix.de%2F&amp;data=05%7C01%7Cgaurav.jain%40nxp.com%7Cc225fa4
> 3da7f4a43f16b08da3723dc4a%7C686ea1d3bc2b4c6fa92cd99c5c301635%7C0%
> 7C0%7C637882924400875890%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wL
> jAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C3000%7C%7C
> %7C&amp;sdata=fI1BHNZIT5RlpjEdEMXVkv1WaHcvgTlZOcaC0LRojac%3D&amp;
> reserved=0 |
> 31137 Hildesheim, Germany | Phone: +49-5121-206917-0 |
> Amtsgericht Hildesheim, HRA 2686| Fax: +49-5121-206917-5555 |