Eric Molitor wrote:
Was there a trace posted somewhere? I would indeed like to look at it.
I'd be quite happy to slam java it it happened to be putting logically
associated data onto the connection in separate send calls :)
It was sent to Bugzilla but too large so Andrew Morton kindly uploaded it to....
http://www.zip.com.au/~akpm/linux/patches/stuff/debug.dump.gz
That certainly is an odd looking trace. There doesn't happen to be a
system call trace to go along with it does there? It looks like it goes
along like this:
13:23:33.458806 IP l.5877 > l.12823: P 29110:29129(19) ack 52355 win 12374
13:23:33.459033 IP l.12823 > l.5877: P 52355:52359(4) ack 29129 win 9148
13:23:33.459113 IP l.12823 > l.5877: P 52359:52363(4) ack 29129 win 9148
13:23:33.497730 IP l.5877 > l.12823: . ack 52363 win 12374
13:23:33.497922 IP l.12823 > l.5877: P 52363:52374(11) ack 29129 win 9148
13:23:33.497971 IP l.5877 > l.12823: . ack 52374 win 12374
13:23:33.498205 IP l.5877 > l.12823: P 29129:29148(19) ack 52374 win 12374
13:23:33.498376 IP l.12823 > l.5877: P 52374:52378(4) ack 29148 win 9148
13:23:33.498454 IP l.12823 > l.5877: P 52378:52382(4) ack 29148 win 9148
13:23:33.537755 IP l.5877 > l.12823: . ack 52382 win 12374
13:23:33.538177 IP l.12823 > l.5877: P 52382:52386(4) ack 29148 win 9148
13:23:33.540439 IP l.5877 > l.12823: . ack 52386 win 12374
and then this
13:23:46.751167 IP l.5877 > l.12823: P 35323:35342(19) ack 58969 win 12374
13:23:46.751372 IP l.12823 > l.5877: P 58969:58973(4) ack 35342 win 9148
13:23:46.751452 IP l.12823 > l.5877: P 58973:58977(4) ack 35342 win 9148
13:23:46.751529 IP l.12823 > l.5877: P 58977:58978(1) ack 35342 win 9148
13:23:46.790557 IP l.5877 > l.12823: . ack 58978 win 12374
13:23:46.790722 IP l.12823 > l.5877: P 58978:58981(3) ack 35342 win 9148
13:23:46.790771 IP l.5877 > l.12823: . ack 58981 win 12374
13:23:46.790946 IP l.5877 > l.12823: P 35342:35361(19) ack 58981 win 12374
13:23:46.791113 IP l.12823 > l.5877: P 58981:58985(4) ack 35361 win 9148
13:23:46.791189 IP l.12823 > l.5877: P 58985:58989(4) ack 35361 win 9148
13:23:46.791263 IP l.12823 > l.5877: P 58989:58990(1) ack 35361 win 9148
13:23:46.830586 IP l.5877 > l.12823: . ack 58990 win 12374
13:23:46.830911 IP l.12823 > l.5877: P 58990:58993(3) ack 35361 win 9148
13:23:46.831035 IP l.5877 > l.12823: . ack 58993 win 12374
and then later like this:
13:24:35.288307 IP l.5877 > l.12823: P 58181:58200(19) ack 82177 win 12374
13:24:35.288635 IP l.12823 > l.5877: P 82177:82181(4) ack 58200 win 9148
13:24:35.288717 IP l.12823 > l.5877: P 82181:82185(4) ack 58200 win 9148
13:24:35.288794 IP l.12823 > l.5877: P 82185:82186(1) ack 58200 win 9148
13:24:35.288872 IP l.12823 > l.5877: P 82186:82188(2) ack 58200 win 9148
13:24:35.325614 IP l.5877 > l.12823: . ack 82188 win 12374
13:24:35.325828 IP l.12823 > l.5877: P 82188:82196(8) ack 58200 win 9148
13:24:35.325886 IP l.5877 > l.12823: . ack 82196 win 12374
13:24:35.326136 IP l.5877 > l.12823: P 58200:58219(19) ack 82196 win 12374
13:24:35.326366 IP l.12823 > l.5877: P 82196:82200(4) ack 58219 win 9148
13:24:35.326442 IP l.12823 > l.5877: P 82200:82204(4) ack 58219 win 9148
13:24:35.326519 IP l.12823 > l.5877: P 82204:82205(1) ack 58219 win 9148
13:24:35.326596 IP l.12823 > l.5877: P 82205:82207(2) ack 58219 win 9148
13:24:35.365629 IP l.5877 > l.12823: . ack 82207 win 12374
13:24:35.365897 IP l.12823 > l.5877: P 82207:82215(8) ack 58219 win 9148
13:24:35.365956 IP l.5877 > l.12823: . ack 82215 win 12374
13:24:35.390580 IP l.5877 > l.12823: P 58219:58238(19) ack 82215 win 12374
13:24:35.391400 IP l.12823 > l.5877: P 82215:82219(4) ack 58238 win 9148
13:24:35.391489 IP l.12823 > l.5877: P 82219:82223(4) ack 58238 win 9148
13:24:35.391568 IP l.12823 > l.5877: P 82223:82224(1) ack 58238 win 9148
13:24:35.391646 IP l.12823 > l.5877: P 82224:82226(2) ack 58238 win 9148
13:24:35.429642 IP l.5877 > l.12823: . ack 82226 win 12374
13:24:35.435902 IP l.12823 > l.5877: P 82226:82234(8) ack 58238 win 9148
13:24:35.439236 IP l.5877 > l.12823: . ack 82234 win 12374
for a long time, slowly being able to send another segment until it gets
to here and the "miracle" occurs and no more delayed ACKs:
13:24:55.124665 IP l.5877 > l.12823: P 67849:67868(19) ack 92387 win 12374
13:24:55.127262 IP l.12823 > l.5877: P 92387:92391(4) ack 67868 win 9148
13:24:55.127350 IP l.12823 > l.5877: P 92391:92395(4) ack 67868 win 9148
13:24:55.127422 IP l.12823 > l.5877: P 92395:92396(1) ack 67868 win 9148
13:24:55.127499 IP l.12823 > l.5877: P 92396:92398(2) ack 67868 win 9148
13:24:55.127574 IP l.12823 > l.5877: P 92398:92399(1) ack 67868 win 9148
13:24:55.127905 IP l.5877 > l.12823: P 67868:67887(19) ack 92399 win 12374
13:24:55.128100 IP l.12823 > l.5877: P 92399:92403(4) ack 67887 win 9148
13:24:55.128182 IP l.12823 > l.5877: P 92403:92407(4) ack 67887 win 9148
13:24:55.128253 IP l.12823 > l.5877: P 92407:92408(1) ack 67887 win 9148
13:24:55.128328 IP l.12823 > l.5877: P 92408:92410(2) ack 67887 win 9148
13:24:55.128400 IP l.12823 > l.5877: P 92410:92411(1) ack 67887 win 9148
13:24:55.128632 IP l.5877 > l.12823: P 67887:67906(19) ack 92411 win 12374
13:24:55.128808 IP l.12823 > l.5877: P 92411:92415(4) ack 67906 win 9148
13:24:55.128883 IP l.12823 > l.5877: P 92415:92419(4) ack 67906 win 9148
13:24:55.128954 IP l.12823 > l.5877: P 92419:92420(1) ack 67906 win 9148
13:24:55.129027 IP l.12823 > l.5877: P 92420:92422(2) ack 67906 win 9148
13:24:55.129112 IP l.12823 > l.5877: P 92422:92423(1) ack 67906 win 9148
looks like whatever is listening on 5877 is waiting for something to
complete before sending his 19 bytes (typically) and that something is
several tiny sends from whatver is at port 12823
The four, four, one, two seems to be a common "preamble" with the fifth
bit ranging in size. I'm guessing those are all separate sends for
logically associated data but the system call trace would help confirm it.
rick jones
-
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
