Too much time taken to send a DataFrame

[prateekkohli2112]

Below are jetty logs for communication over 1 jetty stream:

SERVER.System.6.log:2020-03-07 07:57:58.671, .HTTP2Session # Sending DataFrame@6ec3e832#4372853{length:2739,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.671, .HTTP2Flusher # Appended DataFrame@6ec3e832#4372853{length:2739,end=true}, entries=5
SERVER.System.6.log:2020-03-07 07:57:58.673, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2739,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.673, .HTTP2Flusher # Writing 10 buffers (5549 bytes) - entries processed/pending 5/19: [DataFrame@507f5a22#4372823{length:2739,end=true}, HeadersFrame@4a124105#4372859{end=false}, DataFrame@3ed26ccc#4372827{length:963,end=true}, HeadersFrame@70cff0f8#4372861{end=false}, DataFrame@7647853b#4372775{length:963,end=true}]/[DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@7161ab7e#4372831{length:2739,end=true}, DataFrame@5458306d#4372829{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2739,end=true}, DataFrame@616c5e97#4372835{length:2739,end=true}, DataFrame@200c9504#4372803{length:2193,end=true}, DataFrame@1c79f0ae#4372839{length:2739,end=true}, DataFrame@3745068b#4372837{length:2739,end=true}, DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, DataFrame@180a85db#4372843{length:2739,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.673, .HTTP2Flusher # Written 10 buffers - entries processed/pending 5/19: [DataFrame@507f5a22#4372823{length:0,end=true}, HeadersFrame@4a124105#4372859{end=false}, DataFrame@3ed26ccc#4372827{length:963,end=true}, HeadersFrame@70cff0f8#4372861{end=false}, DataFrame@7647853b#4372775{length:0,end=true}]/[DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@7161ab7e#4372831{length:2739,end=true}, DataFrame@5458306d#4372829{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2739,end=true}, DataFrame@616c5e97#4372835{length:2739,end=true}, DataFrame@200c9504#4372803{length:2193,end=true}, DataFrame@1c79f0ae#4372839{length:2739,end=true}, DataFrame@3745068b#4372837{length:2739,end=true}, DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, DataFrame@180a85db#4372843{length:2739,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.675, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2739,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.676, .HTTP2Flusher # Writing 10 buffers (5603 bytes) - entries processed/pending 5/19: [HeadersFrame@356a0014#4372863{end=false}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@7161ab7e#4372831{length:2739,end=true}, DataFrame@5458306d#4372829{length:2739,end=true}, HeadersFrame@34a2275#4372865{end=false}]/[DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@616c5e97#4372835{length:2739,end=true}, DataFrame@200c9504#4372803{length:2193,end=true}, DataFrame@1c79f0ae#4372839{length:2739,end=true}, DataFrame@3745068b#4372837{length:2739,end=true}, DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, DataFrame@180a85db#4372843{length:2739,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.676, .HTTP2Flusher # Written 10 buffers - entries processed/pending 5/19: [HeadersFrame@356a0014#4372863{end=false}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@7161ab7e#4372831{length:0,end=true}, DataFrame@5458306d#4372829{length:0,end=true}, HeadersFrame@34a2275#4372865{end=false}]/[DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@616c5e97#4372835{length:2739,end=true}, DataFrame@200c9504#4372803{length:2193,end=true}, DataFrame@1c79f0ae#4372839{length:2739,end=true}, DataFrame@3745068b#4372837{length:2739,end=true}, DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, DataFrame@180a85db#4372843{length:2739,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.678, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2739,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.679, .HTTP2Flusher # Writing 8 buffers (3617 bytes) - entries processed/pending 4/20: [DataFrame@616c5e97#4372835{length:2739,end=true}, HeadersFrame@5bbed4be#4372867{end=false}, HeadersFrame@7f86db5#4372869{end=false}, DataFrame@200c9504#4372803{length:1377,end=true}]/[DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@1c79f0ae#4372839{length:2739,end=true}, DataFrame@3745068b#4372837{length:2739,end=true}, DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, DataFrame@180a85db#4372843{length:2739,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.679, .HTTP2Flusher # Written 8 buffers - entries processed/pending 4/20: [DataFrame@616c5e97#4372835{length:0,end=true}, HeadersFrame@5bbed4be#4372867{end=false}, HeadersFrame@7f86db5#4372869{end=false}, DataFrame@200c9504#4372803{length:1377,end=true}]/[DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@1c79f0ae#4372839{length:2739,end=true}, DataFrame@3745068b#4372837{length:2739,end=true}, DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, DataFrame@180a85db#4372843{length:2739,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.680, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2739,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.681, .HTTP2Flusher # Writing 2 buffers (2748 bytes) - entries processed/pending 1/21: [DataFrame@1c79f0ae#4372839{length:2739,end=true}]/[DataFrame@3745068b#4372837{length:2739,end=true}, DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, DataFrame@180a85db#4372843{length:2739,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.681, .HTTP2Flusher # Written 2 buffers - entries processed/pending 1/21: [DataFrame@1c79f0ae#4372839{length:0,end=true}]/[DataFrame@3745068b#4372837{length:2739,end=true}, DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, DataFrame@180a85db#4372843{length:2739,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.682, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2739,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.684, .HTTP2Flusher # Writing 6 buffers (2792 bytes) - entries processed/pending 3/20: [HeadersFrame@302cdbe9#4372873{end=false}, HeadersFrame@4df22d90#4372871{end=false}, DataFrame@3745068b#4372837{length:2739,end=true}]/[DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, DataFrame@180a85db#4372843{length:2739,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.684, .HTTP2Flusher # Written 6 buffers - entries processed/pending 3/20: [HeadersFrame@302cdbe9#4372873{end=false}, HeadersFrame@4df22d90#4372871{end=false}, DataFrame@3745068b#4372837{length:0,end=true}]/[DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, DataFrame@180a85db#4372843{length:2739,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.686, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2739,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.687, .HTTP2Flusher # Writing 12 buffers (8477 bytes) - entries processed/pending 6/19: [DataFrame@671127f8#4372841{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, HeadersFrame@3d091014#4372877{end=false}, DataFrame@6341e9cd#4372783{length:1857,end=true}, DataFrame@111f5ef2#4372845{length:2739,end=true}, HeadersFrame@7b791a47#4372875{end=false}]/[DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.688, .HTTP2Flusher # Written 12 buffers - entries processed/pending 6/19: [DataFrame@671127f8#4372841{length:0,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, HeadersFrame@3d091014#4372877{end=false}, DataFrame@6341e9cd#4372783{length:0,end=true}, DataFrame@111f5ef2#4372845{length:0,end=true}, HeadersFrame@7b791a47#4372875{end=false}]/[DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@3662ee72#4372825{length:2259,end=true}, DataFrame@4f941cce#4372847{length:2739,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.689, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2739,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.690, .HTTP2Flusher # Writing 6 buffers (2779 bytes) - entries processed/pending 3/20: [DataFrame@3662ee72#4372825{length:2259,end=true}, HeadersFrame@530ed5#4372879{end=false}, DataFrame@4f941cce#4372847{length:2259,end=true}]/[DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.690, .HTTP2Flusher # Written 6 buffers - entries processed/pending 3/20: [DataFrame@3662ee72#4372825{length:0,end=true}, HeadersFrame@530ed5#4372879{end=false}, DataFrame@4f941cce#4372847{length:2259,end=true}]/[DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@13f3538d#4372849{length:2739,end=true}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.691, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2739,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.692, .HTTP2Flusher # Writing 4 buffers (2770 bytes) - entries processed/pending 2/20: [DataFrame@13f3538d#4372849{length:2739,end=true}, HeadersFrame@206ab4cb#4372881{end=false}]/[DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.692, .HTTP2Flusher # Written 4 buffers - entries processed/pending 2/20: [DataFrame@13f3538d#4372849{length:0,end=true}, HeadersFrame@206ab4cb#4372881{end=false}]/[DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2739,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.693, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2739,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.693, .HTTP2Session # Generated DataFrame@6ec3e832#4372853{length:2193,end=true}, length/window/data=546/546/2739
SERVER.System.6.log:2020-03-07 07:57:58.693, .FlowControlStrategy # Sending, stream send window 65535 -> 64989 for HTTP2Stream@431675ea#4372853{sendWindow=64989,recvWindow=8388608,reset=false/false,NOT_CLOSED,age=29,attachment=HttpChannelOverHTTP2@3c306f67(exchange=HttpExchange@4e915c28 req=PENDING/null@null res=PENDING/null@null)[send=HttpSenderOverHTTP2@434393ab(req=HEADERS,snd=SENDING,failure=null),recv=HttpReceiverOverHTTP2@38d61d78(rsp=IDLE,failure=null)]}
SERVER.System.6.log:2020-03-07 07:57:58.694, .HTTP2Stream # Update close for HTTP2Stream@431675ea#4372853{sendWindow=64989,recvWindow=8388608,reset=false/false,NOT_CLOSED,age=29,attachment=HttpChannelOverHTTP2@3c306f67(exchange=HttpExchange@4e915c28 req=PENDING/null@null res=PENDING/null@null)[send=HttpSenderOverHTTP2@434393ab(req=HEADERS,snd=SENDING,failure=null),recv=HttpReceiverOverHTTP2@38d61d78(rsp=IDLE,failure=null)]} update=true event=BEFORE_SEND
SERVER.System.6.log:2020-03-07 07:57:58.694, .HTTP2Flusher # Generated 555 frame bytes for DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.695, .HTTP2Flusher # Writing 10 buffers (6095 bytes) - entries processed/pending 5/19: [HeadersFrame@37c6731c#4372885{end=false}, HeadersFrame@6a966fc6#4372883{end=false}, DataFrame@1183bd24#4372851{length:2739,end=true}, DataFrame@24b6a126#4372855{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}]/[DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.695, .HTTP2Session # Flushed 555/555 frame bytes for DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.695, .HTTP2Flusher # Written 10 buffers - entries processed/pending 5/19: [HeadersFrame@37c6731c#4372885{end=false}, HeadersFrame@6a966fc6#4372883{end=false}, DataFrame@1183bd24#4372851{length:0,end=true}, DataFrame@24b6a126#4372855{length:0,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}]/[DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@3b96f133#4372857{length:2739,end=true}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:2739,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.697, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.698, .HTTP2Flusher # Writing 10 buffers (5831 bytes) - entries processed/pending 5/19: [DataFrame@3b96f133#4372857{length:2739,end=true}, HeadersFrame@1ae38262#4372887{end=false}, HeadersFrame@4dede1cf#4372889{end=false}, DataFrame@3ed26ccc#4372827{length:963,end=true}, DataFrame@748b478c#4372859{length:681,end=true}]/[DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.699, .HTTP2Flusher # Written 10 buffers - entries processed/pending 5/19: [DataFrame@3b96f133#4372857{length:0,end=true}, HeadersFrame@1ae38262#4372887{end=false}, HeadersFrame@4dede1cf#4372889{end=false}, DataFrame@3ed26ccc#4372827{length:0,end=true}, DataFrame@748b478c#4372859{length:681,end=true}]/[DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@5a9d388b#4372861{length:2739,end=true}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2739,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.701, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.702, .HTTP2Flusher # Writing 10 buffers (5549 bytes) - entries processed/pending 5/19: [DataFrame@5a9d388b#4372861{length:2739,end=true}, HeadersFrame@18305012#4372891{end=false}, DataFrame@83ff22f#4372833{length:2685,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, HeadersFrame@1eac0da4#4372893{end=false}]/[DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.702, .HTTP2Flusher # Written 10 buffers - entries processed/pending 5/19: [DataFrame@5a9d388b#4372861{length:0,end=true}, HeadersFrame@18305012#4372891{end=false}, DataFrame@83ff22f#4372833{length:0,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, HeadersFrame@1eac0da4#4372893{end=false}]/[DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@1322ac96#4372869{length:2739,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.704, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.705, .HTTP2Flusher # Writing 10 buffers (8755 bytes) - entries processed/pending 5/18: [DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@74173e2f#4372865{length:2739,end=true}, DataFrame@7995393f#4372867{length:2739,end=true}, DataFrame@200c9504#4372803{length:1377,end=true}, HeadersFrame@4deff2f7#4372895{end=false}]/[DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.706, .HTTP2Flusher # Written 10 buffers - entries processed/pending 5/18: [DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@74173e2f#4372865{length:0,end=true}, DataFrame@7995393f#4372867{length:0,end=true}, DataFrame@200c9504#4372803{length:0,end=true}, HeadersFrame@4deff2f7#4372895{end=false}]/[DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}, DataFrame@180a85db#4372843{length:1677,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.708, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.709, .HTTP2Flusher # Writing 12 buffers (5751 bytes) - entries processed/pending 6/17: [HeadersFrame@3444f2bb#4372897{end=false}, DataFrame@180a85db#4372843{length:1497,end=true}, HeadersFrame@25bd0996#4372901{end=false}, HeadersFrame@16ccb4e9#4372899{end=false}, DataFrame@4a63709c#4372873{length:2739,end=true}, DataFrame@6f1c5d8c#4372871{length:2739,end=true}]/[DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.709, .HTTP2Flusher # Written 12 buffers - entries processed/pending 6/17: [HeadersFrame@3444f2bb#4372897{end=false}, DataFrame@180a85db#4372843{length:1497,end=true}, HeadersFrame@25bd0996#4372901{end=false}, HeadersFrame@16ccb4e9#4372899{end=false}, DataFrame@4a63709c#4372873{length:0,end=true}, DataFrame@6f1c5d8c#4372871{length:0,end=true}]/[DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.710, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.711, .HTTP2Flusher # Writing 2 buffers (22 bytes) - entries processed/pending 1/20: [HeadersFrame@180dfd00#4372903{end=false}]/[DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.711, .HTTP2Flusher # Written 2 buffers - entries processed/pending 1/20: [HeadersFrame@180dfd00#4372903{end=false}]/[DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.711, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.712, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.713, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.714, .HTTP2Flusher # Writing 2 buffers (22 bytes) - entries processed/pending 1/21: [HeadersFrame@c7ba5ac#4372905{end=false}]/[DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}, DataFrame@26183828#4372903{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.714, .HTTP2Flusher # Written 2 buffers - entries processed/pending 1/21: [HeadersFrame@c7ba5ac#4372905{end=false}]/[DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}, DataFrame@26183828#4372903{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.715, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.6.log:2020-03-07 07:57:58.716, .HTTP2Flusher # Writing 4 buffers (5496 bytes) - entries processed/pending 2/20: [DataFrame@6ff300bf#4372877{length:2739,end=true}, DataFrame@66f66b4a#4372875{length:2739,end=true}]/[DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}, DataFrame@26183828#4372903{length:2739,end=true}, DataFrame@7b2b4fd2#4372905{length:2739,end=true}]
SERVER.System.6.log:2020-03-07 07:57:58.716, .HTTP2Flusher # Written 4 buffers - entries processed/pending 2/20: [DataFrame@6ff300bf#4372877{length:0,end=true}, DataFrame@66f66b4a#4372875{length:0,end=true}]/[DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}, DataFrame@26183828#4372903{length:2739,end=true}, DataFrame@7b2b4fd2#4372905{length:2739,end=true}]
SERVER.System.5.log:2020-03-07 07:57:58.717, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.5.log:2020-03-07 07:57:58.719, .HTTP2Flusher # Writing 8 buffers (88 bytes) - entries processed/pending 4/20: [HeadersFrame@2e9a43a8#4372913{end=false}, HeadersFrame@624a8345#4372907{end=false}, HeadersFrame@3991253c#4372911{end=false}, HeadersFrame@4e61814b#4372909{end=false}]/[DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}, DataFrame@26183828#4372903{length:2739,end=true}, DataFrame@7b2b4fd2#4372905{length:2739,end=true}]
SERVER.System.5.log:2020-03-07 07:57:58.719, .HTTP2Flusher # Written 8 buffers - entries processed/pending 4/20: [HeadersFrame@2e9a43a8#4372913{end=false}, HeadersFrame@624a8345#4372907{end=false}, HeadersFrame@3991253c#4372911{end=false}, HeadersFrame@4e61814b#4372909{end=false}]/[DataFrame@4f941cce#4372847{length:2259,end=true}, DataFrame@4ae65598#4372879{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2739,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}, DataFrame@26183828#4372903{length:2739,end=true}, DataFrame@7b2b4fd2#4372905{length:2739,end=true}]
SERVER.System.5.log:2020-03-07 07:57:58.720, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.5.log:2020-03-07 07:57:58.720, .HTTP2Flusher # Flow control stalled at DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.5.log:2020-03-07 07:57:58.721, .HTTP2Flusher # Writing 8 buffers (5581 bytes) - entries processed/pending 4/22: [DataFrame@884cd7d#4372881{length:2205,end=true}, DataFrame@4f941cce#4372847{length:2259,end=true}, HeadersFrame@3be1ec42#4372915{end=false}, DataFrame@4ae65598#4372879{length:2739,end=true}]/[DataFrame@884cd7d#4372881{length:2205,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}, DataFrame@26183828#4372903{length:2739,end=true}, DataFrame@7b2b4fd2#4372905{length:2739,end=true}, DataFrame@1cc82c2c#4372913{length:2739,end=true}, DataFrame@202725db#4372907{length:2739,end=true}, DataFrame@5e394bba#4372911{length:2739,end=true}, DataFrame@17ca9619#4372909{length:2739,end=true}]
SERVER.System.5.log:2020-03-07 07:57:58.722, .HTTP2Flusher # Written 8 buffers - entries processed/pending 4/22: [DataFrame@884cd7d#4372881{length:2205,end=true}, DataFrame@4f941cce#4372847{length:0,end=true}, HeadersFrame@3be1ec42#4372915{end=false}, DataFrame@4ae65598#4372879{length:0,end=true}]/[DataFrame@884cd7d#4372881{length:2205,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, DataFrame@73d18021#4372885{length:2739,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}, DataFrame@26183828#4372903{length:2739,end=true}, DataFrame@7b2b4fd2#4372905{length:2739,end=true}, DataFrame@1cc82c2c#4372913{length:2739,end=true}, DataFrame@202725db#4372907{length:2739,end=true}, DataFrame@5e394bba#4372911{length:2739,end=true}, DataFrame@17ca9619#4372909{length:2739,end=true}]
SERVER.System.5.log:2020-03-07 07:57:58.722, .HTTP2Flusher # Processing DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.5.log:2020-03-07 07:57:58.722, .HTTP2Session # Generated DataFrame@6ec3e832#4372853{length:2193,end=true}, length/window/data=2193/3555/2193
SERVER.System.5.log:2020-03-07 07:57:58.722, .FlowControlStrategy # Sending, stream send window 64989 -> 62796 for HTTP2Stream@431675ea#4372853{sendWindow=62796,recvWindow=8388608,reset=false/false,LOCALLY_CLOSING,age=58,attachment=HttpChannelOverHTTP2@3c306f67(exchange=HttpExchange@4e915c28 req=PENDING/null@null res=PENDING/null@null)[send=HttpSenderOverHTTP2@434393ab(req=HEADERS,snd=SENDING,failure=null),recv=HttpReceiverOverHTTP2@38d61d78(rsp=IDLE,failure=null)]}
SERVER.System.5.log:2020-03-07 07:57:58.723, .HTTP2Stream # Update close for HTTP2Stream@431675ea#4372853{sendWindow=62796,recvWindow=8388608,reset=false/false,LOCALLY_CLOSING,age=58,attachment=HttpChannelOverHTTP2@3c306f67(exchange=HttpExchange@4e915c28 req=PENDING/null@null res=PENDING/null@null)[send=HttpSenderOverHTTP2@434393ab(req=HEADERS,snd=SENDING,failure=null),recv=HttpReceiverOverHTTP2@38d61d78(rsp=IDLE,failure=null)]} update=true event=BEFORE_SEND
SERVER.System.5.log:2020-03-07 07:57:58.723, .HTTP2Flusher # Generated 2202 frame bytes for DataFrame@6ec3e832#4372853{length:2193,end=true}
SERVER.System.5.log:2020-03-07 07:57:58.724, .HTTP2Flusher # Writing 6 buffers (3595 bytes) - entries processed/pending 3/22: [DataFrame@73d18021#4372885{length:1377,end=true}, DataFrame@6ec3e832#4372853{length:2193,end=true}, HeadersFrame@40a78e9a#4372917{end=false}]/[DataFrame@73d18021#4372885{length:1377,end=true}, DataFrame@565eb385#4372883{length:2739,end=true}, DataFrame@748b478c#4372859{length:681,end=true}, DataFrame@56056713#4372887{length:2739,end=true}, DataFrame@8e59d39#4372889{length:2739,end=true}, DataFrame@6f0d674f#4372863{length:2685,end=true}, DataFrame@11f61a9#4372891{length:2739,end=true}, DataFrame@72fadc18#4372893{length:2739,end=true}, DataFrame@1322ac96#4372869{length:897,end=true}, DataFrame@42af17d3#4372895{length:2739,end=true}, DataFrame@180a85db#4372843{length:1497,end=true}, DataFrame@40722a51#4372897{length:2739,end=true}, DataFrame@161b8e7c#4372901{length:2739,end=true}, DataFrame@33b0d9b2#4372899{length:2739,end=true}, DataFrame@26183828#4372903{length:2739,end=true}, DataFrame@7b2b4fd2#4372905{length:2739,end=true}, DataFrame@1cc82c2c#4372913{length:2739,end=true}, DataFrame@202725db#4372907{length:2739,end=true}, DataFrame@5e394bba#4372911{length:2739,end=true}, DataFrame@17ca9619#4372909{length:2739,end=true}, DataFrame@884cd7d#4372881{length:2205,end=true}, DataFrame@10545ac8#4372915{length:2739,end=true}]
SERVER.System.5.log:2020-03-07 07:57:58.724, .HTTP2Session # Flushed 2202/2224 frame bytes for DataFrame@6ec3e832#4372853{length:0,end=true}

