ijpiantanida / talkback

A simple HTTP proxy that records and playbacks requests
MIT License
283 stars 41 forks source link

When starting multiple servers the logging does not use the server name provided in options #75

Closed roypa closed 2 years ago

roypa commented 2 years ago

I start multiple Talkback servers in the same Node script, each handling the requests to a specific backend server.

The code looks something like this:

const startTalkbackServer = (serverName: string) => {
  const options = {
    name: serverName,
    host: config.get<string>(`${serverName}.talkbackUrl`),
    port: config.get<string>(`${serverName}.talkbackPort`),
    path: `./talkback/cached_responses/${serverName}`,
    // ...
  };

  const server = talkback(options);
  server.start(() => {
    console.log(`Talkback server started on http://localhost:${options.port} for ${options.host} with tapes at ${options.path}`);
  });
};

['accounts', 'customers'].forEach(startTalkbackServer);

This works very well. The only issue we have with this, is that the log output from each of the servers does not reflect the server name provided in the options. The log output from both servers have the same name in the log line. This is always the name of the last server started.

For example when the the summary is being printed from these two servers, it looks like this:

[talkback] 2022-06-23T07:55:49.200Z [customers] [INFO] ===== SUMMARY =====
...
[talkback] 2022-06-23T07:55:49.300Z [customers] [INFO] ===== SUMMARY =====
...

Any idea why this is happening?

scmx commented 2 years ago

I have run into the same thing. I use multiple talkback.requestHandler.

The problem seems to be that for every time a new requestHandler or server is created there is a line initializeLogger https://github.com/ijpiantanida/talkback/blob/ba5b4ebd1b4518e6f7bc34ad69e6aa8a6ec4bcbe/src/talkback-factory.ts#L10-L16 which modifies a global logger object to override logger.log with an instance of ConsoleLogger instead of NoopLogger. https://github.com/ijpiantanida/talkback/blob/ba5b4ebd1b4518e6f7bc34ad69e6aa8a6ec4bcbe/src/logger.ts#L67 and passes in the options of the current handler! So the logger becomes tied to the current handler.

The logger has a method formatMessage that takes only two arguments message and level. I have been overriding formatMessage myself to tweak its output, but I didn't understand why it printed for the wrong handler.

When formatMessage is called there is nothing to differentiate between different handlers so it is not enough to patch it.

ijpiantanida commented 2 years ago

Great call @scmx, the global logger was definitely a problem.

This should be fixed in v3.0.2