Welcome to AT91SAM Community Discussions

Posted: **Fri Apr 20, 2018 1:38 pm**

I'm using a SAMA5d4 custom board, building Linux image using Yocto Project, Rocko.
Kernel version used: 4.14.14

I have a web server running on this device -serving pages, a python script running on another machine (Linux) makes HTTP requests.
Problem:
A lot of requests are ok, completely served to the client.
Randomly, one connection times out on the client side - I've tracked this problem down to the MACB driver[1]
Investigating using wireshark, client side, I see that the last frame of the response doesn't reach the client, the client times out after 10 seconds, closes the connection (sends FIN ACK), then I immediately see the lost packet arriving.
tcpdump on the SAMA5d4 custom board says that the frame has been 'sent' in time, along with the others.

In the MACB driver, I've added some logs. Basically I’ve been looking at the function that is called for starting the transmission,
macb_start_xmit() and the one that is called after transmission is complete, macb_tx_interrupt().

I’ve add logs containing packet lengths, and I've observed that the missing frame is being mapped for DMA transfer in time, at around the same time with the previous ones (in sync with what I see in tcpdump server side), but I get the corresponding interrupt (in macb_tx_interrupt()) only after 10 seconds (the timeout) - for some reason it's ignored by the hardware (?).
That packet is confirmed to be sent [2] only after a new one is enqueued: the response for the client's FIN ACK - they are both sent

Do you have knowledge of such an issue or hints how to proceed ?

Regards

[1]: https://git.kernel.org/pub/scm/linux/ke ... h=v4.14.14
[2]: https://git.kernel.org/pub/scm/linux/ke ... 14.14#n843

Posted: **Sat Apr 21, 2018 3:49 am**

tamel wrote:ethernet packet fragment not being sent in time

Your title is confusing: what is a "packet fragment"?
Usually a network protocol packet equates to the Ethernet frame of the datalink layer.
Do you mean that a multi-frame message is incomplete, or one Ethernet frame is incomplete?

