diff options
Diffstat (limited to 'netwerk/docs/http')
| -rw-r--r-- | netwerk/docs/http/http3.md | 154 | ||||
| -rw-r--r-- | netwerk/docs/http/lifecycle.rst | 220 | ||||
| -rw-r--r-- | netwerk/docs/http/logging.rst | 320 |
3 files changed, 694 insertions, 0 deletions
diff --git a/netwerk/docs/http/http3.md b/netwerk/docs/http/http3.md new file mode 100644 index 0000000000..9881421d57 --- /dev/null +++ b/netwerk/docs/http/http3.md @@ -0,0 +1,154 @@ +# Http3Session and streams + +The HTTP/3 and QUIC protocol are implemented in the neqo library. Http3Session, Http3Steam, and Http3WebTransportStream are added to integrate the library into the existing necko code. + +The following classes are necessary: +- HttpConnectionUDP - this is the object that is registered in nsHttpConnectionMgr and it is also used as an async listener to socket events (it implements nsIUDPSocketSyncListener) +- nsUDPSocket - represent a UDP socket and implements nsASocketHandler. nsSocketTransportService manages UDP and TCP sockets and calls the corresponding nsASocketHandler when the socket encounters an error or has data to be read, etc. +- NeqoHttp3Conn is a c++ object that maps to the rust object Http3Client. +- Http3Session manages NeqoHttp3Conn/Http3Client and provides bridge between the rust implementation and necko legacy code, i.e. HttpConnectionUDP and nsHttpTransaction. +- Http3Streams are used to map reading and writing from/into a nsHttpTransaction onto the NeqoHttp3Conn/Http3Client API (e.g. nsHttpTransaction::OnWriteSegment will call Http3Client::read_data). NeqoHttp3Conn is only accessed by Http3Sesson and NeqoHttp3Conn functions are exposed through Http3Session where needed. + +```{mermaid} +graph TD + A[HttpConnectionMgr] --> B[HttpConnectionUDP] + B --> C[nsUDPSocket] + C --> B + D[nsSocketTransportService] --> C + B --> E[NeqoHttp3Conn] + B --> F[Http3Stream] + F -->|row| B + F --> G[nsHttpTransport] + G --> B + B --> G +``` + +## Interactions with sockets and driving neqo + +As described in [this docs](https://github.com/mozilla/neqo/blob/main/neqo-http3/src/lib.rs), neqo does not create a socket, it produces, i.e. encodes, data that should be sent as a payload in a UDP packet and consumes data received on the UDP socket. Therefore the necko is responsible for creating a socket and reading and writing data from/into the socket. Necko uses nsUDPSocket and nsSocketTransportService for this. +The UDP socket is constantly polled for reading. It is not polled for writing, we let QUIC control to not overload the network path and buffers. + +When the UDP socket has an available packet, nsSocketTransportService will return from the polling function and call nsUDPSocket::OnSocketReady, which calls HttpConnectionUDP::OnPacketReceived, HttpConnectionUDP::RecvData and further Http3Session::RecvData. For writing data +HttpConnectionUDP::SendData is called which calls Http3Session::SendData. + +Neqo needs an external timer. The timer is managed by Http3Session. When the timer expires HttpConnectionUDP::OnQuicTimeoutExpired is executed that calls Http3Session::ProcessOutputAndEvents. + +HttpConnectionUDP::RecvData, HttpConnectionUDP::SendData or HttpConnectionUDP::OnQuicTimeoutExpired must be on the stack when we interact with neqo. The reason is that they are responsible for proper clean-up in case of an error. For example, if there is a slow reader that is ready to read, it will call Http3Session::TransactionHasDataToRecv to be registered in a list and HttpConnectionUDP::ForceRecv will be called that will call the same function chain as in the case a new packet is received, i.e. HttpConnectionUDP::RecvData and further Http3Session::RecvData. The other example is when a new HTTP transaction is added to the session, the transaction needs to send data. The transaction will be registered in a list and HttpConnectionUDP::ResumeSend will be called which further calls HttpConnectionUDP::SendData. + +Http3Session holds a reference to a ConnectionHandler object which is a wrapper object around HttpConnectionUDP. The destructor of ConnectionHandler calls nsHttpHandler::ReclaimConnection which is responsible for removing the connection from nsHttpConnectionMgr. +HttpConnectionUDP::RecvData, HttpConnectionUDP::SendData or HttpConnectionUDP::OnQuicTimeoutExpired call HttpConnectionUDP::CloseTransaction which will cause Http3Session to remove the reference to the ConnectionHandler object. The ConnectionHandler object will be destroyed and nsHttpHandler::ReclaimConnection will be called. +This behavior is historical and it is also used for HTTP/2 and older versions. In the case of the older versions, nsHttpHandler::ReclaimConnection may actually reuse a connection instead of removing it from nsHttpConnectionMgr. + +Three main neqo functions responsible for driving neqo are process_input, process_output, and next_event. They are called by: +- Http3Session::ProcessInput, +- Http3Session::ProcesOutput and, +- Http3Session::ProcessEvents. + +**ProcessInput** +In this function we take data from the UDP socket and call NeqoHttp3Conn::ProcessInput that maps to Http3Client::process_input. The packets are read from the socket until the socket buffer is empty. + +**ProcessEvents** +This function process all available neqo events. It returns earlier only in case of a fatal error. +It calls NeqoHttp3Conn::GetEvent which maps to Http3Client::next_event. +The events and their handling will be explained below. + +**ProcessOutput** +The function is called when necko has performed some action on neqo, e.g. new HTTP transaction is added, certificate verification is done, etc., or when the timer expires. In both cases, necko wants to check if neqo has data to send or change its state. This function calls NeqoHttp3Conn::ProcessOutput that maps to Http3Client::process_output. NeqoHttp3Conn::ProcessOutput may return a packet that is sent on the socket or a callback timeout. In the Http3Session::ProcessOutput function, NeqoHttp3Conn::ProcessOutput is called repeatedly and packets are sent until a callback timer is returned or a fatal error happens. + +**Http3Session::RecvData** performs the following steps: +- ProcessSlowConsumers - explained below. +- ProcessInput - process new packets. +- ProcessEvents - look if there are new events +- ProcessOutput - look if we have new packets to send after packets arrive(e.g. sending ack) or due to event processing (e.g. a stream has been canceled). + +**Http3Session::SendData** performed the following steps: +- Process (HTTP and WebTransport) streams that have data to write. +- ProcessOutput - look if there are new packets to be sent after streams have supplied data to neqo. + + +**Http3Session::ProcessOutputAndEvents** performed the following steps: +- ProcessOutput - after a timeout most probably neqo will have data to retransmit or it will send a ping +- ProcessEvents - look if the state of the connection has changed, i.e. the connection timed out + + +## HTTP and WebTransport Streams reading data + +The following diagram shows how data are read from an HTTP stream. The diagram for a WebTransport stream will be added later. + +```{mermaid} +flowchart TD + A1[nsUDPSocket::OnSocketReady] --> |HttpConnectionUDP::OnPacketReceived| C[HttpConnectionUDP] + A[HttpConnectionUDP::ResumeRecv calls] --> C + B[HttpConnectionUDPForceIO] --> |HttpConnectionUDP::RecvData| C + C -->|1. Http3Session::RecvData| D[Http3Session] + D --> |2. Http3Stream::WriteSegments|E[Http3Stream] + E --> |3. nsHttpTransaction::WriteSegmentsAgain| F[nsHttpTransaction] + F --> |4. nsPipeOutputStream::WriteSegments| G["nsPipeOutputStream"] + G --> |5. nsHttpTransaction::WritePiipeSegnemt| F + F --> |6. Http3Stream::OnWriteSegment| E + E --> |"7. Return response headers or call Http3Session::ReadResponseData"|D + D --> |8. NeqoHttp3Conn::ReadResponseDataReadResponseData| H[NeqoHHttp3Conn] + +``` + +When there is a new packet carrying a stream data arriving on a QUIC connection nsUDPSocket::OnSocketReady will be called which will call Http3Session::RecvData. Http3Session::RecvData and ProcessInput will read the new packet from the socket and give it to neqo for processing. In the next step, ProcessEvent will be called which will have a DataReadable event and Http3Stream::WriteSegments will be called. +Http3Stream::WriteSegments calls nsHttpTransaction::WriteSegmentsAgain repeatedly until all data are read from the QUIC stream or until the pipe cannot accept more data. The latter can happen when listeners of an HTTP transaction or WebTransport stream are slow and are not able to read all data available on an HTTP3/WebTransport stream fast enough. + +When the pipe cannot accept more data nsHttpTransaction will call nsPipeOutputStream::AsyncWait and wait for the nsHttpTransaction::OnOutputStreamReady callback. When nsHttpTransaction::OnOutputStreamReady is called, Http3Stream/Session::TransactionHasDataToRecv is is executed with the following actions: +- the corresponding stream to a list(mSlowConsumersReadyForRead) and +- nsHttpConnection::ResumeRecv is called (i.e. it forces the same code path as when a socket has data to receive so that errors can be properly handled as explained previously). + +These streams will be processed in ProcessSlowConsumers which is called by Http3Session::RecvData. + +## HTTP and WebTransport Streams writing data + +The following diagram shows how data are sent from an HTTP stream. The diagram for a WebTransport stream will be added later. + +```{mermaid} +flowchart TD + A[HttpConnectionUDP::ResumeSend calls] --> C[HttpConnectionUDP] + B[HttpConnectionUDPForceIO] --> |HttpConnectionUDP::SendData| C + C -->|1. Http3Session::SendData| D[Http3Session] + D --> |2. Http3Stream::ReadSegments|E[Http3Stream] + E --> |3. nsHttpTransaction::ReadSegmentsAgain| F[nsHttpTransaction] + F --> |4. nsPipeInputStream::ReadSegments| G["nsPipeInputStream(Request stream)"] + G --> |5. nsHttpTransaction::ReadRequestSegment| F + F --> |6. Http3Stream::OnReadSegment| E + E --> |7. Http3Session::TryActivating/SendRequestBody|D + D --> |8. NeqoHttp3Conn::Fetch/SendRequestBody| H[NeqoHHttp3Conn] +``` + +When a nsHttpTransaction has been newly added to a transaction or when nsHttpTransaction has more data to write Http3Session::StreamReadyToWrite is called (in the latter case through Http3Session::TransactionHasDataToWrite) which performs the following actions: +- add the corresponding stream to a list(mReadyForWrite) and +- call HttpConnectionUDP::ResumeSend + +The Http3Session::SendData function iterates through mReadyForWrite and calls Http3Stream::ReadSegments for each stream. + +## Neqo events + +For **HeaderReady** and **DataReadable** the Http3Stream::WriteSegments function of the corresponding stream is called. The code path shown in the flowchart above will call the nssHttpTransaction served by the stream to take headers and data. + +**DataWritable** means that a stream could not accept more data earlier and that flow control now allows sending more data. Http3Sesson will mark the stream as writable(by calling Http3Session::StreamReadyToWrite) to verify if a stream wants to write more data. + +**Reset** and **StopSending** events will be propagated to the stream and the stream will be closed. + +**RequestsCreatable** events are posted when a QUIC connection could not accept new streams due to the flow control in the past and the stream flow control is increased and the streams are creatable again. Http3Session::ProcessPendingProcessPending will trigger the activation of the queued streams. + +**AuthenticationNeeded** and **EchFallbackAuthenticationNeeded** are posted when a certificate verification is needed. + + +**ZeroRttRejected** is posted when zero RTT data was rejected. + +**ResumptionToken** is posted when a new resumption token is available. + +**ConnectionConnected**, **GoawayReceived**, **ConnectionClosing** and **ConnectionClosed** expose change in the connection state. Difference between **ConnectionClosing** and **ConnectionClosed** that after **ConnectionClosed** the connection can be immediately closed and after **ConnectionClosing** we will keep the connection object for a short time until **ConnectionClosed** event is received. During this period we will retransmit the closing frame if they are lost. + +### WebTransport events + +**Negotiated** - WebTransport is negotiated only after the HTTP/3 settings frame has been received from the server. At that point **Negotiated** event is posted to inform the application. + +The **Session** event is posted when a WebTransport session is successfully negotiated. + +The **SessionClosed** event is posted when a connection is closed gracefully or abruptly. + +The **NewStream** is posted when a new stream has been opened by the peer. diff --git a/netwerk/docs/http/lifecycle.rst b/netwerk/docs/http/lifecycle.rst new file mode 100644 index 0000000000..007d35e579 --- /dev/null +++ b/netwerk/docs/http/lifecycle.rst @@ -0,0 +1,220 @@ +The lifecycle of a HTTP request +=============================== + + +HTTP requests in Firefox go through several steps. Each piece of the request message and response message become available at certain points. Extracting that information is a challenge, though. + +What is available when +---------------------- + ++-----------------------+---------------------------------------------------+---------------------------------------+------------------------+-------------------------------+ +| Data | When it's available | Sample JS code | Interfaces | Test code | ++=======================+===================================================+=======================================+========================+===============================+ +| HTTP request method | *http-on-modify-request* observer notification | channel.requestMethod | nsIHttpChannel_ | | ++-----------------------+---------------------------------------------------+---------------------------------------+------------------------+-------------------------------+ +| HTTP request URI | *http-on-modify-request* observer notification | channel.URI | nsIChannel_ | | ++-----------------------+---------------------------------------------------+---------------------------------------+------------------------+-------------------------------+ +| HTTP request headers | *http-on-modify-request* observer notification | channel.visitRequestHeaders(visitor) | nsIHttpChannel_ | | ++-----------------------+---------------------------------------------------+---------------------------------------+------------------------+-------------------------------+ +| HTTP request body | *http-on-modify-request* observer notification | channel.uploadStream | nsIUploadChannel_ | | ++-----------------------+---------------------------------------------------+---------------------------------------+------------------------+-------------------------------+ +|| HTTP response status || *http-on-examine-response* observer notification || channel.responseStatus || nsIHttpChannel_ || test_basic_functionality.js_ | +|| || || channel.responseStatusText || || | ++-----------------------+---------------------------------------------------+---------------------------------------+------------------------+-------------------------------+ +| HTTP response headers | *http-on-examine-response* observer notification | channel.visitResponseHeaders(visitor) | nsIHttpChannel_ | | ++-----------------------+---------------------------------------------------+---------------------------------------+------------------------+-------------------------------+ +|| HTTP response body || *onStopRequest* via stream listener tee || See below || nsITraceableChannel_ || test_traceable_channel.js_ | +|| || || || nsIStreamListenerTee_ || | +|| || || || nsIPipe_ || | ++-----------------------+---------------------------------------------------+---------------------------------------+------------------------+-------------------------------+ + +The request: http-on-modify-request +----------------------------------- + +Firefox fires a "http-on-modify-request" observer notification before sending the HTTP request, and this blocks the sending of the request until all observers exit. This is generally the point at which you can modify the HTTP request headers (hence the name). + +Attaching a listener for a request is pretty simple:: + + const obs = { + QueryInterface: ChromeUtils.generateQI(["nsIObserver"]), + + observe: function(channel, topic, data) { + if (!(channel instanceof Ci.nsIHttpChannel)) + return; + + // process the channel's data + } + } + + Services.obs.addObserver(observer, "http-on-modify-request", false); + +See nsIObserverService_ for the details. + +The request method and URI are immediately available at this time. Request headers are trivially easy to get:: + + /** + * HTTP header visitor. + */ + class HeaderVisitor { + #targetObject; + + constructor(targetObject) { + this.#targetObject = targetObject; + } + + // nsIHttpHeaderVisitor + visitHeader(header, value) { + this.#targetObject[header] = value; + } + + QueryInterface = ChromeUtils.generateQI(["nsIHttpHeaderVisitor"]); + } + + // ... + const requestHeaders = {}; + const visitor = new HeaderVisitor(requestHeaders); + channel.visitRequestHeaders(visitor); + +This is also the time to set request headers, if you need to. The method for that on the nsIHttpChannel_ interface is `channel.setRequestHeader(header, value);` + +Most HTTP requests don't have a body, as they are GET requests. POST requests often have them, though. As the nsIUploadChannel_ documentation indicates, the body of most HTTP requests is available via a seekable stream (nsISeekableStream_). So you can simply capture the body stream and its current position, to revisit it later. network-helper.js_ has code to read the request body. + +The response: http-on-examine-response +-------------------------------------- + +Firefox fires a "http-on-examine-response" observer notification after parsing the HTTP response status and headers, but **before** reading the response body. Attaching a listener for this phase is also very easy:: + + Services.obs.addObserver(observer, "http-on-examine-response", false); + +If you use the same observer for "http-on-modify-request" and "http-on-examine-response", make sure you check the topic argument before interacting with the channel. + +The response status is available via the *responseStatus* and *responseStatusText* properties. The response headers are available via the *visitResponseHeaders* method, and requires the same interface. + +The response body: onStopRequest, stream listener tee +----------------------------------------------------- + +During the "http-on-examine-response" notification, the response body is *not* available. You can, however, use a stream listener tee to *copy* the stream so that the original stream data goes on, and you have a separate input stream you can read from with the same data. + +Here's some sample code to illustrate what you need:: + + const Pipe = Components.Constructor( + "@mozilla.org/pipe;1", + "nsIPipe", + "init" + ); + const StreamListenerTee = Components.Constructor( + "@mozilla.org/network/stream-listener-tee;1", + "nsIStreamListenerTee" + ); + const ScriptableStream = Components.Constructor( + "@mozilla.org/scriptableinputstream;1", + "nsIScriptableInputStream", + "init" + ); + + const obs = { + QueryInterface: ChromeUtils.generateQI(["nsIObserver", "nsIRequestObserver"]), + + /** @typedef {WeakMap<nsIHttpChannel, nsIPipe>} */ + requestToTeePipe: new WeakMap, + + // nsIObserver + observe: function(channel, topic, data) { + if (!(channel instanceof Ci.nsIHttpChannel)) + return; + + /* Create input and output streams to take the new data. + The 0xffffffff argument is the segment count. + It has to be this high because you don't know how much data is coming in the response body. + + As for why these are blocking streams: I believe this is because there's no actual need to make them non-blocking. + The stream processing happens during onStopRequest(), so we have all the data then and the operation can be synchronous. + But I could be very wrong on this. + */ + const pipe = new Pipe(false, false, 0, 0xffffffff); + + // Install the stream listener tee to intercept the HTTP body. + const tee = new StreamListenerTee; + const originalListener = channel.setNewListener(tee); + tee.init(originalListener, pipe.outputStream, this); + + this.requestToTeePipe.set(channel, pipe); + } + + // nsIRequestObserver + onStartRequest: function() { + // do nothing + } + + // nsIRequestObserver + onStopRequest: function(channel, statusCode) { + const pipe = this.requestToTeePipe.get(channel); + + // No more data coming in anyway. + pipe.outputStream.close(); + this.requestToTeePipe.delete(channel); + + let length = 0; + try { + length = pipe.inputStream.available(); + } + catch (e) { + if (e.result === Components.results.NS_BASE_STREAM_CLOSED) + throw e; + } + + let responseBody = ""; + if (length) { + // C++ code doesn't need the scriptable input stream. + const sin = new ScriptableStream(pipe.inputStream); + responseBody = sin.read(length); + sin.close(); + } + + void(responseBody); // do something with the body + } + } + +test_traceable_channel.js_ does essentially this. + +Character encodings and compression +----------------------------------- + +Canceling requests +------------------ + +HTTP activity distributor notes +------------------------------- + +URIContentLoader notes +---------------------- + +Order of operations +------------------- + +1. The HTTP channel is constructed. +2. The "http-on-modify-request" observer service notification fires. +3. If the request has been canceled, exit at this step. +4. The HTTP channel's request is submitted to the server. Time passes. +5. The HTTP channel's response comes in from the server. +6. The HTTP channel parses the response status and headers. +7. The "http-on-examine-response" observer service notification fires. + +Useful code samples and references +---------------------------------- + +- nsIHttpProtocolHandler_ defines a lot of observer topics, and has a lot of details. + +.. _nsIHttpChannel: https://searchfox.org/mozilla-central/source/netwerk/protocol/http/nsIHttpChannel.idl +.. _nsIChannel: https://searchfox.org/mozilla-central/source/netwerk/base/nsIChannel.idl +.. _nsIUploadChannel: https://searchfox.org/mozilla-central/source/netwerk/base/nsIUploadChannel.idl +.. _nsITraceableChannel: https://searchfox.org/mozilla-central/source/netwerk/base/nsITraceableChannel.idl +.. _nsISeekableStream: https://searchfox.org/mozilla-central/source/xpcom/io/nsISeekableStream.idl +.. _nsIObserverService: https://searchfox.org/mozilla-central/source/xpcom/ds/nsIObserverService.idl +.. _nsIHttpProtocolHandler: https://searchfox.org/mozilla-central/source/netwerk/protocol/http/nsIHttpProtocolHandler.idl +.. _nsIStreamListenerTee: https://searchfox.org/mozilla-central/source/netwerk/base/nsIStreamListenerTee.idl +.. _nsIPipe: https://searchfox.org/mozilla-central/source/xpcom/io/nsIPipe.idl + +.. _test_basic_functionality.js: https://searchfox.org/mozilla-central/source/netwerk/test/httpserver/test/test_basic_functionality.js +.. _test_traceable_channel.js: https://searchfox.org/mozilla-central/source/netwerk/test/unit/test_traceable_channel.js +.. _network-helper.js: https://searchfox.org/mozilla-central/source/devtools/shared/webconsole/network-helper.js diff --git a/netwerk/docs/http/logging.rst b/netwerk/docs/http/logging.rst new file mode 100644 index 0000000000..7dbc418a7a --- /dev/null +++ b/netwerk/docs/http/logging.rst @@ -0,0 +1,320 @@ +HTTP Logging +============ + + +Sometimes, while debugging your Web app (or client-side code using +Necko), it can be useful to log HTTP traffic. This saves a log of HTTP-related +information from your browser run into a file that you can examine (or +upload to Bugzilla if a developer has asked you for a log). + +.. note:: + + **Note:** The `Web + Console <https://developer.mozilla.org/en-US/docs/Tools/Web_Console>`__ + also offers the ability to peek at HTTP transactions within Firefox. + HTTP logging generally provides more detailed logging. + +.. _using-about-networking: + +Using about:logging +------------------- + +This is the best and easiest way to do HTTP logging. At any point +during while your browser is running, you can turn logging on and off. + +.. note:: + + **Note:** Before Firefox 108 the logging UI used to be located at `about:networking#logging` + +This allows you to capture only the "interesting" part of the browser's +behavior (i.e. your bug), which makes the HTTP log much smaller and +easier to analyze. + +#. Launch the browser and get it into whatever state you need to be in + just before your bug occurs. +#. Open a new tab and type in "about:logging" into the URL bar. +#. Adjust the location of the log file if you don't like the default +#. Adjust the list of modules that you want to log: this list has the + exact same format as the MOZ_LOG environment variable (see below). + Generally the default list is OK, unless a Mozilla developer has told + you to modify it. +#. Click on Start Logging. +#. Reproduce the bug (i.e. go to the web site that is broken for you and + make the bug happen in the browser) +#. Make a note of the value of "Current Log File". +#. Click on Stop Logging. +#. Go to the folder containing the specified log file, and gather all + the log files. You will see several files that look like: + log.txt-main.1806.moz_log, log.txt-child.1954.moz_log, + log.txt-child.1970.moz_log, etc. This is because Firefox now uses + multiple processes, and each process gets its own log file. +#. For many bugs, the "log.txt-main.moz_log" file is the only thing you need to + upload as a file attachment to your Bugzilla bug (this is assuming + you're logging to help a mozilla developer). Other bugs may require + all the logs to be uploaded--ask the developer if you're not sure. +#. Pat yourself on the back--a job well done! Thanks for helping us + debug Firefox. + +Logging HTTP activity by manually setting environment variables +--------------------------------------------------------------- + +Sometimes the about:logging approach won't work, for instance if your +bug occurs during startup, or you're running on mobile, etc. In that +case you can set environment variables \*before\* you launch Firefox. +Note that this approach winds up logging the whole browser history, so +files can get rather large (they compress well :) + +Setting environment variables differs by operating system. Don't let the +scary-looking command line stuff frighten you off; it's not hard at all! + +Windows +~~~~~~~ + +#. If Firefox is already running, exit out of it. + +#. Open a command prompt by holding down the Windows key and pressing "R". + +#. Type CMD and press enter, a new Command Prompt window with a black + background will appear. + +#. | Copy and paste the following lines one at a time into the Command + Prompt window. Press the enter key after each one.: + | **For 64-bit Windows:** + + :: + + set MOZ_LOG=timestamp,rotate:200,nsHttp:5,cache2:5,nsSocketTransport:5,nsHostResolver:5 + set MOZ_LOG_FILE=%TEMP%\log.txt + "c:\Program Files\Mozilla Firefox\firefox.exe" + + **For 32-bit Windows:** + + :: + + set MOZ_LOG=timestamp,rotate:200,nsHttp:5,cache2:5,nsSocketTransport:5,nsHostResolver:5 + set MOZ_LOG_FILE=%TEMP%\log.txt + "c:\Program Files (x86)\Mozilla Firefox\firefox.exe" + + (These instructions assume that you installed Firefox to the default + location, and that drive C: is your Windows startup disk. Make the + appropriate adjustments if those aren't the case.) + +#. Reproduce whatever problem it is that you're having. + +#. Once you've reproduced the problem, exit Firefox and look for the + generated log files in your temporary directory. You can type + "%TEMP%" directly into the Windows Explorer location bar to get there + quickly. + +Linux +~~~~~ + +This section offers information on how to capture HTTP logs for Firefox +running on Linux. + +#. Quit out of Firefox if it's running. + +#. Open a new shell. The commands listed here assume a bash-compatible + shell. + +#. Copy and paste the following commands into the shell one at a time. + Make sure to hit enter after each line. + + :: + + export MOZ_LOG=timestamp,rotate:200,nsHttp:5,cache2:5,nsSocketTransport:5,nsHostResolver:5 + export MOZ_LOG_FILE=/tmp/log.txt + cd /path/to/firefox + ./firefox + +#. Reproduce the problem you're debugging. + +#. When the problem has been reproduced, exit Firefox and look for the + generated log files, which you can find at ``/tmp/log.txt``. + +Mac OS X +~~~~~~~~ + +These instructions show how to log HTTP traffic in Firefox on Mac OS X. + +#. Quit Firefox is if it's currently running, by using the Quit option + in the File menu. Keep in mind that simply closing all windows does + **not** quit Firefox on Mac OS X (this is standard practice for Mac + applications). + +#. Run the Terminal application, which is located in the Utilities + subfolder in your startup disk's Applications folder. + +#. Copy and paste the following commands into the Terminal window, + hitting the return key after each line. + + :: + + export MOZ_LOG=timestamp,rotate:200,nsHttp:5,cache2:5,nsSocketTransport:5,nsHostResolver:5 + export MOZ_LOG_FILE=~/Desktop/log.txt + cd /Applications/Firefox.app/Contents/MacOS + ./firefox-bin + + (The instructions assume that you've installed Firefox directly into + your startup disk's Applications folder. If you've put it elsewhere, + change the path used on the third line appropriately.) + +#. Reproduce whatever problem you're trying to debug. + +#. Quit Firefox and look for the generated ``log.txt`` log files on your + desktop. + +.. note:: + + **Note:** The generated log file uses Unix-style line endings. Older + editors may have problems with this, but if you're using an even + reasonably modern Mac OS X application to view the log, you won't + have any problems. + +Start logging using command line arguments +------------------------------------------ + +Since Firefox 61 it's possible to start logging in a bit simpler way +than setting environment variables: using command line arguments. Here +is an example for the **Windows** platform, on other platforms we accept +the same form of the arguments: + +#. If Firefox is already running, exit out of it. + +#. Open a command prompt. On `Windows + XP <https://commandwindows.com/runline.htm>`__, you can find the + "Run..." command in the Start menu's "All Programs" submenu. On `all + newer versions of + Windows <http://www.xp-vista.com/other/where-is-run-in-windows-vista>`__, + you can hold down the Windows key and press "R". + +#. | Copy and paste the following line into the "Run" command window and + then press enter: + | **For 32-bit Windows:** + + :: + + "c:\Program Files (x86)\Mozilla Firefox\firefox.exe" -MOZ_LOG=timestamp,rotate:200,nsHttp:5,cache2:5,nsSocketTransport:5,nsHostResolver:5 -MOZ_LOG_FILE=%TEMP%\log.txt + + **For 64-bit Windows:** + + :: + + "c:\Program Files\Mozilla Firefox\firefox.exe" -MOZ_LOG=timestamp,rotate:200,nsHttp:5,cache2:5,nsSocketTransport:5,nsHostResolver:5 -MOZ_LOG_FILE=%TEMP%\log.txt + + (These instructions assume that you installed Firefox to the default + location, and that drive C: is your Windows startup disk. Make the + appropriate adjustments if those aren't the case.) + +#. Reproduce whatever problem it is that you're having. + +#. Once you've reproduced the problem, exit Firefox and look for the + generated log files in your temporary directory. You can type + "%TEMP%" directly into the Windows Explorer location bar to get there + quickly. + +Advanced techniques +------------------- + +You can adjust some of the settings listed above to change what HTTP +information get logged. + +Limiting the size of the logged data +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +By default there is no limit to the size of log file(s), and they +capture the logging throughout the time Firefox runs, from start to +finish. These files can get quite large (gigabytes)! So we have added +a 'rotate:SIZE_IN_MB' option to MOZ_LOG (we use it in the examples +above). If you are using Firefox >= 51, setting this option saves only +the last N megabytes of logging data, which helps keep them manageable +in size. (Unknown modules are ignored, so it's OK to use 'rotate' in +your environment even if you're running Firefox <= 50: it will do +nothing). + +This is accomplished by splitting the log into up to 4 separate files +(their filenames have a numbered extension, .0, .1, .2, .3) The logging +back end cycles the files it writes to, while ensuring that the sum of +these files’ sizes will never go over the specified limit. + +Note 1: **the file with the largest number is not guaranteed to be the +last file written!** We don’t move the files, we only cycle. Using the +rotate module automatically adds timestamps to the log, so it’s always +easy to recognize which file keeps the most recent data. + +Note 2: **rotate doesn’t support append**. When you specify rotate, on +every start all the files (including any previous non-rotated log file) +are deleted to avoid any mixture of information. The ``append`` module +specified is then ignored. + +Use 'sync' if your browser crashes or hangs +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +By default, HTTP logging buffers messages and only periodically writes +them to disk (this is more efficient and also makes logging less likely +to interfere with race conditions, etc). However, if you are seeing +your browser crash (or hang) you should add ",sync" to the list of +logging modules in your MOZ_LOG environment variable. This will cause +each log message to be immediately written (and fflush()'d), which is +likely to give us more information about your crash. + +Turning on QUIC logging +~~~~~~~~~~~~~~~~~~~~~~~ + +This can be done by setting `MOZ_LOG` to +`timestamp,rotate:200,nsHttp:5,neqo_http3::*:5,neqo_transport::*:5`. + +Logging only HTTP request and response headers +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +There are two ways to do this: + +#. Replace MOZ_LOG\ ``=nsHttp:5`` with MOZ_LOG\ ``=nsHttp:3`` in the + commands above. +#. There's a handy extension for Firefox called `HTTP Header + Live <https://addons.mozilla.org/firefox/addon/3829>`__ that you can + use to capture just the HTTP request and response headers. This is a + useful tool when you want to peek at HTTP traffic. + +Turning off logging of socket-level transactions +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +If you're not interested in socket-level log information, either because +it's not relevant to your bug or because you're debugging something that +includes a lot of noise that's hard to parse through, you can do that. +Simply remove the text ``nsSocketTransport:5`` from the commands above. + +Turning off DNS query logging +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +You can turn off logging of host resolving (that is, DNS queries) by +removing the text ``nsHostResolver:5`` from the commands above. + +Enable Logging for try server runs +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +You can enable logging on try by passing the `env` argument via `mach try`. +For example: + +.. note:: + + ``./mach try fuzzy --env "MOZ_LOG=nsHttp:5,SSLTokensCache:5"`` + +See also +-------- + +- There are similar options available to debug mailnews protocols. + See `this + document <https://www-archive.mozilla.org/quality/mailnews/mail-troubleshoot.html>`__ for + more info about mailnews troubleshooting. +- On the Windows platform, nightly Firefox builds have FTP logging + built-in (don't ask why this is only the case for Windows!). To + enable FTP logging, just set ``MOZ_LOG=nsFtp:5`` (in older versions + of Mozilla, you need to use ``nsFTPProtocol`` instead of ``nsFtp``). +- When Mozilla's built-in logging capabilities aren't good enough, and + you need a full-fledged packet tracing tool, two free products are + `Wireshark <https://www.wireshark.org/>`__ + and `ngrep <https://github.com/jpr5/ngrep/>`__. They are available + for Windows and most flavors of UNIX (including Linux and Mac OS + X), are rock solid, and offer enough features to help uncover any + Mozilla networking problem. |