It seems that the time taken between sending the DataFrame and actually flushing it is too much.
Flushing time : 07:57:58.724
Sending time : 07:57:58.671

Difference : 53 ms

Is it the expected behavior or do I need to configure any buffers to reduce this time.

Thanks
Prateek

[sbordet]

Please report what Jetty version are you using. The logs you show are incomplete or important bits redacted out or you are using an old Jetty version.

[sbordet]

Very likely you are hitting the session flow control window.
The logs you reported are incomplete though, so difficult to tell.
Please report complete DEBUG logs.

[prateekkohli2112]

Thanks for the reply.

I have attached the logs for a complete stream and also the MBean attributes.

Stream_4372853_logs.txt

We can also see that the number of threads being used in HttpClient are only 2, rest of the threads are either in RUNNABLE state or TIMED_WAITING state. So I think we are unable to make jetty client use all its threads.

[prateekkohli2112]

Jetty Version : 9.4.24.v20191120

[sbordet]

@prateekkohli2112 you have not reported the full DEBUG logs, so it's difficult to say anything about what's going on. Don't remove lines from the logs or we will be unable to understand what's going on.
Also, you should really print out also the thread name or id to better understand what thread does what.

One log line that is present is the following:

SERVER.System.6.log:2020-03-07 07:57:58.693, FINER, module.Services.Logging - org.eclipse.jetty.http2.HTTP2Session # Generated DataFrame@6ec3e832#4372853{length:2193,end=true}, length/window/data=546/546/2739

