Re: ena(4) tx timeout messages in dmesg

From: Pete Wright <pete_at_nomadlogic.org>
Date: Tue, 13 May 2025 17:22:18 UTC

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.

-pete

-- 
Pete Wright
pete@nomadlogic.org