"Bert Huijben" <b...@qqmail.nl> writes:
> Nice idea on the concept, but this patch doesn't implement that behavior
>
> You will see the first result very fast. (No behavior change)
I don't understand, I see a behaviour change when I try it.
The first few writes with my patch:
[pid 8814] writev(17, [{"HTTP/1.1 200 OK\r\nDate: Mon, 16 M"..., 189},
{"1f53\r\n", 6}, {"<?xml version=\"1.0\" encoding=\"ut"..., 7965},
{"<S:log-item>\n<D:version-name>166"..., 54}, {"\r\n", 2}], 5) = 8216
[pid 8814] writev(17, [{"1f55\r\n", 6},
{"<D:creator-displayname>rhuijben<"..., 7976},
{"<S:date>2015-02-14T00:17:25.9215"..., 45}, {"\r\n", 2}], 4) = 8029
[pid 8814] writev(17, [{"1f6d\r\n", 6},
{"</S:log-item>\n<S:log-item>\n<D:ve"..., 8000},
{"<S:date>2015-01-15T04:00:33.4982"..., 45}, {"\r\n", 2}], 4) = 8053
[pid 8814] writev(17, [{"1f4e\r\n", 6},
{"</S:log-item>\n<S:log-item>\n<D:ve"..., 7958},
{"<D:creator-displayname>rhuijben<"..., 56}, {"\r\n", 2}], 4) = 8022
[pid 8814] writev(17, [{"1f47\r\n", 6},
{"<S:date>2014-11-25T12:20:06.2266"..., 7953},
{"<S:log-item>\n<D:version-name>162"..., 54}, {"\r\n", 2}], 4) = 8015
[pid 8814] writev(17, [{"ba0\r\n", 5}, {"<D:creator-displayname>stsp</D:c"...,
2976}, {"\r\n", 2}], 3) = 2983
[pid 8814] writev(17, [{"1f52\r\n", 6},
{"<S:log-item>\n<D:version-name>161"..., 7973},
{"<S:date>2014-06-30T13:46:18.9128"..., 45}, {"\r\n", 2}], 4) = 8026
The current code without my patch:
[pid 9113] writev(17, [{"HTTP/1.1 200 OK\r\nDate: Mon, 16 M"..., 189},
{"fd\r\n", 4}, {"<?xml version=\"1.0\" encoding=\"ut"..., 253}, {"\r\n", 2}],
4) = 448
[pid 9113] writev(17, [{"a9\r\n", 4}, {"<S:log-item>\n<D:version-name>166"...,
169}, {"\r\n", 2}], 3) = 175
[pid 9113] writev(17, [{"14e\r\n", 5},
{"<S:log-item>\n<D:version-name>166"..., 334}, {"\r\n", 2}], 3) = 341
[pid 9113] writev(17, [{"294\r\n", 5},
{"<S:log-item>\n<D:version-name>166"..., 660}, {"\r\n", 2}], 3) = 667
[pid 9113] writev(17, [{"53a\r\n", 5},
{"<S:log-item>\n<D:version-name>166"..., 1338}, {"\r\n", 2}], 3) = 1345
[pid 9113] writev(17, [{"a7c\r\n", 5},
{"<S:log-item>\n<D:version-name>166"..., 2684}, {"\r\n", 2}], 3) = 2691
[pid 9113] writev(17, [{"1511\r\n", 6},
{"<S:log-item>\n<D:version-name>166"..., 5393}, {"\r\n", 2}], 3) = 5401
[pid 9113] writev(17, [{"1f46\r\n", 6},
{"<S:log-item>\n<D:version-name>166"..., 7951},
{"<D:creator-displayname>stefan2</"..., 55}, {"\r\n", 2}], 4) = 8014
[pid 9113] writev(17, [{"aba\r\n", 5}, {"<S:date>2015-02-13T10:00:18.5170"...,
2746}, {"\r\n", 2}], 3) = 2753
[pid 9113] writev(17, [{"1f61\r\n", 6},
{"<S:log-item>\n<D:version-name>165"..., 7988},
{"<S:date>2014-12-06T02:05:01.7811"..., 45}, {"\r\n", 2}], 4) = 8041
[pid 9113] writev(17, [{"1f60\r\n", 6},
{"</S:log-item>\n<S:log-item>\n<D:ve"..., 7976},
{"<D:creator-displayname>rhuijben<"..., 56}, {"\r\n", 2}], 4) = 8040
[pid 9113] writev(17, [{"153a\r\n", 6},
{"<S:date>2014-10-20T12:44:19.4131"..., 5434}, {"\r\n", 2}], 3) = 5442
> BTW 500 msec is about two or three the time you expect for google page of
> results.... Why this arbritrary number?
How do you explain the 2 and 2048 in the current code? They are all
just arbitrary numbers. Make it 100ms instead of 500ms. The trace
above is what I got for a debug build and 200ms. Several 8K writes in
the first 200ms followed by a short 3K write when the first extra flush
triggers after 200ms. That's a very fast server that doesn't need the
extra flushes.
If I introduce a delay into the log loop, 50ms between revisions, I see
more of the extra flushes:
[pid 9751] writev(17, [{"HTTP/1.1 200 OK\r\nDate: Mon, 16 M"..., 189},
{"588\r\n", 5}, {"<?xml version=\"1.0\" encoding=\"ut"..., 1416}, {"\r\n", 2}],
4) = 1612
[pid 9751] writev(17, [{"53a\r\n", 5},
{"<S:log-item>\n<D:version-name>166"..., 1338}, {"\r\n", 2}], 3) = 1345
[pid 9751] writev(17, [{"a7c\r\n", 5},
{"<S:log-item>\n<D:version-name>166"..., 2684}, {"\r\n", 2}], 3) = 2691
[pid 9751] writev(17, [{"1511\r\n", 6},
{"<S:log-item>\n<D:version-name>166"..., 5393}, {"\r\n", 2}], 3) = 5401
[pid 9751] writev(17, [{"1f46\r\n", 6},
{"<S:log-item>\n<D:version-name>166"..., 7951},
{"<D:creator-displayname>stefan2</"..., 55}, {"\r\n", 2}], 4) = 8014
[pid 9751] writev(17, [{"aba\r\n", 5}, {"<S:date>2015-02-13T10:00:18.5170"...,
2746}, {"\r\n", 2}], 3) = 2753
[pid 9751] writev(17, [{"1f61\r\n", 6},
{"<S:log-item>\n<D:version-name>165"..., 7988},
{"<S:date>2014-12-06T02:05:01.7811"..., 45}, {"\r\n", 2}], 4) = 8041
[pid 9751] writev(17, [{"1f60\r\n", 6},
{"</S:log-item>\n<S:log-item>\n<D:ve"..., 7976},
{"<D:creator-displayname>rhuijben<"..., 56}, {"\r\n", 2}], 4) = 8040
[pid 9751] writev(17, [{"153a\r\n", 6},
{"<S:date>2014-10-20T12:44:19.4131"..., 5434}, {"\r\n", 2}], 3) = 5442
[pid 9751] writev(17, [{"1f52\r\n", 6},
{"<S:log-item>\n<D:version-name>161"..., 7973},
{"<S:date>2014-06-30T13:46:18.9128"..., 45}, {"\r\n", 2}], 4) = 8026
The first flush happens after 8 revisions because the first 4 revisions
all get written within the first 200ms. The 8th revision is the first
flush after 200ms.
I'm not claiming this is the best algorithm, I just want to know if it
is the sort of thing we want.
--
Philip Martin | Subversion Committer
WANdisco // *Non-Stop Data*
