Hi,
Thanks for the report.
I'll Cc networking people on this.
I've a strong feeling that we saw it before. The kernel is
CONFIG_PREEMPT_VOLUNTARY=y, llcp_sock_sendmsg() stuck in a error
reporting loop:
do {
...
pdu = nfc_alloc_send_skb(sock->dev, &sock->sk, MSG_DONTWAIT,
frag_len + LLCP_HEADER_SIZE, &err);
if (pdu == NULL) {
pr_err("Could not allocate PDU\n");
continue;
}
...
} while (remaining_len > 0);
[ 1004.674843] llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
[ 1004.681035] llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
...
[ 1098.508526] llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
[ 1098.514698] llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
[ 1098.520844] INFO: rcu_sched self-detected stall on CPU
94 seconds worth of heavy printing, no preemption:
@@ -755,7 +755,7 @@ int nfc_llcp_send_ui_frame(struct nfc_llcp_sock *sock, u8 ssap, u8 dsap,pdu=nfc_alloc_send_skb(sock->dev,&sock->sk,MSG_DONTWAIT,frag_len+LLCP_HEADER_SIZE,&err);if(pdu==NULL){-pr_err("Could not allocate PDU\n");+pr_err_ratelimited("Could not allocate PDU\n");continue;}---
Or ratelimited error reporting and cond_resched()
[that would be option B]:
I don't think this is a printk() issue per se, so I think Option B is
the only option. You should not get stuck in an infinite loop if we run
short on memory. Perhaps we could have an Option C which would exit
this loop gracefully with some kind of error. But I haven't looked at
the surrounding code to be sure if that is possible.
-- Steve
Or ratelimited error reporting and cond_resched()
[that would be option B]:
I don't think this is a printk() issue per se, so I think Option B is
the only option. You should not get stuck in an infinite loop if we run
short on memory. Perhaps we could have an Option C which would exit
this loop gracefully with some kind of error. But I haven't looked at
the surrounding code to be sure if that is possible.
Agree. I like Option B - an endless loop is the root cause, at the same
time filling up logbuf with useless data is useless. Can't tell if Option C
is feasible, up to networking people.
-ss
@@ -755,7 +755,7 @@ int nfc_llcp_send_ui_frame(struct nfc_llcp_sock *sock, u8 ssap, u8 dsap,pdu=nfc_alloc_send_skb(sock->dev,&sock->sk,MSG_DONTWAIT,frag_len+LLCP_HEADER_SIZE,&err);if(pdu==NULL){-pr_err("Could not allocate PDU\n");+pr_err_ratelimited("Could not allocate PDU\n");continue;}---
Or ratelimited error reporting and cond_resched()
[that would be option B]:
I don't think this is a printk() issue per se, so I think Option B is
the only option. You should not get stuck in an infinite loop if we run
short on memory. Perhaps we could have an Option C which would exit
this loop gracefully with some kind of error. But I haven't looked at
the surrounding code to be sure if that is possible.
I suspect this is not even OOM. This is probably some persistent
logical condition that makes the allocation function fail, either we
ask for too much, or socket in some bad state. Potentially this is
even triggerable remotely because there are some remove variables
involved in size calculation.
I don't think this is a printk() issue per se, so I think Option B is
the only option. You should not get stuck in an infinite loop if we run
short on memory. Perhaps we could have an Option C which would exit
this loop gracefully with some kind of error. But I haven't looked at
the surrounding code to be sure if that is possible.
I suspect this is not even OOM.
Could be. But at the same time it stalls RCU, so OOM at some point
becomes realistic.
-ss
The kernel is
CONFIG_PREEMPT_VOLUNTARY=y, llcp_sock_sendmsg() stuck in a error
reporting loop:
do {
...
pdu = nfc_alloc_send_skb(sock->dev, &sock->sk, MSG_DONTWAIT,
frag_len + LLCP_HEADER_SIZE, &err);
if (pdu == NULL) {
pr_err("Could not allocate PDU\n");
continue;
}
...
} while (remaining_len > 0);
[ 1004.674843] llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
[ 1004.681035] llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
...
[ 1098.508526] llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
[ 1098.514698] llcp: nfc_llcp_send_ui_frame: Could not allocate PDU
[ 1098.520844] INFO: rcu_sched self-detected stall on CPU
94 seconds worth of heavy printing, no preemption: