[NETCONF-776] Delay during delivery of NETCONF message Created: 17/May/21  Updated: 21/May/21  Resolved: 21/May/21

Status: Resolved
Project: netconf
Component/s: netconf
Affects Version/s: 1.13.0, Aluminium SR3
Fix Version/s: Aluminium SR4, 2.0.0, 1.13.3

Type: Bug Priority: Medium
Reporter: Martin Balaz Assignee: Robert Varga
Resolution: Done Votes: 0
Labels: pt
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File packet_trace.pcap    

 Description   

 

When NETCONF messages are sent from ODL controller to a simulated device, there is a delay of around 40 miliseconds during transmitting packets through network. This happens when smaller segments are sent, from ODL controller, for which it does not receive ACK right away, but sometimes after some delay of about 40 miliseconds.

Part of packet trace, which is included as an attechment:

  352 18.452697180    127.0.0.1 → 127.0.0.1    HTTP 306 HTTP/1.1 204 No Content 
  353 18.454299387    127.0.0.1 → 127.0.0.1    HTTP 24778 POST /restconf/operations/ncmount:write-routes HTTP/1.1  (application/json)
  354 18.462870957    127.0.0.1 → 127.0.0.1    TCP 374 53014 → 17830 [PSH, ACK] Seq=910075 Ack=18803 Win=65536 Len=308 TSval=1956095973 TSecr=1956095955
  355 18.467105704    127.0.0.1 → 127.0.0.1    TCP 294 17830 → 53014 [PSH, ACK] Seq=18803 Ack=910383 Win=1171456 Len=228 TSval=1956095977 TSecr=1956095973
  356 18.468011857    127.0.0.1 → 127.0.0.1    TCP 358 53014 → 17830 [PSH, ACK] Seq=910383 Ack=19031 Win=65536 Len=292 TSval=1956095978 TSecr=1956095977
  357 18.475131627    127.0.0.1 → 127.0.0.1    TCP 294 17830 → 53014 [PSH, ACK] Seq=19031 Ack=910675 Win=1171456 Len=228 TSval=1956095985 TSecr=1956095978
  358 18.496973379    127.0.0.1 → 127.0.0.1    TCP 66 8181 → 38312 [ACK] Seq=1920 Ack=222409 Win=65536 Len=0 TSval=1956096007 TSecr=1956095964
  359 18.499013130    127.0.0.1 → 127.0.0.1    TCP 32902 53014 → 17830 [PSH, ACK] Seq=910675 Ack=19259 Win=65536 Len=32836 TSval=1956096009 TSecr=1956095985
  360 18.506765555    127.0.0.1 → 127.0.0.1    TCP 65549 53014 → 17830 [ACK] Seq=943511 Ack=19259 Win=65536 Len=65483 TSval=1956096017 TSecr=1956095985
  361 18.508246260    127.0.0.1 → 127.0.0.1    TCP 66 17830 → 53014 [ACK] Seq=19259 Ack=1008994 Win=1145856 Len=0 TSval=1956096018 TSecr=1956096009
  362 18.508259159    127.0.0.1 → 127.0.0.1    TCP 255 53014 → 17830 [PSH, ACK] Seq=1008994 Ack=19259 Win=65536 Len=189 TSval=1956096018 TSecr=1956096018
  363 18.552865326    127.0.0.1 → 127.0.0.1    TCP 66 17830 → 53014 [ACK] Seq=19259 Ack=1009183 Win=1171456 Len=0 TSval=1956096063 TSecr=1956096018
  364 18.552891630    127.0.0.1 → 127.0.0.1    TCP 14234 53014 → 17830 [PSH, ACK] Seq=1009183 Ack=19259 Win=65536 Len=14168 TSval=1956096063 TSecr=1956096063
  365 18.552973144    127.0.0.1 → 127.0.0.1    TCP 66 17830 → 53014 [ACK] Seq=19259 Ack=1023351 Win=1171456 Len=0 TSval=1956096063 TSecr=1956096063
  366 18.577113026    127.0.0.1 → 127.0.0.1    TCP 294 17830 → 53014 [PSH, ACK] Seq=19259 Ack=1023351 Win=1171456 Len=228 TSval=1956096087 TSecr=1956096063
  367 18.577786589    127.0.0.1 → 127.0.0.1    TCP 294 17830 → 53014 [PSH, ACK] Seq=19487 Ack=1023351 Win=1171456 Len=228 TSval=1956096088 TSecr=1956096063
  368 18.578334159    127.0.0.1 → 127.0.0.1    TCP 66 53014 → 17830 [ACK] Seq=1023351 Ack=19715 Win=65536 Len=0 TSval=1956096089 TSecr=1956096087
  369 18.583169095    127.0.0.1 → 127.0.0.1    HTTP 306 HTTP/1.1 204 No Content 

There is a delay between sending packet number 362 an receiving ACK in packet 363. 

Time interval between sending packet with data and it's acknowledgment is about 52 miliseconds. Next packet with data is sent only after receiving acknowledgment for previously sent data.

This is probably caused by combination of ACK delay and Nagel's algorithm.

 


Generated at Wed Feb 07 20:15:52 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.