It says that the session flow control window is down to only 546 bytes.

Also, this log line:

SERVER.System.6.log:2020-03-07 07:57:58.693, FINER, module.Services.Logging - org.eclipse.jetty.http2.FlowControlStrategy # Sending, stream send window 65535 -> 64989 for HTTP2Stream@431675ea#4372853{sendWindow=64989,recvWindow=8388608,reset=false/false,NOT_CLOSED,age=29,attachment=HttpChannelOverHTTP2@3c306f67(exchange=HttpExchange@4e915c28 req=PENDING/null@null res=PENDING/null@null)[send=HttpSenderOverHTTP2@434393ab(req=HEADERS,snd=SENDING,failure=null),recv=HttpReceiverOverHTTP2@38d61d78(rsp=IDLE,failure=null)]}

hints that the server told the client that the session flow control window is the default of 65535 bytes, which is really small.
What server is it? Jetty has a default of 1 MiB.
You need to configure the server with a larger session receive window if you want the client to send DATA frames faster.

In summary, the server is configured with a too small session flow control window, and it's not reading fast enough so the client is forced to slow down the send of DATA frames.

[prateekkohli2112]

We are using tomcat server.

We changed the session flow control window to 655350 bytes, but still there is no improvement.

I am attaching the full logs and tcpdump.

