[SERVER-31063] Monitor queued network data for adaptive service executor Created: 12/Sep/17  Updated: 08/Jan/24  Resolved: 02/Nov/21

Status: Closed
Project: Core Server
Component/s: Diagnostics
Affects Version/s: None
Fix Version/s: None

Type: Improvement Priority: Major - P3
Reporter: Bruce Lucas (Inactive) Assignee: Backlog - Service Architecture
Resolution: Won't Do Votes: 24
Labels: SWDI, re-triaged-ticket
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Attachments: PNG File queueing.png    
Issue Links:
Depends
Related
is related to SERVER-30623 Operation latency and queuing stats a... Closed
Assigned Teams:
Service Arch
Participants:

 Description   

The adaptive service executor introduces a significant new queueing point. Two runs of test that ramps up to 20 k connections executing updates - first run is adaptive service executor, second run is synchronous (default) executor.

In the sync case (right) the signficant queuing point is the "queued writers" metric, but not in the adaptive case.

In the adaptive case (left) queuing occurs upstream of that. By monitoring /proc/net/tcp ("csv rx" chart) we can see far more requests queued in the network layer in the adaptive case than in the sync case. This represents about 1800 queued requests, so is a very significant queuing point, unlike in the sync case. Note that this only includes network data buffered in the kernel; there may possibly be signficant additional network data buffered in ASIO.

Understanding the queueing points is important for diagnosing bottleneck, so we should monitor buffered network data to support the adaptive service executor. This could be done

  • at the kernel level (as above). However this would be global for the node (not specific to mongod) and would not include data buffered in ASIO.
  • at the socket layer in mongod. This would be specific to mongod, but would not include whatever might be buffered in ASIO.
  • via ASIO APIs, if available.


 Comments   
Comment by Lauren Lewis (Inactive) [ 02/Nov/21 ]

The Service Arch team is in the process of cleaning up tickets in the backlog. This ticket has not been updated in two years so we are closing it. Please reopen if you think this change is valuable.

Comment by Bruce Lucas (Inactive) [ 18/Dec/17 ]

It looks like you're correct about SIOCGSTAMP.

There is an an SO_TIMESTAMP ioctl that purports to be able to provide timestamps for stream-based network i/o like TCP, but I don't know it's status; it may require a sufficiently recent kernel.

I agree that we should record /proc/net/tcp, specifically tx_queue and rx_queue, in FTDC. That will at least give us queue sizes.

Comment by Henrik Edin [ 12/Dec/17 ]

From what I understand you can only check SIOCGSTAMP for datagram sockets. It probably doesn't make much sense on tcp the way the protocol works.
ASIO doesn't do any additional buffering. What it looks like to me is that this mainly is an artifact of using asynchronous networking and not the queuing before a worker thread picks up the task in the adaptive executor.
As I wrote in SERVER-30623 I think it's a good idea to add /proc/net/tcp to FTDC. But I'm not sure if there's anything else we should do. Do you have any opinion on this jonathan.reams?

Comment by Bruce Lucas (Inactive) [ 11/Dec/17 ]

We could also investigate whether the SIOCGSTAMP ioctl would provide the means to monitor time spent queued in the kernel network buffers so that it an be added to the reported latency (along with other additions to latency reporting in SERVER-30623).

Comment by Bruce Lucas (Inactive) [ 12/Sep/17 ]

jonathan.reams, I was a bit surprised to see requests queueing in the network ("csv rx") instead of in the task queue ("totalTimeQueuedMicros") here, so maybe there's also an issue in the code to be investigated here.

(Note "totalTimeQueuedMicros" is marked with unit of "threads" which is not the correct unit in the case of the adaptive executor - should be "tasks").

Generated at Thu Feb 08 04:25:52 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.