Log HTTP client behaviour

[gajus]

To begin with, it would be handy to be able to inspect configuration of every HTTP request. I currently do that by wrapping got in a helper function that logs whatever the configuration was used to create a request.

Other things that would be useful to log:

• Response meta data (including redirects)
• Response timings (if/ when Add ability to time requests #557 is implemented)
• Whether response was served from cache
• Request cancellation
• Request timeout

If you used something like https://github.com/gajus/roarr, there would be near-0 performance impact (calling noop function) when logging is disabled. Logging can be controlled using environment variables.

Happy to contribute an integration.

[sindresorhus]

I agree this would be useful. I think roarr is a bit heavyweight to include in Got, but how about we just expose a metadata event and people can log using whatever they want? We could also log by default using util.debuglog().

[gajus]

I think roarr is a bit heavyweight to include in Got, [..]

I have refactored Roarr into two packages:

• https://github.com/gajus/roarr
• https://github.com/gajus/roarr-cli

Now Roarr logger package is 304K.

Now the bulk of the size comes from sprintf-js, which I cannot do much about.

If the intent is to compete with other packages on package size, then this is going to compromise your position.

but how about we just expose a metadata event and people can log using whatever they want?

This approach works great for applications, but it sucks for modules. I explain the distinction in https://github.com/gajus/roarr#motivation.

tl;dr;

When you have an application which depends on modules that use got, there is no way to enable got logging without digging through node_modules/ and patching the code.

We could also log by default using util.debuglog().

I like util.debuglog(). However, it does not provide structured logs. Modern logging stacks (ELK, Splunk) ingest structured logs (JSON), which allows to implement monitoring/ alerting and even scaling based on log attributes. This is primary reason for using logs in the first place – nowadays debugging is better achieved with --inspect anyway.

[sindresorhus]

When you have an application which depends on modules that use got, there is no way to enable got logging without digging through node_modules/ and patching the code.

Environment variable? Alternatively or in addition to, we could have a singleton emitter, that logs for all instances, so you could just require('got').on('metadata', () => {}) and get logs even when got is used in sub-dependencies.

[gajus]

Environment variable?

Not if you go with the custom event approach. Environment variables can only toggle logging, not configure the hooks.

debug (module) and util.debuglog() already provide this functionality with DEBUG and NODE_DEBUG variables. The only downside is that the logs are not structured.

Alternatively or in addition to, we could have a singleton emitter, that logs for all instances, so you could just require('got').on('metadata', () => {}) and get logs even when got is used in sub-dependencies.

Unfortunately, you cannot do that either, because the application will loose access to the singleton if modules depend on incompatible Got versions.

This is the reason why Roarr is using global to register log handler/ push logs to. It is the only approach to have interoperable log handling between all components, regardless of the version. Resolving version incompatibilities then becomes the responsibility of the logger itself – every initialisation of Roarr logger promotes handling of global space to the highest available Roarr version.

[sindresorhus]

Not if you go with the custom event approach. Environment variables can only toggle logging, not configure the hooks.

I was responding to the comment about the problem of not being able to toggle it.

Unfortunately, you cannot do that either, because the application will loose access to the singleton if modules depend on incompatible Got versions.

Got could use global internally to orchestrate the singleton listeners, like roarr, and then just expose that global. We should use a Symbol so it's only accessible by a Got instance.

[gajus]

We should use a Symbol so it's only accessible by a Got instance.

If you use a Symbol, then you are back to square one – Symbols are not going to be shared between incompatible Got versions. Of course, you could create a dedicated package just for the symbol... thats a bit of stretch.

In general, yes, this approach would work. I am not recommending it as it is effectively inlining logger logic into the package, but it does the job.

[sindresorhus]

If you use a Symbol, then you are back to square one – Symbols are not going to be shared between incompatible Got versions. Of course, you could create a dedicated package just for the symbol... thats a bit of stretch.

Right, good point.

[jstewmon]

@gajus would you mind taking a look at #561 (WIP)? I think it would facilitate the introspection features you're describing. I'm looking for feedback on the interface and mechanics, so feel free to add your perspective.

Notably, cache hit/miss is not facilitated. I need to look again, but I think those have to be inferred by 'response' without 'request' (for a hit) and 'request' (for a miss).

[wtgtybhertgeghgtwtg]

I think it's important that the software directly consuming got must explicitly enable logging and that all other instances of got be unaffected by that. So, I I have the following

require('my-got');
const ghGot = require('gh-got');
ghGot('users/wtgtybhertgeghgtwtg', {token: 'my-token'});

whatever goes on in my-got should not affect what gh-got logs. I believe that neither a solution based on environmental variables (where my-got can just add the variable) nor one using a singleton (where it can require('got').on('metadata', data => console.log(data))) can account for this.

[gajus]

I think it's important that the software directly consuming got must explicitly enable logging and that all other instances of got be unaffected by that.

I argue for the exact opposite.

Logging (not to confuse with debugging) serves the purpose of exposing all available information about application to enable a comprehensive view of all attributes associated with the application. One of these attributes is HTTP requests. Therefore, if I enable HTTP logging for an application, I expect a comprehensive view of all requests made either by my application or descendent components.

What is the logic for what you are arguing?

[wtgtybhertgeghgtwtg]

Therefore, if I enable HTTP logging for an application, I expect a comprehensive view of all requests made either by my application or descendent components.

With an allowance for redaction of sensitive information, I agree. The issue is the "if I enable" part. I'm saying settings made in or for a descendant or sibling component should not affect what I have here.

[gajus]

With an allowance for redaction of sensitive information, I agree. The issue is the "if I enable" part. I'm saying settings made in or for a descendant or sibling component should not affect what I have here.

Thats a responsibility of the log consumer, not the application.

Something like Logstash would be responsible for stripping away the data that is not supposed to leave enter the log database, e.g. passwords and such. This is a manual process and a responsibility of your sysops.

[wtgtybhertgeghgtwtg]

I might agree, but that's making a lot of assumptions about the stack. How many users of got or its dependents do you think have a dedicated sysops team? What is your suggestion for those who don't?

[gajus]

I might agree, but that's making a lot of assumptions about the stack. How many users of got or its dependents do you think have a dedicated sysops team? What is your suggestion for those who don't?

1. Most of the users who do not have sysops are going to be jacks of all trades and can implement this themselves.
2. Most of the users who do not have sysops are unlikely to have a centralised log aggregation system either. Those that do, will have the technical knowledge of how to configure the aggregators.

There are a lot bigger security concerns prior to concerning with log neutralisation.

[szmarczak]

@gajus You can achieve what you want using custom instances. I'd use got.create and attach some listeners + logging and done.

[gajus]

@gajus You can achieve what you want using custom instances. I'd use got.create and attach some listeners + logging and done.

Thats what we are doing already.

The point was to have logging that would enable inspection of all application traffic, including its dependencies.

[szmarczak]

Thats what we are doing already.

Oh.

Logging (not to confuse with debugging) serves the purpose of exposing all available information about application to enable a comprehensive view of all attributes associated with the application.

IMO logging stands for saving data which are useful to improve user's experience. In most cases debugging means using a debugger. The name says that for itself: de-bug, getting rid of bugs.

Thats a responsibility of the log consumer, not the application.

It can be done in both ways. It's just a matter of choice, some people are comfortable with different ways.

@sindresorhus

I think roarr is a bit heavyweight to include in Got

It can be a dev dependency :)

There are many ways to implement logging. I don't know which way is better, because I only log the URLs of failed requests, so I can't say much. This issue needs more attention.

[sindresorhus]

Relevant Node.js thread: nodejs/node#21888 Please comment your use-cases and needs there.