tcpdumps are taken on port 1091.

jettylogs.txt

tcpdump.zip

[sbordet]

We changed the session flow control window to 655350 bytes, but still there is no improvement.

What does that mean? No improvements in what exactly?

Are you taking into account pauses due to GC?
Maybe that's what's slowing down your client, not HTTP/2.

[sbordet]

From your latest logs I don't see any slow down sending DATA frames.
I do see occasional 100+ ms pauses, but I think those are due to GC.

[prateekkohli2112]

Below is our use case:

• We have one Java embedded tomcat Http2 server which receives an http2 request and that request is transmitted to the jetty http2 client.

• This jetty http2 client forwards the request to another embedded tomcat server and receives the response.

As the load on the 1st tomcat increases, we can observe a dip in the throughput.

We are investigating this issue and looking at the possible reasons of low throughput in jetty.

We are looking into tomcat as well, but wanted to know if jetty might be causing some back pressure.

[sbordet]

It's unlikely that Jetty will cause any throughput issue since its HTTP/2 implementation powers others projects that require a very high throughput that would have noticed immediately if there was a problem.

Have you tried Jetty as a server?

[prateekkohli2112]

Ours is a legacy application in which we have already used Tomcat server and cannot change.

We have kept the default values for Max requests queued per destination and max connections.

