Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

refactor: removed "getLogger" usage #1556

Draft
wants to merge 44 commits into
base: main
Choose a base branch
from
Draft

Conversation

kirrg001
Copy link
Contributor

@kirrg001 kirrg001 commented Feb 11, 2025

refs https://jsw.ibm.com/browse/INSTA-13498

Reasons why we have to move away from getLogger('tracing/xxx'):

  • Overhead / Performance. We create and store (!) more then 70 logger child instances. See registry logic in logger.js.
  • We do not follow dependency injection, which makes it very hard to maintain the codebase. We always request a new instance on top of each file using getLogger('tracing/blubb') - without knowing what the actual logging instance is. We should only access config.logger in the init function of each module. This gives us control over the codeflow.
  • Logs disappear in the beginning of the application if you call getLogger too early e.g. logs from normalizeConfig did not appear from serverless correctly.
  • I have never used this feature. If we receive logs, I just copy the error message and search for it in the codebase.

I have not found a good reason to keep the child logger logic. We now create only one child logger: the instana internal logger if you provide a custom logger. Otherwise we only have one logger instance.

If we want to re-add log prefixes, we can easily do that by adding e.g. logger = config.logger.prefix('xxx'). This helper fn will wrap the log calls and automatically adds a prefix such as tracing/kafka: error msg.

  • measure bootstrap time (AWS + Locally)
  • fallback for let logger to prevent bugs
  • extract some changes in smaller PR's if possible

@kirrg001 kirrg001 force-pushed the refactor-remove-getlogger branch 2 times, most recently from 61df358 to 1a95836 Compare February 12, 2025 13:08
} else {
logger.debug(`Sending data to ${path}, ${agentOpts}`);
}
logger.debug(`Sending data to ${path}, ${agentOpts}`);
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note to me: revert

cmdline.init(config);
pidStore = _pidStore;

cpuSetFileContent = getCpuSetFileContent();
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

NOTE: Moved from root initialization to init fn. We should never initialize components on root.

// NOTE: By default we set our instana internal logger
config.logger = logger;

pidStore.init(config);
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

NOTE: We define & init the pidstore in the parent module (collector) and pass it on to all modules, who use the pidstore. Dependency injection.

const registry = {};
let instanaLogger;

class InstanaLogger {
Copy link
Contributor Author

@kirrg001 kirrg001 Feb 17, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

NOTE: The class instance makes it possible to update the logger without having to reinitialize all components.

It makes the old wrong logging design obsolete.

e.g.

  if (isReInit) {
    Object.keys(registry).forEach(loggerName => {
      const reInitFn = registry[loggerName];
      reInitFn(exports.getLogger(loggerName));
    });
    // cascade re-init to @instana/core
    logger.init(config);
  }

e.g.

exports.setLogger = function setLogger(_logger) {
  logger = _logger;
  config.logger = logger;
  instanaCore.logger.init(config);
};

e.g.

exports.setLogger = function setLogger(logger) {
  metricsModules.forEach(metricModule => {
    if (typeof metricModule.setLogger === 'function') {
      metricModule.setLogger(logger);
    }
  });
};

Look at these complicated code constructs.

@@ -45,7 +104,8 @@ exports.init = function init(config, isReInit) {
// we create later on.
parentLogger = uninstrumentedLogger({
name: '@instana/collector',
level: 'info'
level: 'info',
base: { threadId }
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

TODO: this removes pid & hostname


coreMetrics.registerAdditionalMetrics(sharedMetrics.allMetrics);
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

NOTE: Same here. No initialization on the root file.

// @ts-ignore - Cannot redeclare exported variable
exports.immediate = path.join(__dirname, '..', '..', '..', 'immediate.js');

if (!fs.existsSync(exports.immediate)) {
Copy link
Contributor Author

@kirrg001 kirrg001 Feb 17, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@@ -7,7 +7,7 @@

// NOTE: c8 bug https://github.com/bcoe/c8/issues/166
process.on('SIGTERM', () => {
process.disconnect();
process.disconnect && process.disconnect();
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

TODO: ?

@@ -47,6 +46,7 @@ exports.findAndRequire = function findAndRequire(baseDir) {
.filter(
moduleName =>
moduleName.indexOf('.js') === moduleName.length - 3 &&
// TODO: move the extra metrics into a separate folder
Copy link
Contributor Author

@kirrg001 kirrg001 Feb 17, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just noticed while coding. Bad code quality. Ignore this change if you want.

@@ -0,0 +1,163 @@
/*
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Putting it here. Same concept as our collector logger. Just with a little bit less logic.

@@ -36,32 +36,36 @@ let warningsHaveBeenLogged = false;
const disableCaCheckEnvVar = 'INSTANA_DISABLE_CA_CHECK';
const disableCaCheck = process.env[disableCaCheckEnvVar] === 'true';

if (process.env[proxyEnvVar] && !environmentUtil.sendUnencrypted) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just moved into init fn.

* @return {(...args: *) => *} A wrapped function which will forward the first call to `cb`
* and log any successive calls.
*/
exports.atMostOnce = function atMostOnce(name, cb) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Move the content of the file "atMostOnce" into this file for now, because I could not find a nice way to add an init fn to this little helper.

kirrg001 added a commit that referenced this pull request Feb 18, 2025
@kirrg001 kirrg001 force-pushed the refactor-remove-getlogger branch 3 times, most recently from 1848a47 to 32268f6 Compare February 18, 2025 07:57
kirrg001 added a commit that referenced this pull request Feb 18, 2025
refs https://jsw.ibm.com/browse/INSTA-13498

Extracted from #1556

With this refactoring, we can easily forward the config object now to the aws v3 pkg. Each class is instantiated with the config object, which contains the logger.
@kirrg001 kirrg001 force-pushed the refactor-remove-getlogger branch from 32268f6 to 3731ce9 Compare February 18, 2025 10:44
kirrg001 added a commit that referenced this pull request Feb 19, 2025
@kirrg001 kirrg001 force-pushed the refactor-remove-getlogger branch 2 times, most recently from 96425d4 to cbc832d Compare February 19, 2025 10:14
@kirrg001 kirrg001 force-pushed the refactor-remove-getlogger branch from cbc832d to d042d81 Compare February 19, 2025 11:10
@@ -6,24 +6,17 @@
'use strict';

const { util, uninstrumentedHttp, uninstrumentedFs: fs } = require('@instana/core');
const http = uninstrumentedHttp.http;
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sorted requires and variables. Just moved down


const circularReferenceRemover = require('./util/removeCircular');
const agentOpts = require('./agent/opts');
const pidStore = require('./pidStore');
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

pidStore is injected. See later comments.

const agentConnection = require('../agentConnection');
const agentOpts = require('../agent/opts');
const initializedTooLate = require('../util/initializedTooLate');
const metrics = require('../metrics');
const pidStore = require('../pidStore');
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same here. Dependency injection. pidStore is defined in the upper unit.

log.init(_config);
}

// TODO: The idea of having a config per parent module probably makes, sense
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not solved as part of this PR.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant