Re: ena(4) tx timeout messages in dmesg

From: Dan Langille <dan_at_langille.org>
Date: Tue, 13 May 2025 20:20:56 UTC
On Tue, May 13, 2025, at 1:22 PM, Pete Wright wrote:
> On 5/12/25 11:04, Pete Wright wrote:
>> hey there - i have an ec2 instance that i'm using as a nfs server and 
>> have noticed the following messages in my dmesg buffer:
>> 
>> ena0: Found a Tx that wasn't completed on time, qid 2, index 593. 10 
>> msecs have passed since last cleanup. Missing Tx timeout value 5000 msecs.
>> ena0: Found a Tx that wasn't completed on time, qid 2, index 220. 1 
>> msecs have passed since last cleanup. Missing Tx timeout value 5000 msecs.
>> ena0: Found a Tx that wasn't completed on time, qid 3, index 240. 1 
>> msecs have passed since last cleanup. Missing Tx timeout value 5000 msecs.
>> ena0: Found a Tx that wasn't completed on time, qid 3, index 974. 1 
>> msecs have passed since last cleanup. Missing Tx timeout value 5000 msecs.
>> ena0: Found a Tx that wasn't completed on time, qid 2, index 730. 1 
>> msecs have passed since last cleanup. Missing Tx timeout value 5000 msecs.
>> ena0: Found a Tx that wasn't completed on time, qid 2, index 864. 10 
>> msecs have passed since last cleanup. Missing Tx timeout value 5000 msecs.
>> ena0: Found a Tx that wasn't completed on time, qid 3, index 998. 1 
>> msecs have passed since last cleanup. Missing Tx timeout value 5000 msecs.
>> 
>> 
>
>
> So I've found an interesting pattern, the above messages get printed to 
> /var/log/messages and the dmesg buffer when i "su" to root apparently:
>
> May  9 19:19:23 airflow-nfs su[66523]: ec2-user to root on /dev/pts/3
> May  9 19:19:23 airflow-nfs kernel: Found a Tx that wasn't completed on 
> time, qid 2, index 593. 10 msecs have passed since last cleanup. Missing 
> Tx timeout value 5000 msecs.
> May  9 19:19:23 airflow-nfs kernel: Found a Tx that wasn't completed on 
> time, qid 2, index 220. 1 msecs have passed since last cleanup. Missing 
> Tx timeout value 5000 msecs.
> M
>
>
> May 12 17:55:25 airflow-nfs su[29272]: ec2-user to root on /dev/pts/0
> May 12 17:55:25 airflow-nfs kernel: Found a Tx that wasn't completed on 
> time, qid 3, index 998. 1 msecs have passed since last cleanup. Missing 
> Tx timeout value 5000 msecs.
> May 12 17:55:25 airflow-nfs kernel: Found a Tx that wasn't completed on 
> time, qid 1, index 975. 1 msecs have passed since last cleanup. Missing 
> Tx timeout value 5000 msecs.
> May 12 17:55:25 airflow-nfs kernel: Found a Tx that wasn't completed on 
> time, qid 1, index 428. 1 msecs have passed since last cleanup. Missing 
> Tx timeout value 5000 msecs.
>
>
> May 13 17:17:14 airflow-nfs su[16099]: ec2-user to root on /dev/pts/0
> May 13 17:17:14 airflow-nfs kernel: Found a Tx that wasn't completed on 
> time, qid 1, index 289. 1 msecs have passed since last cleanup. Missing 
> Tx timeout value 5000 msecs.
> May 13 17:17:14 airflow-nfs kernel: Found a Tx that wasn't completed on 
> time, qid 1, index 159. 1 msecs have passed since last cleanup. Missing 
> Tx timeout value 5000 msecs.
>
>
> I have no idea what that means, but certainly feels like an interesting 
> data-point.  i'm ssh'ing as the ec2-user, then "su -" to become root and 
> as you can see from the timestamps something triggers those log events. 
> i'm not seeing any other occurances of these log messages outside of 
> su'ing too.  this is a very vanilla system, not krb auth or other 
> network interactions should happen when i become root.

I get them too:

May  9 21:20:50 aws-1 kernel: ena0: Found a Tx that wasn't completed on time, qid 0, index 105. 1 msecs have passed since last cleanup. Missing Tx timeout value 5000 msecs.

-- 
  Dan Langille
  dan@langille.org