And we are creating a single client for all the traffic in jetty as per the HTTP2 RFC recommendation to keep only a single connection open with 1 host and port.

We have 1 more application in which we are creating multiple clients to the same destination and can observe very high throughput.

So, even though it is recommended to open a single connection per destination, have you observed any use cases in which creating multiple clients to a single destination is preferred for throughput efficiency.

[sbordet]

Single connection per destination is only good for browsers (maybe).

If you are writing a proxy, or a load test, etc. you don't want to use a single connection because you will be severely limited by the session flow control window.

Don't configure Jetty's HttpClient with maxConnectionsPerDestination=1.
Either leave the default (64) or set it to a larger value.

Always use just one HttpClient instance, just don't limit the number of connections too much.

[prateekkohli2112]

We have already kept 64 maxConnections and 1024 maxRequestsQueued per destination.

And we are using 1 HttpClient instance.

We have observed that as we increase the number of HttpClient instances, our throughput also increases.

[sbordet]

We have observed that as we increase the number of HttpClient instances, our throughput also increases.

This is strange. If that's the case, you have something configured wrongly.

We have used one HttpClient instance to send tens of thousands of requests/s without throughput issues, if not hundreds of thousands. Is your throughput greater?

[prateekkohli2112]

No, we are expecting around 10,000 only.

