Bug 1733481 retry telemetry requests when a proxy fails r=chutten,robwu,necko-reviewers,valentin

Differential Revision: https://phabricator.services.mozilla.com/D127170
This commit is contained in:
Shane Caraveo 2021-10-27 16:16:50 +00:00
Родитель 7aae3ff478
Коммит b683ebea88
11 изменённых файлов: 524 добавлений и 88 удалений

Просмотреть файл

@ -9584,6 +9584,13 @@
mirror: always
#endif
# Whether to allow a bypass flag to be set on httpChannel that will
# prevent proxies from being used for that specific request.
- name: network.proxy.allow_bypass
type: bool
value: true
mirror: always
- name: network.proxy.parse_pac_on_socket_process
type: RelaxedAtomicBool
value: false

Просмотреть файл

@ -27,6 +27,7 @@
#include "mozilla/Components.h"
#include "mozilla/StaticPrefs_browser.h"
#include "mozilla/StaticPrefs_fission.h"
#include "mozilla/StaticPrefs_network.h"
#include "mozilla/StaticPrefs_security.h"
#include "mozilla/Telemetry.h"
#include "mozilla/Tokenizer.h"
@ -3355,17 +3356,26 @@ HttpBaseChannel::SetBeConservative(bool aBeConservative) {
return NS_OK;
}
bool HttpBaseChannel::BypassProxy() {
return StaticPrefs::network_proxy_allow_bypass() && LoadBypassProxy();
}
NS_IMETHODIMP
HttpBaseChannel::GetBypassProxy(bool* aBypassProxy) {
NS_ENSURE_ARG_POINTER(aBypassProxy);
*aBypassProxy = LoadBypassProxy();
*aBypassProxy = BypassProxy();
return NS_OK;
}
NS_IMETHODIMP
HttpBaseChannel::SetBypassProxy(bool aBypassProxy) {
StoreBypassProxy(aBypassProxy);
if (StaticPrefs::network_proxy_allow_bypass()) {
StoreBypassProxy(aBypassProxy);
} else {
NS_WARNING("bypassProxy set but network.proxy.allow_bypass is disabled");
return NS_ERROR_FAILURE;
}
return NS_OK;
}

Просмотреть файл

@ -274,6 +274,8 @@ class HttpBaseChannel : public nsHashPropertyBag,
NS_IMETHOD SetBeConservative(bool aBeConservative) override;
NS_IMETHOD GetBypassProxy(bool* aBypassProxy) override;
NS_IMETHOD SetBypassProxy(bool aBypassProxy) override;
bool BypassProxy();
NS_IMETHOD GetIsTRRServiceChannel(bool* aTRR) override;
NS_IMETHOD SetIsTRRServiceChannel(bool aTRR) override;
NS_IMETHOD GetIsResolvedByTRR(bool* aResolvedByTRR) override;

Просмотреть файл

