Nov 17, 2024 5 min read k6

Building a Load Testing Framework using K6.io — Logging (Part 7)

In Part-06, we integrated multi-part requests with FormData for uploading files.
So far in our scripts we have been relying on the console.log() statements for logging and debugging.

In this article we will integrate a custom logger to replace the default console.log.

A custom logger can be very useful for several reasons, especially in complex applications or testing environments. Here are some key benefits:

1. Consistency and Control

Uniform Logging Format: Ensures that all log messages follow a consistent format, making it easier to read and analyze logs.
Centralized Configuration: Allows you to configure log levels, prefixes, and other settings in one place, ensuring consistent behavior across your application.

2. Flexibility

Customizable Log Levels: You can define and control which log levels are active, filtering out unnecessary information and focusing on what’s important.
Dynamic Prefixes: Adding dynamic prefixes (e.g., function names, timestamps) helps in identifying the source and context of log messages.

3. Enhanced Debugging

Conditional Logging: Log messages can be conditionally output based on the environment or specific conditions, which is useful for debugging without cluttering production logs.
Detailed Context: Custom loggers can include additional context or metadata with each log message, aiding in troubleshooting and debugging.

4. Performance

No-Operation for Disabled Levels: By using a no-operation function (noop) for disabled log levels, you avoid the performance overhead of unnecessary logging.
Efficient Log Handling: Custom loggers can be optimized for performance, ensuring that logging does not significantly impact the application’s performance.

5. Integration with Other Tools

Custom Metrics: In testing environments like k6, custom loggers can integrate with metrics and monitoring tools, providing valuable insights into test performance.
Error Handling: Custom loggers can be integrated with error tracking and alerting systems, ensuring that critical issues are promptly addressed.

6. Environment-Specific Behavior

Different Environments: Custom loggers can behave differently based on the environment (development, testing, production), providing more verbose logging in development and more concise logging in production.
Stderr Handling: In environments like k6, you might want to direct certain log levels to stderr for better visibility.

Let's begin!

Adding custom logger to k6

In order to add a logger to this framework lets start by creating a logger.js in 'common' directory:

Now add following code to the logger.js file:

//logger.js

const levels = ['debug', 'info', 'warn', 'error']
const noop = function () {}

export default function createLogger(options) {
  options = options || {}
  options.level = options.level || 'info'

  const logger = {}

  const shouldLog = function (level) {
    return levels.indexOf(level) >= levels.indexOf(options.level)
  }

  levels.forEach(function (level) {
    logger[level] = shouldLog(level) ? log : noop

    function log () {
      let prefix = options.prefix
      let normalizedLevel

      if (options.stderr) {
        normalizedLevel = 'error'
      } else {
        switch (level) {
          // 'debug' normalizedLevel to 'info'. o/w k6 will only print debug level logs with passing -v/--verbose flag.
          case 'debug': normalizedLevel = 'info'; break
          default: normalizedLevel = level
        }
      }

      if (prefix) {
        if (typeof prefix === 'function') prefix = prefix(level)
        arguments[0] =  prefix + " " + arguments[0]
      }

      if(normalizedLevel !== level){
        console[normalizedLevel](level.toUpperCase(), ...arguments)
      }
      else {
        console[normalizedLevel](...arguments)
      }

    }
  })

  return logger
}

Some of this code was taken from GitHub Gist. (Please contact for credits)

Explanation:

1) Log Levels and No-Operation Function:

let levels = ['debug', 'info', 'warn', 'error'];
let noop = function () {};

levels: An array of log levels in increasing order of severity.
noop: A no-operation function that does nothing. It is used to disable logging for levels below the configured level.

2) Logger Factory Function:

export default function createLogger(opts) {
  opts = opts || {};
  opts.level = opts.level || 'info';

The function takes an opts object as an argument, which can contain configuration options for the logger.
opts.level: The minimum log level to output. Defaults to 'info'

3) Logger Object and Should Log Function:

let logger = {};

let shouldLog = function (level) {
  return levels.indexOf(level) >= levels.indexOf(opts.level);
};

logger: An object that will hold the logging methods.
shouldLog: A function that determines if a message should be logged based on the current log level.

4) Creating Log Methods:

levels.forEach(function (level) {
  logger[level] = shouldLog(level) ? log : noop;

  function log() {
    let prefix = opts.prefix;
    let normalizedLevel;

For each log level, a method is added to the logger object.
If the log level should be logged (shouldLog(level) returns true), the method is set to log. Otherwise, it is set to noop.

5) Log Function:

    if (opts.stderr) {
      normalizedLevel = 'error';
    } else {
      switch (level) {
        case 'debug': normalizedLevel = 'info'; break;
        default: normalizedLevel = level;
      }
    }

    if (prefix) {
      if (typeof prefix === 'function') prefix = prefix(level);
      arguments[0] = prefix + " " + arguments[0];
    }

    if (normalizedLevel !== level) {
      consolenormalizedLevel, ...arguments);
    } else {
      consolenormalizedLevel;
    }
  }
});

normalizedLevel: Determines the actual log level to use. If opts.stderr is true, it is set to 'error'. Otherwise, 'debug' is normalized to 'info'.
prefix: If a prefix is provided, it is prepended to the log message. If the prefix is a function, it is called with the log level as an argument.
The log message is then output using console[normalizedLevel]. If the normalized level is different from the original level, the original level is included in the message.

6) Return Logger:

return logger;

The function returns the logger object with the configured log methods.

Integrating this code with framework:

Now that we have a custom logger ready, we can integrate it with any of the files for ex: iit.js,client.js,or any code/scripts/*.js files

Import the Logger:

import createLogger from '../common/logger.js';

Create a Logger Instance:

create the logger instance with desired level of logging and prefix for logs

const logger = createLogger({ level: 'info', prefix: '[k6-LoadTestFrameork]' });

Use the Logger:

Replace console.log statements with logger.info and logger.debug

logger.info('activeConfig NAME', init.getActiveConfig().NAME);
logger.info('activeConfig CONTENT', init.getActiveConfig().CONTENT);
logger.debug(`Loaded file: ${JSON.stringify(loadedFile)}`);
logger.info('Teardown data:', JSON.stringify(data));

replaced code with logger.js

By following these steps, you ensure that all logging in *.js is handled by the custom logger, providing consistent and configurable logging throughout your application.

Result:

Note:

logger.debug() is also displayed as an Info log but with a "DEBUG" prefix; because displaying the actual debug log will require passing -v verbose in the run command. and that will also show internal debug logs from k6 which will clutter the console view.

Summary:

In this article we saw how the logger.js file defines a logger factory function that creates a logger object with methods for different log levels (debug, info, warn, error). The logger only outputs messages at or above the configured log level. It also supports optional message prefixes and can normalize the 'debug' level to 'info' for environments like k6.

Ciao!