But the throughput which we are getting is only 2-3k.

[sbordet]

You have not given enough information to help you more, sorry.

What's the max_concurrent_streams that the Tomcats send to the clients?
Can you enable JMX for Jetty's HttpClient and actually report how many connections are actually opened?

[prateekkohli2112]

We have kept max_concurrent_streams as 200 and maxConnections have been changed to 100.

But I can see in the tcpdump that only 1 connection is made to the destination. I do not how will these connections increase.

Below is the HTTPClient JMX output:

[sbordet]

This is the HttpClient in the client, or the HttpClient in the proxy?

[sbordet]

The way connections are used in HTTP/2 is that one connection is opened and used until max_concurrent_streams is reached; after that, if another request is queued a new connection is opened, etc.

If your client is sending requests from a single thread sequentially, then only one connection will ever be opened (and only one stream will be active at a time).
If your client is sending requests but not waiting for responses, then depending on the send rate this may or may not exceed max_concurrent_streams. If it does not, only one connection will be used.

Jetty's HttpClient components such as destinations and connection pools are exported to JMX if you use Jetty JMX features - that will help figuring out what's going on in the system at runtime.
See https://github.com/eclipse/jetty.project/blob/jetty-9.4.27.v20200227/jetty-client/src/test/java/org/eclipse/jetty/client/jmx/HttpClientJMXTest.java#L46-L49