@ -2151,7 +2151,7 @@ nsresult HttpChannelChild::ContinueAsyncOpen() {
openArgs.allowHttp3() = LoadAllowHttp3();
openArgs.allowAltSvc() = LoadAllowAltSvc();
openArgs.beConservative() = LoadBeConservative();
openArgs.bypassProxy() = LoadBypassProxy();
openArgs.bypassProxy() = BypassProxy();
openArgs.tlsFlags() = mTlsFlags;
openArgs.initialRwin() = mInitialRwin;

Просмотреть файл

@ -5925,7 +5925,7 @@ void nsHttpChannel::MaybeResolveProxyAndBeginConnect() {
// settings if we are never going to make a network connection.
if (!mProxyInfo &&
!(mLoadFlags & (LOAD_ONLY_FROM_CACHE | LOAD_NO_NETWORK_IO)) &&
!LoadBypassProxy() && NS_SUCCEEDED(ResolveProxy())) {
!BypassProxy() && NS_SUCCEEDED(ResolveProxy())) {
return;
}

Просмотреть файл

@ -3013,3 +3013,24 @@ memory_watcher:
bug_numbers: [1715858]
notification_emails:
- tkikuchi@mozilla.com
service_request:
bypass:
description: >
This event is recorded by a small set of services when a proxy failure
causes a service to re-request with a proxy bypass. It records some
basic information such as the type of proxy configuration, and the source
of the proxy configuration. The value of the event is the name of the
service that triggers the event (e.g. telemetry, remote-settings).
methods: ["bypass"]
objects: ["proxy_info"]
release_channel_collection: opt-out
expiry_version: never
record_in_processes: ["main"]
products: ["firefox"]
bug_numbers: [1732792, 1732793, 1733481, 1733994, 1732388]
notification_emails:
- scaraveo@mozilla.com
extra_keys:
source: the source of the proxy configuration. e.g. policy, prefs or extension_id
type: the type for the proxy configuration source. e.g. api or string version of nsIProtocolProxyService.proxyConfigType

Просмотреть файл

@ -1308,6 +1308,73 @@ var TelemetrySendImpl = {
return "/submit/telemetry/" + slug;
},
_doPingRequest(ping, id, url, options, errorHandler, onloadHandler) {
// Don't send cookies with these requests.
let request = new ServiceRequest({ mozAnon: true });
request.mozBackgroundRequest = true;
request.timeout = Policy.pingSubmissionTimeout();
request.open("POST", url, options);
request.overrideMimeType("text/plain");
request.setRequestHeader("Content-Type", "application/json; charset=UTF-8");
request.setRequestHeader("Date", Policy.now().toUTCString());
request.setRequestHeader("Content-Encoding", "gzip");
request.onerror = errorHandler;
request.ontimeout = errorHandler;
request.onabort = errorHandler;
request.onload = onloadHandler;
this._pendingPingRequests.set(id, request);
let startTime = Utils.monotonicNow();
// If that's a legacy ping format, just send its payload.
let networkPayload = isV4PingFormat(ping) ? ping : ping.payload;
let converter = Cc[
"@mozilla.org/intl/scriptableunicodeconverter"
].createInstance(Ci.nsIScriptableUnicodeConverter);
converter.charset = "UTF-8";
let utf8Payload = converter.ConvertFromUnicode(
JSON.stringify(networkPayload)
);
utf8Payload += converter.Finish();
Services.telemetry
.getHistogramById("TELEMETRY_STRINGIFY")
.add(Utils.monotonicNow() - startTime);
let payloadStream = Cc[
"@mozilla.org/io/string-input-stream;1"
].createInstance(Ci.nsIStringInputStream);
startTime = Utils.monotonicNow();
payloadStream.data = Policy.gzipCompressString(utf8Payload);
// Check the size and drop pings which are too big.
const compressedPingSizeBytes = payloadStream.data.length;
if (compressedPingSizeBytes > TelemetryStorage.MAXIMUM_PING_SIZE) {
this._log.error(
"_doPing - submitted ping exceeds the size limit, size: " +
compressedPingSizeBytes
);
Services.telemetry
.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_SEND")
.add();
Services.telemetry
.getHistogramById("TELEMETRY_DISCARDED_SEND_PINGS_SIZE_MB")
.add(Math.floor(compressedPingSizeBytes / 1024 / 1024));
// We don't need to call |request.abort()| as it was not sent yet.
this._pendingPingRequests.delete(id);
TelemetryHealthPing.recordDiscardedPing(ping.type);
return { promise: TelemetryStorage.removePendingPing(id) };
}
Services.telemetry
.getHistogramById("TELEMETRY_COMPRESS")
.add(Utils.monotonicNow() - startTime);
request.sendInputStream(payloadStream);
return { payloadStream };
},
_doPing(ping, id, isPersisted) {
if (!this.sendingEnabled(ping)) {
// We can't send the pings to the server, so don't try to.
@ -1338,18 +1405,6 @@ var TelemetrySendImpl = {
const url = this._buildSubmissionURL(ping);
// Don't send cookies with these requests.
let request = new ServiceRequest({ mozAnon: true });
request.mozBackgroundRequest = true;
request.timeout = Policy.pingSubmissionTimeout();
request.open("POST", url, true);
request.overrideMimeType("text/plain");
request.setRequestHeader("Content-Type", "application/json; charset=UTF-8");
request.setRequestHeader("Date", Policy.now().toUTCString());
this._pendingPingRequests.set(id, request);
const monotonicStartTime = Utils.monotonicNow();
let deferred = PromiseUtils.defer();
@ -1379,7 +1434,36 @@ var TelemetrySendImpl = {
);
};
let errorhandler = event => {
let retryRequest = request => {
if (
!request.bypassProxyEnabled ||
this._tooLateToSend ||
request.bypassProxy ||
!request.isProxied
) {
return false;
}
ServiceRequest.logProxySource(request.channel, "telemetry.send");
// If the request failed, and it's using a proxy, automatically
// attempt without proxy.
let { payloadStream } = this._doPingRequest(
ping,
id,
url,
{ bypassProxy: true },
errorHandler,
onloadHandler
);
this.payloadStream = payloadStream;
return true;
};
let errorHandler = event => {
let request = event.target;
if (retryRequest(request)) {
return;
}
let failure = event.type;
if (failure === "error") {
failure = XHR_ERROR_TYPE[request.errorCode];
@ -1387,23 +1471,6 @@ var TelemetrySendImpl = {
TelemetryHealthPing.recordSendFailure(failure);
if (this.fallbackHttp) {
// only one attempt
this.fallbackHttp = false;
request.channel.securityInfo
.QueryInterface(Ci.nsITransportSecurityInfo)
.QueryInterface(Ci.nsISerializable);
if (request.channel.securityInfo.errorCodeString.startsWith("SEC_")) {
// re-open the request with the HTTP version of the URL
let fallbackUrl = new URL(url);
fallbackUrl.protocol = "http:";
// TODO encrypt payload
request.open("POST", fallbackUrl, true);
request.sendInputStream(this.payloadStream);
}
}
Services.telemetry
.getHistogramById("TELEMETRY_SEND_FAILURE_TYPE")
.add(failure);
@ -1416,11 +1483,9 @@ var TelemetrySendImpl = {
);
onRequestFinished(false, event);
};
request.onerror = errorhandler;
request.ontimeout = errorhandler;
request.onabort = errorhandler;
request.onload = event => {
let onloadHandler = event => {
let request = event.target;
let status = request.status;
let statusClass = status - (status % 100);
let success = false;
@ -1464,57 +1529,24 @@ var TelemetrySendImpl = {
event.type
);
}
if (!success && retryRequest(request)) {
return;
}
onRequestFinished(success, event);
};
// If that's a legacy ping format, just send its payload.
let networkPayload = isV4PingFormat(ping) ? ping : ping.payload;
request.setRequestHeader("Content-Encoding", "gzip");
let converter = Cc[
"@mozilla.org/intl/scriptableunicodeconverter"
].createInstance(Ci.nsIScriptableUnicodeConverter);
converter.charset = "UTF-8";
let startTime = Utils.monotonicNow();
let utf8Payload = converter.ConvertFromUnicode(
JSON.stringify(networkPayload)
let { payloadStream, promise } = this._doPingRequest(
ping,
id,
url,
{},
errorHandler,
onloadHandler
);
utf8Payload += converter.Finish();
Services.telemetry
.getHistogramById("TELEMETRY_STRINGIFY")
.add(Utils.monotonicNow() - startTime);
let payloadStream = Cc[
"@mozilla.org/io/string-input-stream;1"
].createInstance(Ci.nsIStringInputStream);
startTime = Utils.monotonicNow();
payloadStream.data = Policy.gzipCompressString(utf8Payload);
// Check the size and drop pings which are too big.
const compressedPingSizeBytes = payloadStream.data.length;
if (compressedPingSizeBytes > TelemetryStorage.MAXIMUM_PING_SIZE) {
this._log.error(
"_doPing - submitted ping exceeds the size limit, size: " +
compressedPingSizeBytes
);
Services.telemetry
.getHistogramById("TELEMETRY_PING_SIZE_EXCEEDED_SEND")
.add();
Services.telemetry
.getHistogramById("TELEMETRY_DISCARDED_SEND_PINGS_SIZE_MB")
.add(Math.floor(compressedPingSizeBytes / 1024 / 1024));
// We don't need to call |request.abort()| as it was not sent yet.
this._pendingPingRequests.delete(id);
TelemetryHealthPing.recordDiscardedPing(ping.type);
return TelemetryStorage.removePendingPing(id);
if (promise) {
return promise;
}
Services.telemetry
.getHistogramById("TELEMETRY_COMPRESS")
.add(Utils.monotonicNow() - startTime);
request.sendInputStream(payloadStream);
this.payloadStream = payloadStream;
return deferred.promise;

Просмотреть файл

@ -52,6 +52,10 @@ const PingServer = {
return this._httpServer.identity.primaryPort;
},
get host() {
return this._httpServer.identity.primaryHost;
},
get started() {
return this._started;
},

Просмотреть файл

@ -0,0 +1,258 @@
/* -*- Mode: indent-tabs-mode: nil; js-indent-level: 2 -*- */
/* vim: set sts=2 sw=2 et tw=80: */
"use strict";
const { NetUtil } = ChromeUtils.import("resource://gre/modules/NetUtil.jsm");
const { Services } = ChromeUtils.import("resource://gre/modules/Services.jsm");
const { HttpServer } = ChromeUtils.import("resource://testing-common/httpd.js");
const { TelemetryUtils } = ChromeUtils.import(
"resource://gre/modules/TelemetryUtils.jsm"
);
Services.prefs.setBoolPref("network.dns.native-is-localhost", true);
const TELEMETRY_HOST = "telemetry.mochi.test";
// Trigger a proper telemetry init.
do_get_profile(true);
AddonTestUtils.init(this);
AddonTestUtils.overrideCertDB();
AddonTestUtils.createAppInfo(
"xpcshell@tests.mozilla.org",
"XPCShell",
"42",
"42"
);
// setup and configure a proxy server that will just deny connections.
const proxy = AddonTestUtils.createHttpServer();
proxy.registerPrefixHandler("/", (request, response) => {
response.setStatusLine(request.httpVersion, 504, "hello proxy user");
response.write("ok!");
});
// Register a proxy to be used by TCPSocket connections later.
let proxy_info;
function getBadProxyPort() {
let server = new HttpServer();
server.start(-1);
const badPort = server.identity.primaryPort;
server.stop();
return badPort;
}
function registerProxy() {
let pps = Cc["@mozilla.org/network/protocol-proxy-service;1"].getService(
Ci.nsIProtocolProxyService
);
const proxyFilter = {
applyFilter(uri, defaultProxyInfo, callback) {
if (
proxy_info &&
uri.host == PingServer.host &&
uri.port == PingServer.port
) {
let proxyInfo = pps.newProxyInfo(
proxy_info.type,
proxy_info.host,
proxy_info.port,
"",
"",
0,
4096,
null
);
proxyInfo.sourceId = proxy_info.sourceId;
callback.onProxyFilterResult(proxyInfo);
} else {
callback.onProxyFilterResult(defaultProxyInfo);
}
},
};
pps.registerFilter(proxyFilter, 0);
registerCleanupFunction(() => {
pps.unregisterFilter(proxyFilter);
});
}
add_task(async function setup() {
fakeIntlReady();
// Make sure we don't generate unexpected pings due to pref changes.
await setEmptyPrefWatchlist();
Services.prefs.setBoolPref(
TelemetryUtils.Preferences.HealthPingEnabled,
false
);
TelemetryStopwatch.setTestModeEnabled(true);
registerProxy();
PingServer.start();
// accept proxy connections for PingServer
proxy.identity.add("http", PingServer.host, PingServer.port);
await TelemetrySend.setup(true);
TelemetrySend.setTestModeEnabled(true);
TelemetrySend.setServer(`http://localhost:${PingServer.port}`);
});
function checkEvent() {
// ServiceRequest should have recorded an event for this.
let expected = [
"service_request",
"bypass",
"proxy_info",
"telemetry.send",
{
source: proxy_info.sourceId,
type: "api",
},
];
let snapshot = Telemetry.snapshotEvents(
Ci.nsITelemetry.DATASET_ALL_CHANNELS,
false
);
let received = snapshot.parent[0];
received.shift();
Assert.deepEqual(
expected,
received,
`retry telemetry data matched ${JSON.stringify(received)}`
);
Telemetry.clearEvents();
}
async function submitPingWithDate(date, expected) {
fakeNow(new Date(date));
let pingId = await TelemetryController.submitExternalPing(
"test-send-date-header",
{}
);
let req = await PingServer.promiseNextRequest();
let ping = decodeRequestPayload(req);
Assert.equal(
req.getHeader("Date"),
expected,
"Telemetry should send the correct Date header with requests."
);
Assert.equal(ping.id, pingId, "Should have received the correct ping id.");
}
// While there is no specific indiction, this test causes the
// telemetrySend doPing onload handler to be invoked.
add_task(async function test_failed_server() {
proxy_info = {
type: "http",
host: proxy.identity.primaryHost,
port: proxy.identity.primaryPort,
sourceId: "failed_server_test",
};
await TelemetrySend.reset();
await submitPingWithDate(
Date.UTC(2011, 1, 1, 11, 0, 0),
"Tue, 01 Feb 2011 11:00:00 GMT"
);
checkEvent();
});
// While there is no specific indiction, this test causes the
// telemetrySend doPing error handler to be invoked.
add_task(async function test_no_server() {
// Make sure the underlying proxy failover is disabled to easily force
// telemetry to retry the request.
Services.prefs.setBoolPref("network.proxy.failover_direct", false);
proxy_info = {
type: "http",
host: "localhost",
port: getBadProxyPort(),
sourceId: "no_server_test",
};
await TelemetrySend.reset();
await submitPingWithDate(
Date.UTC(2012, 1, 1, 11, 0, 0),
"Wed, 01 Feb 2012 11:00:00 GMT"
);
checkEvent();
});
// Mock out the send timer activity.
function waitForTimer() {
return new Promise(resolve => {
fakePingSendTimer(
(callback, timeout) => {
resolve([callback, timeout]);
},
() => {}
);
});
}
add_task(async function test_no_bypass() {
// Make sure the underlying proxy failover is disabled to easily force
// telemetry to retry the request.
Services.prefs.setBoolPref("network.proxy.failover_direct", false);
// Disable the retry and submit again.
Services.prefs.setBoolPref("network.proxy.allow_bypass", false);
proxy_info = {
type: "http",
host: "localhost",
port: getBadProxyPort(),
sourceId: "no_server_test",
};
await TelemetrySend.reset();
fakeNow(new Date(Date.UTC(2013, 1, 1, 11, 0, 0)));
let timerPromise = waitForTimer();
let pingId = await TelemetryController.submitExternalPing(
"test-send-date-header",
{}
);
let [pingSendTimerCallback] = await timerPromise;
Assert.ok(!!pingSendTimerCallback, "Should have a timer callback");
Assert.equal(
TelemetrySend.pendingPingCount,
1,
"Should have correct pending ping count"
);
// Reset the proxy, trigger the next tick - we should receive the ping.
proxy_info = null;
pingSendTimerCallback();
let req = await PingServer.promiseNextRequest();
let ping = decodeRequestPayload(req);
// PingServer finished before telemetry, so make sure it's done.
await TelemetrySend.testWaitOnOutgoingPings();
Assert.equal(
req.getHeader("Date"),
"Fri, 01 Feb 2013 11:00:00 GMT",
"Telemetry should send the correct Date header with requests."
);
Assert.equal(ping.id, pingId, "Should have received the correct ping id.");
// reset to save any pending pings
Assert.equal(
TelemetrySend.pendingPingCount,
0,
"Should not have any pending pings"
);
await TelemetrySend.reset();
PingServer.stop();
});

Просмотреть файл

@ -106,3 +106,5 @@ tags = coverage
[test_bug1555798.js]
[test_UninstallPing.js]
run-if = os == 'win'
[test_failover_retry.js]
skip-if = os == "android" # Android doesn't support telemetry though some tests manage to pass with xpcshell

Просмотреть файл

@ -9,17 +9,94 @@
* can be set, Telemetry collected, etc. in a central place.
*/
const { Log } = ChromeUtils.import("resource://gre/modules/Log.jsm");
const { Services } = ChromeUtils.import("resource://gre/modules/Services.jsm");
const { XPCOMUtils } = ChromeUtils.import(
"resource://gre/modules/XPCOMUtils.jsm"
);
XPCOMUtils.defineLazyGlobalGetters(this, ["XMLHttpRequest"]);
XPCOMUtils.defineLazyServiceGetter(
this,
"ProxyService",
"@mozilla.org/network/protocol-proxy-service;1",
"nsIProtocolProxyService"
);
XPCOMUtils.defineLazyModuleGetters(this, {
ExtensionPreferencesManager:
"resource://gre/modules/ExtensionPreferencesManager.jsm",
});
var EXPORTED_SYMBOLS = ["ServiceRequest"];
const logger = Log.repository.getLogger("ServiceRequest");
logger.level = Log.Level.Debug;
logger.addAppender(new Log.ConsoleAppender(new Log.BasicFormatter()));
const PROXY_CONFIG_TYPES = [
"direct",
"manual",
"pac",
"unused", // nsIProtocolProxyService.idl skips index 3.
"wpad",
"system",
];
function recordEvent(service, source = {}) {
try {
Services.telemetry.setEventRecordingEnabled("service_request", true);
Services.telemetry.recordEvent(
"service_request",
"bypass",
"proxy_info",
service,
source
);
} catch (err) {
// If the telemetry throws just log the error so it doesn't break any
// functionality.
Cu.reportError(err);
}
}
// If proxy.settings is used to change the proxy, an extension will
// be "in control". This returns the id of that extension.
async function getControllingExtension() {
if (
!WebExtensionPolicy.getActiveExtensions().some(p =>
p.permissions.includes("proxy")
)
) {
return undefined;
}
// Is this proxied by an extension that set proxy prefs?
let setting = await ExtensionPreferencesManager.getSetting("proxy.settings");
return setting?.id;
}
async function getProxySource(proxyInfo) {
// sourceId is set when using proxy.onRequest
if (proxyInfo.sourceId) {
return {
source: proxyInfo.sourceId,
type: "api",
};
}
let type = PROXY_CONFIG_TYPES[ProxyService.proxyConfigType] || "unknown";
// If we have a policy it will have set the prefs.
if (Services.policies.status === Services.policies.ACTIVE) {
let policies = Services.policies.getActivePolicies()?.filter(p => p.Proxy);
if (policies?.length) {
return {
source: "policy",
type,
};
}
}
let source = await getControllingExtension();
return {
source: source || "prefs",
type,
};
}
/**
* ServiceRequest is intended to be a drop-in replacement for current users
@ -47,7 +124,30 @@ class ServiceRequest extends XMLHttpRequest {
// Disable cutting edge features, like TLS 1.3, where middleboxes might brick us
internal.beConservative = true;
// Disable use of proxy for this request if necessary.
internal.bypassProxy = options?.bypassProxy;
if (options?.bypassProxy && this.bypassProxyEnabled) {
internal.bypassProxy = this.bypassProxyEnabled;
}
}
}
get bypassProxy() {
let { channel } = this;
return channel.QueryInterface(Ci.nsIHttpChannelInternal).bypassProxy;
}
get isProxied() {
let { channel } = this;
return !!(channel instanceof Ci.nsIProxiedChannel && channel.proxyInfo);
}
get bypassProxyEnabled() {
return Services.prefs.getBoolPref("network.proxy.allow_bypass", true);
}
static async logProxySource(channel, service) {
if (channel.proxyInfo) {
let source = await getProxySource(channel.proxyInfo);
recordEvent(service, source);
}
}
}