Regarding Wireshark captures, IMO a man-in-the-middle capture is less intrusive, and therefore more accurate. I've acquired old Netgear hubs from eBay just for such situations. The one big downside is that old hubs maxed out at 10Base-T, so you have to hope that the speed reduction doesn't affect the problem (e.g. the speed reduction didn't matter when investigating NAPI rotting packets).

Regards

Posted: **Mon Apr 23, 2018 8:24 am**

blue_z wrote: ↑
Sat Apr 21, 2018 3:49 am
Do you mean that a multi-frame message is incomplete, or one Ethernet frame is incomplete?

Sorry for not being clear enough, I mean a multi-frame message is incomplete, the last frame is not sent in time, even if I see it being mapped for DMA transfer in time, along with the previous ones. Enqueuing another packet for transmission - a new call of macb_start_xmit() [1] -, triggers the send operation of this "forgotten" frame.
So, after a GET from the client, the server sends back the response - the response gets split in multiple frames - the last frame doesn't end up on the client side.
See this capture : https://imgur.com/a/vNW7W0U
server is 192.168.100.100, Client closes the connection after 10 seconds - times out, as a result the server delivers the missing frame, 5519

During the investigation, I already tested this problem with a man-in-the-middle, as you also proposed. I used a router and I've mirrored the port that the server was connected to. Then I captured the server traffic from that mirrored port:

Code: Select all

client <------> router <------> server
                          ^
                          | (server port mirrored) 
                   wireshark

The capture is consistent with what I see on the client: the last frame is received delayed, after the client closes the connection.

On some rare occasions (depending on the number/locations of my netdev_dbg log calls in the driver) I've seen the issue not only for the last frame, but for the last 2.

Regards

[1]: https://git.kernel.org/pub/scm/linux/ke ... 4.14#n1595

Posted: **Tue Apr 24, 2018 3:16 am**

tamel wrote:... I see that the last frame of the response doesn't reach the client, the client times out after 10 seconds, closes the connection (sends FIN ACK), then I immediately see the lost packet arriving.

So in effect, can you use receipt of this FIN ACK to trigger debug output on the transmitter state?
The state of the list of transmit buffer descriptors and GMAC device registers would be of interest.

According to the SoC datasheet (section 36.6.3.2), the reasons for transmission to halt are:

a buffer descriptor with its used bit set is read,
a transmit error occurs, or
by writing to the transmit halt bit of the Network Control register.
Transmission is suspended if a pause frame is received while the pause enable bit is set in the Network Configuration register.

All of these conditions need to be ruled out as the reasons for the delayed transmission of the last frame.
Considering that the transmit side of the macb driver does not appear to have a race condition like the NAPI receive side that can cause rotting packets, the root cause could be unique to your situation.

Regards

Posted: **Wed Apr 25, 2018 2:45 pm**

I am also working at the topic (with tamel):
From traces, the issue could be, when transmitting a TX-frame (called current frame here) with multiple buffers (2 in this case), having the buffers already added to the TX DMA descriptor list and having triggered the MAC DMA to start TX-transfer.
A MAC interrupt happens with TX-complete for the previous frame (transfer is ok). The trace from this ISR invokation shows also already the first buffer of the current frame, but it is unclear to me if it was already transferred. From the wireshark trace I would say yes (but I am not sure if descriptor-buffers correspond to the TCP-segment frames seen in wireshark).
Next an RX Interrupt is happening. According to the sama5d4 data sheet, receive DMA transactions have priority over transmit DMA transactions (whatever this would mean in detail).
After the RX ISR, I would expect that the MAC DMA continues with the TX transfer in order to send the second buffer of the current frame, but this is not happening. It usually only gets sent when the connection is closed.
My current view of the problem is that the DMA somehow sleeps, after got interrupted by RX while it was doing TX mit multiple buffers in a frame. I have checked all the error conditions from MAC registers like suspension, pause-frames, tx-errors etc. but everything look ok.
(source code is in drivers/net/ethernet/cadence/macb_main.c )

Posted: **Thu Apr 26, 2018 1:16 am**

onnascha wrote:From traces, the issue could be, ...
...
From the wireshark trace I would say yes

Describe the problem's symptoms, not your guesses.

onnascha wrote:The trace from this ISR invokation shows also already the first buffer of the current frame, but it is unclear to me if it was already transferred.

If you had inspected the list of transmit buffer descriptors as suggested, then this probably would not be such a mystery.

onnascha wrote:After the RX ISR, I would expect that the MAC DMA continues with the TX transfer in order to send the second buffer of the current frame, but this is not happening. It usually only gets sent when the connection is closed.

Now you're contradicting the clarification I got from tamel.
Your understanding of DMA seems flawed; priority only applies to bus arbitration.
Your scenario seems implausible; I would expect a transmit underrun to occur if the DMA "failed".
You seem to be misusing jargon. What exactly do you think a "buffer" and a "frame" are, and how they relate to each other?

FYI each transmitted Ethernet frame can consist of one to 128 buffers (per GMAC specification in the SoC datasheet).
An HTTP response can be fragmented into several frames.

Since the SoC datasheet states:

If transmission stops due to a transmit error or a used bit being read, transmission restarts from the first buffer
descriptor of the frame being transmitted when the transmit start bit is rewritten.

you probably don't even know what was the last buffer that was actually transmitted before the "delay".
I.E. your Wireshark captures will only show you complete frames.

If you think that the last buffer of a (or the last?) frame is not getting transmitted, then that would result in an incomplete frame.
With modern network hardware, that can be difficult to detect and capture.
See Capturing damaged frames.

onnascha wrote:My current view of the problem is that the DMA somehow sleeps, after got interrupted by RX while it was doing TX mit multiple buffers in a frame.

What evidence (other than Wireshark captures) do you have to support this "current view"?
Without any evidence, your "view" is pure speculation and alleges a HW or SW bug that is not worth investigating.
(I would try to disprove your "view" by simply running the subnet in half-duplex mode.)

Regards

Posted: **Fri Jun 22, 2018 7:48 am**

I was able to reproduce the problem using the SAMA5D4 Xplained board.
I used a slightly modified demo image from the linux4sam site: linux4sam-poky-sama5d4_xplained-5.8.zip
ftp://www.at91.com/pub/demo/linux4sam_5 ... ed-5.8.zip

Instead of the rootfs provided in that demo image I’ve built another one, which includes nginx + some static html files. I've also added dropbear.
This was built using Yocto, and is based on core-image-minimal - Rocko branch
Everything else (Kernel etc) are the one provided by microchip.

So, using a python script to send HTTP requests to the server I'm able to reproduce the problem in the OP.

Posted: **Tue Jun 26, 2018 9:17 pm**

tamel wrote: I was able to reproduce the problem using the SAMA5D4 Xplained board.
...
So, using a python script to send HTTP requests to the server I'm able to reproduce the problem in the OP.

Okay, but how does that help clarify the "problem"?
You and your co-worker have provided contradictory descriptions of this "problem".

Regards

Posted: **Thu Jul 05, 2018 6:10 pm**

Hi,

The problem seems pretty well described to me.
To go further with the distinction between "buffer" and "frame" and figuring out if it could be an error within the internal DMA, do you think that disabling the SG feature and knowing that it could make the problem disappear gives us a clue?

Let's say that disabling SG in the driver doesn't solve the issue that you are seeing with a part of the network data failing to be transmitted in time to the client... Then we can conclude that it's not a "buffer" issue as without the SG feature on the adapater's side, the kernel would re-arrange the network packets so that a single sk_buff is used. As for GEM, a single sk_buff can be mappted to a single descriptor so a single "buffer". Does it make sense?

I'm still trying to figure out what could cause this issue...
Best regards,
Nicolas

Welcome to AT91SAM Community Discussions

MACB driver: ethernet packet fragment not being sent in time

MACB driver: ethernet packet fragment not being sent in time

Re: MACB driver: ethernet packet fragment not being sent in time

Re: MACB driver: ethernet packet fragment not being sent in time

Re: MACB driver: ethernet packet fragment not being sent in time

Re: MACB driver: ethernet packet fragment not being sent in time

Re: MACB driver: ethernet packet fragment not being sent in time

Re: MACB driver: ethernet packet fragment not being sent in time

Re: MACB driver: ethernet packet fragment not being sent in time

Re: MACB driver: ethernet packet fragment not being sent in time