Logging HTTP calls made by Node.js and Python applications
As developers we often come across situations where we’d like to see all the remote API calls made by a certain application. This requirement often comes up during development and testing, but there are times when you might want to see this information for production applications too.
In this article we explore a couple of simple tricks for logging the HTTP requests made by applications written in Node.js or Python. These techniques do not require any specific logging framework, and can be managed entirely within the application code without too much effort. I’m going to use the Firebase Admin SDK as an example library in my code samples, but the techniques described here should work with most, if not all Node.js and Python libraries. Let’s start with Node.js.
Node.js
One of the easiest ways to log all the HTTP requests made by any Node.js application is to wrap the core HTTP module of the Node.js runtime. To be more specific, we replace the http.request() (or https.request()) method of Node.js with a custom function that logs the outgoing request, and delegates the request back to the original method. Listing 1 shows what this looks like in practice.
We enable HTTP request logging by calling enableRequestLogger() in our code. This function handles the actual wrapping of the https.request() method. Note how it logs some of the request options to the console, before calling the original method. Executing the above program produces an output similar to the following:
2020-10-25T00:03:54.629Z POST https://accounts.google.com/o/oauth2/token
2020-10-25T00:03:54.789Z POST https://fcm.googleapis.com/v1/projects/my-project/messages:sendThis output indicates that the Admin SDK has made two requests during execution of the above code — one to the OAuth2 token server, and the other to the Firebase Cloud Messaging (FCM) service. The implementation in listing 1 is pretty basic, and logs only the request method and URL for each outgoing request. It is certainly possible to come up with a more sophisticated implementation that logs both requests and responses, including the message headers and payloads if you like. There are even third party libraries like http-debug and global-request-logger that provide these capabilities out of the box, so you don’t have to implement custom wrappers for http.request() yourself.
Note: As of October, 2020 global-request-logger doesn’t work for HTTPS interactions. But their implementation is pretty straightforward, and serves as a good reference if you ever decide to implement a custom request logger for Node.js.
Python
Many Python applications use the requests library to make remote API calls, which in turns uses Python’s http.client. Therefore you can simply turn on the debug logs at the http.client level to log request headers, payload and response headers (but not the response body) for each HTTP interaction. Listing 2 demonstrates this approach.
We enable debug logging by setting the HTTPConnection.debuglevel property to a value greater than 0. Executing the above program results in the following logs:
send: b'POST /token HTTP/1.1\r\nHost: oauth2.googleapis.com\r\nUser-Agent: python-requests/2.24.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\ncontent-type: application/x-www-form-urlencoded\r\nContent-Length: 1127\r\n\r\n'
send: b'assertion=eyJ....'
reply: 'HTTP/1.1 200 OK\r\n'
header: Content-Type: application/json; charset=UTF-8
header: Vary: Origin
header: Vary: X-Origin
header: Vary: Referer
header: Content-Encoding: gzip
header: Date: Sun, 25 Oct 2020 20:46:43 GMT
header: Server: scaffolding on HTTPServer2
header: Cache-Control: private
header: X-XSS-Protection: 0
header: X-Frame-Options: SAMEORIGIN
header: X-Content-Type-Options: nosniff
header: Alt-Svc: h3-Q050=":443"; ma=2592000,h3-29=":443"; ma=2592000,h3-T051=":443"; ma=2592000,h3-T050=":443"; ma=2592000,h3-Q046=":443"; ma=2592000,h3-Q043=":443"; ma=2592000,quic=":443"; ma=2592000; v="46,43"
header: Transfer-Encoding: chunkedsend: b'POST /v1/projects/my-project/messages:send HTTP/1.1\r\nHost: fcm.googleapis.com\r\nUser-Agent: python-requests/2.24.0\r\nAccept-Encoding: gzip, deflate\r\nAccept: */*\r\nConnection: keep-alive\r\nX-GOOG-API-FORMAT-VERSION: 2\r\nX-FIREBASE-CLIENT: fire-admin-python/4.4.0\r\nauthorization: Bearer ya29.c.KqYB4gesy_EQO8hL3r_RFC3tSSA_6of8JuN8cvgFy78FwI1HFpSlJmsrHHivx1Dd_lDzwY8tbrfpK4MLmTVNO-e0RUm7H4y9siwGUPjyOmTr4TTQzDLDhANiy4oJaKJt77OOgIp3gCiyxNcsl9YvQskVca1iHlXParHjsduJYgzvWCC-CsYEFe4O4Jz6H9ti8f3smfuoN8lhJrL4fxrg713hZ_lM5Fj7bQ\r\nContent-Length: 73\r\nContent-Type: application/json\r\n\r\n'
send: b'{"message": {"notification": {"title": "Hello world!"}, "topic": "test"}}'
reply: 'HTTP/1.1 200 OK\r\n'
header: Content-Type: application/json; charset=UTF-8
header: Vary: Origin
header: Vary: X-Origin
header: Vary: Referer
header: Content-Encoding: gzip
header: Date: Sun, 25 Oct 2020 20:46:44 GMT
header: Server: ESF
header: Cache-Control: private
header: X-XSS-Protection: 0
header: X-Frame-Options: SAMEORIGIN
header: X-Content-Type-Options: nosniff
header: Alt-Svc: h3-Q050=":443"; ma=2592000,h3-29=":443"; ma=2592000,h3-T051=":443"; ma=2592000,h3-T050=":443"; ma=2592000,h3-Q046=":443"; ma=2592000,h3-Q043=":443"; ma=2592000,quic=":443"; ma=2592000; v="46,43"
header: Transfer-Encoding: chunked
We are seeing the same two HTTP requests as before, but this time logged with more details. For a slightly less verbose output, you can try enabling debug logs at the urllib3 package level. This package serves as an intermediary between requests and http.client. Listing 3 shows how this can be achieved.
Notice the use of Python’s built-in logging package. This is essential to see the log output from urllib3. The output of listing 3 looks something like this:
DEBUG:google.auth.transport.requests:Making request: POST https://oauth2.googleapis.com/token
DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): oauth2.googleapis.com:443
DEBUG:urllib3.connectionpool:https://oauth2.googleapis.com:443 "POST /token HTTP/1.1" 200 None
DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): fcm.googleapis.com:443
DEBUG:urllib3.connectionpool:https://fcm.googleapis.com:443 "POST /v1/projects/my-project/messages:send HTTP/1.1" 200 NoneRefer to the Python documentation for more details about the logging package, and the various configuration options it provides. You can also use the techniques shown in listing 2 and listing 3 together in the same application for a highly verbose log output.
Conclusion
We looked at some simple techniques for logging the HTTP requests made by Node.js and Python applications. We used the Firebase Admin SDK as an example in our code snippets, but our approach generalizes well to a wide range of Node.js and Python libraries. Developers can use these techniques to simplify testing applications and debugging complex issues. We can also use them in production deployments to gain more visibility into the internal workings of an application. However, keep in mind that extra logging almost always comes with a performance penalty, so only use logging when necessary, and in the right amount.