CPU Stuck Error When Using Xbufs

CPU Stuck Error When Using Xbufs

[Russell Johnson]

[-- Attachment #1: Type: text/plain, Size: 1896 bytes --]

Hello,

I am running into a CPU Stuck issue when I added another xbuf to our
application where we have data being transported from EVL  to Linux
constantly. 

I get a message on the console that mentions there is a CPU that is stuck
due to spinlock recursion:
"
Message from syslogd@Modem1 at Aug 18 23:02:25 ...
kernel:BUG: spinlock cpu recursion on CPU#5, SINK_0_DATA/4437
Message from syslogd@Modem1 at Aug 18 23:02:25 ...
kernel: lock: 0xffff8f27d329f610, .magic: dead4ead, .owner:
SINK_0_XBUF_L/4402, .owner_cpu: 5
"

I collected some data using sysrq and got the following stacks for both of
the threads in question:
"
task:SINK_0_DATA     state:S stack:    0 pid:15095 ppid: 14415
flags:0x00000000
Call Trace:
<TASK>
? wait_events.isra.15+0xae/0x3e0
? evl_lock_mutex_timeout+0x45/0x540
? evl_flush_wait+0x50/0x50
? monitor_oob_ioctl+0x487/0xbd0
? poll_oob_ioctl+0xc7/0x440
? EVL_ioctl+0x46/0xa0
? do_oob_syscall+0x251/0x260
? handle_oob_syscall+0xa4/0xf0
? pipeline_syscall+0x65/0x130
? syscall_enter_from_user_mode+0x4d/0x120
? do_syscall_64+0x1d/0xa0
? entry_SYSCALL_64_after_hwframe+0x67/0xd1
</TASK>

task:SINK_0_XBUF_L   state:R  running task     stack:    0 pid:15059 ppid:
14333 flags:0x00000008
Call Trace:
<TASK>
dovetail_context_switch+0xaf/0x200
__evl_schedule+0x266/0x560
run_oob_call+0x99/0x170
inbound_signal_output+0xab/0xb0
do_xbuf_read+0x1b3/0x240
xbuf_read+0x4d/0x70
? do_irq_work+0x70/0x70
vfs_read+0x9b/0x1a0
ksys_read+0xc4/0xe0
__x64_sys_read+0x15/0x20
do_syscall_64+0x4c/0xa0
entry_SYSCALL_64_after_hwframe+0x67/0xd1
"

NOTE: SINK_0_DATA is the thread in the EVL app that is pushing data onto the
xbuf. SINK_0_XBUF_L is the thread in the Linux app that is pulling data off
of the xbuf.

Do you have any idea would could be going on? Is there any additional data
you would like me to collect that would be helpful to understand
what is happening?


Thanks,

Russell



[-- Attachment #2: smime.p7s --]
[-- Type: application/pkcs7-signature, Size: 6739 bytes --]

Re: CPU Stuck Error When Using Xbufs

[Philippe Gerum]

Russell Johnson <russell.johnson@kratosdefense.com> writes:

> [[S/MIME Signed Part:Undecided]]
> Hello,
>
> I am running into a CPU Stuck issue when I added another xbuf to our
> application where we have data being transported from EVL  to Linux
> constantly. 
>
> I get a message on the console that mentions there is a CPU that is stuck
> due to spinlock recursion:
> "
> Message from syslogd@Modem1 at Aug 18 23:02:25 ...
> kernel:BUG: spinlock cpu recursion on CPU#5, SINK_0_DATA/4437
> Message from syslogd@Modem1 at Aug 18 23:02:25 ...
> kernel: lock: 0xffff8f27d329f610, .magic: dead4ead, .owner:
> SINK_0_XBUF_L/4402, .owner_cpu: 5
> "
>
> I collected some data using sysrq and got the following stacks for both of
> the threads in question:
> "
> task:SINK_0_DATA     state:S stack:    0 pid:15095 ppid: 14415
> flags:0x00000000
> Call Trace:
> <TASK>
> ? wait_events.isra.15+0xae/0x3e0
> ? evl_lock_mutex_timeout+0x45/0x540
> ? evl_flush_wait+0x50/0x50
> ? monitor_oob_ioctl+0x487/0xbd0
> ? poll_oob_ioctl+0xc7/0x440
> ? EVL_ioctl+0x46/0xa0
> ? do_oob_syscall+0x251/0x260
> ? handle_oob_syscall+0xa4/0xf0
> ? pipeline_syscall+0x65/0x130
> ? syscall_enter_from_user_mode+0x4d/0x120
> ? do_syscall_64+0x1d/0xa0
> ? entry_SYSCALL_64_after_hwframe+0x67/0xd1
> </TASK>
>
> task:SINK_0_XBUF_L   state:R  running task     stack:    0 pid:15059 ppid:
> 14333 flags:0x00000008
> Call Trace:
> <TASK>
> dovetail_context_switch+0xaf/0x200
> __evl_schedule+0x266/0x560
> run_oob_call+0x99/0x170
> inbound_signal_output+0xab/0xb0
> do_xbuf_read+0x1b3/0x240
> xbuf_read+0x4d/0x70
> ? do_irq_work+0x70/0x70
> vfs_read+0x9b/0x1a0
> ksys_read+0xc4/0xe0
> __x64_sys_read+0x15/0x20
> do_syscall_64+0x4c/0xa0
> entry_SYSCALL_64_after_hwframe+0x67/0xd1
> "
>
> NOTE: SINK_0_DATA is the thread in the EVL app that is pushing data onto the
> xbuf. SINK_0_XBUF_L is the thread in the Linux app that is pulling data off
> of the xbuf.
>
> Do you have any idea would could be going on?

Yes, quite clearly now. I'll follow up on this in the coming days.

> Is there any additional data
> you would like me to collect that would be helpful to understand
> what is happening?
>

Not ATM, thanks.

-- 
Philippe.

Re: CPU Stuck Error When Using Xbufs

[Philippe Gerum]

Philippe Gerum <rpm@xenomai.org> writes:

> Russell Johnson <russell.johnson@kratosdefense.com> writes:
>
>> [[S/MIME Signed Part:Undecided]]
>> Hello,
>>
>> I am running into a CPU Stuck issue when I added another xbuf to our
>> application where we have data being transported from EVL  to Linux
>> constantly. 
>>
>> I get a message on the console that mentions there is a CPU that is stuck
>> due to spinlock recursion:
>> "
>> Message from syslogd@Modem1 at Aug 18 23:02:25 ...
>> kernel:BUG: spinlock cpu recursion on CPU#5, SINK_0_DATA/4437
>> Message from syslogd@Modem1 at Aug 18 23:02:25 ...
>> kernel: lock: 0xffff8f27d329f610, .magic: dead4ead, .owner:
>> SINK_0_XBUF_L/4402, .owner_cpu: 5
>> "
>>
>> I collected some data using sysrq and got the following stacks for both of
>> the threads in question:
>> "
>> task:SINK_0_DATA     state:S stack:    0 pid:15095 ppid: 14415
>> flags:0x00000000
>> Call Trace:
>> <TASK>
>> ? wait_events.isra.15+0xae/0x3e0
>> ? evl_lock_mutex_timeout+0x45/0x540
>> ? evl_flush_wait+0x50/0x50
>> ? monitor_oob_ioctl+0x487/0xbd0
>> ? poll_oob_ioctl+0xc7/0x440
>> ? EVL_ioctl+0x46/0xa0
>> ? do_oob_syscall+0x251/0x260
>> ? handle_oob_syscall+0xa4/0xf0
>> ? pipeline_syscall+0x65/0x130
>> ? syscall_enter_from_user_mode+0x4d/0x120
>> ? do_syscall_64+0x1d/0xa0
>> ? entry_SYSCALL_64_after_hwframe+0x67/0xd1
>> </TASK>
>>
>> task:SINK_0_XBUF_L   state:R  running task     stack:    0 pid:15059 ppid:
>> 14333 flags:0x00000008
>> Call Trace:
>> <TASK>
>> dovetail_context_switch+0xaf/0x200
>> __evl_schedule+0x266/0x560
>> run_oob_call+0x99/0x170
>> inbound_signal_output+0xab/0xb0
>> do_xbuf_read+0x1b3/0x240
>> xbuf_read+0x4d/0x70
>> ? do_irq_work+0x70/0x70
>> vfs_read+0x9b/0x1a0
>> ksys_read+0xc4/0xe0
>> __x64_sys_read+0x15/0x20
>> do_syscall_64+0x4c/0xa0
>> entry_SYSCALL_64_after_hwframe+0x67/0xd1
>> "
>>
>> NOTE: SINK_0_DATA is the thread in the EVL app that is pushing data onto the
>> xbuf. SINK_0_XBUF_L is the thread in the Linux app that is pulling data off
>> of the xbuf.
>>
>> Do you have any idea would could be going on?
>
> Yes, quite clearly now. I'll follow up on this in the coming days.
>

Please give a try to this patch:
https://source.denx.de/Xenomai/xenomai4/linux-evl/-/commit/6b0dbab59eedb0b992a08be35197fccacad578d3

Thanks,

-- 
Philippe.

RE: [External] - Re: CPU Stuck Error When Using Xbufs

[Russell Johnson]

[-- Attachment #1: Type: text/plain, Size: 2993 bytes --]

Hi Philippe,

It appears that this has solved our issue. Thanks!


Russell

-----Original Message-----
From: Philippe Gerum <rpm@xenomai.org> 
Sent: Wednesday, August 23, 2023 2:26 AM
To: Russell Johnson <russell.johnson@kratosdefense.com>
Cc: xenomai@lists.linux.dev; Dave Rolenc <Dave.Rolenc@kratosdefense.com>
Subject: [External] - Re: CPU Stuck Error When Using Xbufs

CAUTION: This email originated from outside of the organization. Do not
click links or open attachments unless you recognize the sender and know the
content is safe.


Philippe Gerum <rpm@xenomai.org> writes:

> Russell Johnson <russell.johnson@kratosdefense.com> writes:
>
>> [[S/MIME Signed Part:Undecided]]
>> Hello,
>>
>> I am running into a CPU Stuck issue when I added another xbuf to our 
>> application where we have data being transported from EVL  to Linux 
>> constantly.
>>
>> I get a message on the console that mentions there is a CPU that is 
>> stuck due to spinlock recursion:
>> "
>> Message from syslogd@Modem1 at Aug 18 23:02:25 ...
>> kernel:BUG: spinlock cpu recursion on CPU#5, SINK_0_DATA/4437 Message 
>> from syslogd@Modem1 at Aug 18 23:02:25 ...
>> kernel: lock: 0xffff8f27d329f610, .magic: dead4ead, .owner:
>> SINK_0_XBUF_L/4402, .owner_cpu: 5
>> "
>>
>> I collected some data using sysrq and got the following stacks for 
>> both of the threads in question:
>> "
>> task:SINK_0_DATA     state:S stack:    0 pid:15095 ppid: 14415
>> flags:0x00000000
>> Call Trace:
>> <TASK>
>> ? wait_events.isra.15+0xae/0x3e0
>> ? evl_lock_mutex_timeout+0x45/0x540
>> ? evl_flush_wait+0x50/0x50
>> ? monitor_oob_ioctl+0x487/0xbd0
>> ? poll_oob_ioctl+0xc7/0x440
>> ? EVL_ioctl+0x46/0xa0
>> ? do_oob_syscall+0x251/0x260
>> ? handle_oob_syscall+0xa4/0xf0
>> ? pipeline_syscall+0x65/0x130
>> ? syscall_enter_from_user_mode+0x4d/0x120
>> ? do_syscall_64+0x1d/0xa0
>> ? entry_SYSCALL_64_after_hwframe+0x67/0xd1
>> </TASK>
>>
>> task:SINK_0_XBUF_L   state:R  running task     stack:    0 pid:15059
ppid:
>> 14333 flags:0x00000008
>> Call Trace:
>> <TASK>
>> dovetail_context_switch+0xaf/0x200
>> __evl_schedule+0x266/0x560
>> run_oob_call+0x99/0x170
>> inbound_signal_output+0xab/0xb0
>> do_xbuf_read+0x1b3/0x240
>> xbuf_read+0x4d/0x70
>> ? do_irq_work+0x70/0x70
>> vfs_read+0x9b/0x1a0
>> ksys_read+0xc4/0xe0
>> __x64_sys_read+0x15/0x20
>> do_syscall_64+0x4c/0xa0
>> entry_SYSCALL_64_after_hwframe+0x67/0xd1
>> "
>>
>> NOTE: SINK_0_DATA is the thread in the EVL app that is pushing data 
>> onto the xbuf. SINK_0_XBUF_L is the thread in the Linux app that is 
>> pulling data off of the xbuf.
>>
>> Do you have any idea would could be going on?
>
> Yes, quite clearly now. I'll follow up on this in the coming days.
>

Please give a try to this patch:
https://urldefense.com/v3/__https://source.denx.de/Xenomai/xenomai4/linux-ev
l/-/commit/6b0dbab59eedb0b992a08be35197fccacad578d3__;!!KM6X6ZXWXVtZMQ!aQX1I
dWU2mC0fpoFsdz9yOB0Ywl-whRYJ1j3vJ3bM_HXU4sIAzNqORFiWcC1mbs6HCAjWbqDyJsbvPYyk
ShlZA$

Thanks,

--
Philippe.

[-- Attachment #2: smime.p7s --]
[-- Type: application/pkcs7-signature, Size: 6739 bytes --]