Re: [PATCH net 1/2] mlx5: fix possible ptp queue fifo overflow

[Vadim Fedorenko <vadfed@meta.com>]

On 24/01/2023 14:39, Gal Pressman wrote:
> On 23/01/2023 19:24, Vadim Fedorenko wrote:
>>   > Hi Vadim,
>>   >
>>
>>   >> +		ptpsq->cq_stats->ooo_cqe++;
>>   >> +		return false;
>>   >> +	}
>>   >
>>   >I honestly don't understand how this could happen, can you please
>>   >provide more information about your issue? Did you actually witness ooo
>>   >completions or is it a theoretical issue?
>>   >We know ptp CQEs can be dropped in some rare cases (that's the reason we
>>   >implemented this resync flow), but completions should always arrive
>>   >in-order.
>>
>> I was also surprised to see OOO completions but it's the reality. With a
>> little bit of debug I found this issue:
> 
> Where are these prints added? I assume inside the 'if
> (mlx5e_ptp_ts_cqe_drop())' statement?
> 
>>
>> [65578.231710] FIFO drop found, skb_cc = 141, skb_id = 140
> 
> Is this the first drop? In order for skb_cc to reach 141 it means it has
> already seen skb_id 140 (and consumed it). But here we see skb_id 140
> again? Is it a duplicate completion? Or is it a full wraparound?
> I'm now realising that the naming of the variables is very confusing,
> skb_cc isn't really the consumer counter, it is the cosumer index
> (masked value).
> 
>> [65578.293358] FIFO drop found, skb_cc = 141, skb_id = 143
> 
> How come we see the same skb_cc twice? When a drop is found we increment it.
> 
>> [65578.301240] FIFO drop found, skb_cc = 145, skb_id = 142
>> [65578.365277] FIFO drop found, skb_cc = 173, skb_id = 141
>> [65578.426681] FIFO drop found, skb_cc = 173, skb_id = 145
>> [65578.488089] FIFO drop found, skb_cc = 173, skb_id = 146
>> [65578.549489] FIFO drop found, skb_cc = 173, skb_id = 147
>> [65578.610897] FIFO drop found, skb_cc = 173, skb_id = 148
>> [65578.672301] FIFO drop found, skb_cc = 173, skb_id = 149
> 
> Confusing :S, did you manage to make sense out of these prints? We need
> prints when !dropped as well, otherwise it's impossible to tell when a
> wraparound occurred.
> 
> Anyway, I'd like to zoom out for a second, the whole fifo was designed
> under the assumption that completions are in-order (this is a guarantee
> for all SQs, not just ptp ones!), this fix seems more of a bandage that
> potentially hides a more severe issue.
> 
>>
>> It really shows that CQE are coming OOO sometimes.
> 
> Can we reproduce it somehow?
> Can you please try to update your firmware version? I'm quite confident
> that this issue is fixed already.
> 
I added some debug prints on top of the patches to show skb_cc and 
skb_id for every packet that is found by mlx5e_ptp_ts_cqe_drop() and 10 
packets after. The output is in https://dpaste.org/rMybA/raw

It clearly shows that some reordering is happening in CQE.
I'm open to add more debug info if you need it.