Source code

Revision control

Copy as Markdown

Other Tools

Test Info:

/* This Source Code Form is subject to the terms of the Mozilla Public
* License, v. 2.0. If a copy of the MPL was not distributed with this
* file, You can obtain one at http://mozilla.org/MPL/2.0/. */
// Two things a consumer of nsITimedChannel and the activity distributor relies
// on, for bug 2067308:
//
// * nsHttpTransaction::Restart clears mTimings, so what the channel reports
// describes the attempt that served the request. Nothing else clears it for
// a retry re-dispatched onto an established connection, since
// nsHttpConnection::Activate only bootstraps a connection's first
// transaction.
// * a response is reported complete even when its length is signalled only by
// the stream end, which is how HTTP/2 delivers a response with no
// content-length.
"use strict";
const { NodeHTTPSServer, NodeHTTP2Server } = ChromeUtils.importESModule(
);
const { TestUtils } = ChromeUtils.importESModule(
);
let server;
let h2Server;
add_setup(async function () {
let certdb = Cc["@mozilla.org/security/x509certdb;1"].getService(
Ci.nsIX509CertDB
);
addCertFromFile(certdb, "http2-ca.pem", "CTu,u,u");
Services.prefs.setCharPref("network.dns.localDomains", "foo.example.com");
server = new NodeHTTPSServer();
await server.start();
// Holds its connection open until /drop-pooled releases it.
await server.registerPathHandler("/hold", (req, resp) => {
global.heldResponse = resp;
});
// Occupies a second connection while /hold has the first. Releases /hold so
// that connection goes idle, then drops this one unanswered, so the retry has
// an established connection to be re-dispatched onto.
await server.registerPathHandler("/drop-pooled", (req, resp) => {
if (global.droppedPooled) {
resp.writeHead(200, { "Content-Type": "text/plain" });
resp.end("ok");
return;
}
global.droppedPooled = true;
// These run in the node server, not in Gecko.
/* eslint-disable mozilla/no-arbitrary-setTimeout */
setTimeout(() => {
if (global.heldResponse) {
global.heldResponse.writeHead(200, { "Content-Type": "text/plain" });
global.heldResponse.end("held");
global.heldResponse = null;
}
setTimeout(() => resp.socket.destroy(), 200);
}, 300);
/* eslint-enable mozilla/no-arbitrary-setTimeout */
});
h2Server = new NodeHTTP2Server();
await h2Server.start();
await h2Server.registerPathHandler("/unsized", (req, resp) => {
resp.writeHead(200, { "Content-Type": "text/plain" });
resp.end("ok");
});
await h2Server.registerPathHandler("/sized", (req, resp) => {
resp.writeHead(200, {
"Content-Type": "text/plain",
"Content-Length": "2",
});
resp.end("ok");
});
registerCleanupFunction(async () => {
Services.prefs.clearUserPref("network.dns.localDomains");
await server?.stop();
await h2Server?.stop();
});
});
// The channel is needed alongside its response, to read nsITimedChannel off it.
function openChannel(uri) {
const chan = makeChan(uri);
return { chan, done: channelOpenPromise(chan, CL_ALLOW_UNKNOWN_CL) };
}
// Collects the HTTP transaction activity reported for one channel, waiting for
// `until` rather than guessing how long the marshalling to the main thread takes.
async function transactionActivity(uri, until) {
let sequence = [];
let distributor = Cc[
"@mozilla.org/network/http-activity-distributor;1"
].getService(Ci.nsIHttpActivityDistributor);
let observer = {
observeActivity(aChannel, aActivityType, aActivitySubtype) {
if (
aActivityType !==
Ci.nsIHttpActivityObserver.ACTIVITY_TYPE_HTTP_TRANSACTION
) {
return;
}
try {
if (aChannel.QueryInterface(Ci.nsIChannel).URI.spec === uri) {
sequence.push(aActivitySubtype);
}
} catch (e) {}
},
};
distributor.addObserver(observer);
try {
const { done } = openChannel(uri);
await done;
// The notifications are marshalled to the main thread, so some are still in
// flight when onStopRequest runs.
await TestUtils.waitForCondition(
() => sequence.includes(until),
`activity subtype ${until} was reported`
);
} finally {
// Left registered, it would keep filling a dead array and turn one failure
// into a cascade over the remaining tasks.
distributor.removeObserver(observer);
}
return sequence;
}
add_task(async function test_restart_onto_pooled_connection_clears_timings() {
const held = openChannel(
`https://foo.example.com:${server.port()}/hold`
).done;
// /drop-pooled only has a connection to hand over once /hold owns one, so wait
// for the server to say so rather than racing its timer.
await TestUtils.waitForCondition(
async () => (await server.execute("!!global.heldResponse")) === true,
"/hold is occupying a connection"
);
// The failed attempt connects as soon as this is opened; /drop-pooled releases
// /hold and drops it 500ms later, so anything the serving attempt stamps has
// to postdate that. Microseconds, to compare against PRTime.
const openedAt = Date.now() * 1000;
const AFTER_DROP_US = 400_000;
const { chan, done } = openChannel(
`https://foo.example.com:${server.port()}/drop-pooled`
);
const timedChannel = chan.QueryInterface(Ci.nsITimedChannel);
const [, buffer] = await done;
await held;
info(
`connectStart=${timedChannel.connectStartTime} ` +
`domainLookupStart=${timedChannel.domainLookupStartTime} ` +
`requestStart=${timedChannel.requestStartTime}`
);
Assert.equal(buffer, "ok", "the retried request succeeded");
// Proves a restart happened at all, so the checks below cannot pass simply
// because nothing was ever stamped: only a retry can send after the drop.
Assert.greaterOrEqual(
timedChannel.requestStartTime,
openedAt + AFTER_DROP_US,
`requestStart (${timedChannel.requestStartTime}) is the retry's, not the ` +
`failed attempt's`
);
// Zero when the retry was re-dispatched onto the connection /hold released,
// and so resolved and connected nothing. A stamp of its own is fine too - the
// connection manager is free to open a fresh one - as long as it is not the
// failed attempt's, which is the regression this guards.
for (const field of ["connectStartTime", "domainLookupStartTime"]) {
const value = timedChannel[field];
Assert.ok(
value === 0 || value >= openedAt + AFTER_DROP_US,
`${field} (${value}) is not left over from the failed attempt, ` +
`which connected around ${openedAt} and was dropped 500ms later`
);
}
});
add_task(async function test_response_complete_without_content_length() {
// HTTP/2 marks a response complete from the stream end. Without a
// content-length, HandleContent never reaches its end-of-file branch and Close
// finds the response already complete, so nothing reported it and consumers
// had no receive phase for these responses.
const COMPLETE =
Ci.nsIHttpActivityObserver.ACTIVITY_SUBTYPE_RESPONSE_COMPLETE;
for (const [path, label] of [
["/unsized", "no content-length"],
["/sized", "with content-length"],
]) {
// Waits for the terminal notification, so a duplicate RESPONSE_COMPLETE
// would have arrived by the time the count below is taken.
const sequence = await transactionActivity(
`https://foo.example.com:${h2Server.port()}${path}`,
Ci.nsIHttpActivityObserver.ACTIVITY_SUBTYPE_TRANSACTION_CLOSE
);
info(`${label}: ${sequence.join(",")}`);
Assert.equal(
sequence.filter(subtype => subtype === COMPLETE).length,
1,
`${label}: the response is reported complete exactly once`
);
}
});