[prateekkohli2112]

I am attaching the JMX output below. Only 1 HttpConnection is made in our case as per the JMX output.

Also, we have observed that in jetty 9.4.8 version multiple connections were established at the start (i.e. it did not wait for the max_concurrent_streams to reach its max value) but only 1 of them was being used to sent the requests.

But in 9.4.24 version only 1 connection is established at the start and in our case no new connections are established. We are sending requests and waiting for the response.

[sbordet]

we have observed that in jetty 9.4.8 version multiple connections were established at the start

This was issue #2293 that we fixed.

We are sending requests and waiting for the response.

If you are waiting for the response before sending the next request, then you only ever have 1 outstanding request at a time, and therefore just 1 HTTP/2 stream, and therefore you will never open more than 1 connection because you will never reach max_concurrent_streams.
And if you are waiting for the response before sending the next request, you are not measuring throughput, you are just measuring latency.

[prateekkohli2112]

Due to our design constraint we are sending synchronous requests to jetty client using 50 threads.

Even if we use Jetty's asynchronous API we will have to use synchronous listeners in our design.
Do you still think will it improve the overall throughput.

[sbordet]

50 threads means at most 50 concurrent requests/streams.
Not enough to pass the max_concurrent_streams which you set at 200, so you will always have just 1 connection.

Do you still think will it improve the overall throughput.

You are not measuring throughput, but latency.

The number you are getting is not something that represents the throughput (as in max number of requests/s) of your system.

If you are interested, you can contact Webtide for commercial support, we do have lots of experience in load testing and in HTTP/2.

[prateekkohli2112]

Thanks for the help, will surely consider this.

Just 1 question, is it possible to open static connections to Http2 server, i.e. open 2-3 connections while creating the HttpClient object, before calling the request.send() method and use those connections to then send all the subsequent requests.

[prateekkohli2112]

I am using the below API:

HTTP2Client jettHttp2Client = new HTTP2Client();
SslContextFactory sslContextFactory = configureSSL(certificateLocation, certificatePassword,
endpointIdentification);

jettHttp2Client.setSelectors(1);
jettHttp2Client.setExecutor(new QueuedThreadPool(400));

HttpClientTransportOverHTTP2 httpClientTransportOverHTTP2 = new HttpClientTransportOverHTTP2(jettHttp2Client);
jettHttp2Client.start();

RetryJettyHttpClient jettyHttpClient;
HttpClient jettyHttpClient = new RetryJettyHttpClient(httpClientTransportOverHTTP2, sslContextFactory);

Is there any possibility I can open connections before sending the request and then send all the requests to these statically opened connections?

[sbordet]

There is a RoundRobinConnectionPool that you can use that will select connections using a round-robin algorithm.

HttpClientTransportOverHTTP2 httpClientTransportOverHTTP2 = new HttpClientTransportOverHTTP2(jettHttp2Client);
httpClientTransportOverHTTP2.setConnectionPoolFactory(destination -> new RoundRobinConnectionPool(destination, N, destination));

where N is the numbers of connections you want.
Note that this will always use a different connection for sequential requests - it may or may not be what you want.
There is also a risk that you are maxing out the connections and may spend time in the connection pool trying to find an available connection.

If your numbers improve with the RoundRobinConnectionPool then you probably have a HTTP/2 flow control issue.

[prateekkohli2112]

Thanks, but still it did not improve.

I have 1 different question.
Is there any way in which we can configure the max number of streams for a connection at client end.
So that after this stream count is exhausted a new connection is automatically established. I know maxConcurrentStreams is a server property. But is there any way I can just restrict the max stream Id count, so that the stream count get exhausted and a new connection is automatically established.

[sbordet]

Is there any way in which we can configure the max number of streams for a connection at client end.

I believe you are looking in the wrong place. Your initial problem was "slow" sending of DATA frame. From the DEBUG logs you provided, that was not the problem, or it was a GC issue, not a HTTP/2 issue.

You are complaining about a generic throughput problem, but I have yet to see a concrete issue about that. You are using a limited number of threads on the client, there is no information about the client configuration (thread pool sizing, etc.) and whether the client sends content to the server or not (which also would be flow controlled).
From the little information you gave, I think you are load testing in the wrong way.

There is currently no reliable way to configure the max multiplex number on the client side. You probably have to write your own ConnectionPool implementation, but I would not recommend that you go that way because I don't think that is the problem, especially after RoundRobinConnectionPool did not "improve" what you expect (and BTW it's not clear either how do you measure "improved").

Have you looked into Tomcat to see whether it's the problem? Or your application code in the proxy?

[prateekkohli2112]

Thanks for all the help.

We were able to increase the performance by setting the below logging parameters:
javaopt=-Dorg.eclipse.jetty.util.log.class=org.eclipse.jetty.util.log.StdErrLog
javaopt=-Dorg.eclipse.jetty.LEVEL=WARN

We were using the java util logging and thought disabling those would disable jetty logs as well.
Even though, jetty logs were not getting printed but in the thread dump we were able to see some threads blocked for debug logging in Jetty.

So we set the above logging parameters and our performance improved significantly.

[sbordet]

@prateekkohli2112 glad it's working for you. Feel free to close the issue if it's resolved for you.

[prateekkohli2112]

Sure, I have 1 small question other than this. (Not related to this query).

Is there any way I can close my connection after a certain stream count and open a new connection.
For e.g. if my sending stream Id has reached 100001 value, I would like to close this connection and reopen.

Is there any way I can achieve this, may be by setting the max streamId count or any othwer way you can suggest.

[sbordet]

@prateekkohli2112 there is no way to do this automatically right now.

This information is exported to JMX (Connection.messagesOut), but not easily available to applications.

Why do you need it?
By understanding better the use case, we may consider adding the feature if it's useful in general.

[prateekkohli2112]

Actually we are planning to have a L4 load balancer between Jetty client and HTTP server. The load balancer routes traffic based on established connections with the backend servers. Load balancer will maintain a mapping between a client connection and backend server connection. And every request from a particular client will be routed on a specific connection.

Now for dynamically scaling the backend servers, we would want that these client connections have a limited age. So to avoid starving a backend server of traffic.

We were thinking of doing this based on a limited number of streams on a single connection. And that's why need to set either the max number of local streams or an initial number from where stream IDs should start.

Also, we were able to reach the Integer max limit for number of streams for a connection. When the max range for Integer is reached we get an error for the 1 next request saying "java.lang.IllegalArgumentException: Invalid stream id: -2147483647"
After that request it works fine for all other requests again till the max range is achieved again and a new Connection is created.

[sbordet]

@prateekkohli2112 can you please open a new issue about this feature, i.e. set a max number of requests per connection.

[prateekkohli2112]

Raised below issue #4809 for setting max number of requests per connection:

#4809