0

I have a typescript project using winston and winston-daily-rotate-file. At the start of the project I check for environment variables that are present. If not, I want to log the missing variable using logger.error(). But for some reason the error log is never created. The logs do appear in my console.

Note:

The logger and function to check environment variables come from a custom npm module, because I want to reuse this logic for all other projects of mine. So the logger is actually placed in node_modules/my-custom-project/util/logger.ts

Console output:
yarn run v1.22.19
$ ts-node src/index.ts
Debugger attached.
info: Starting project Test {"timestamp":"2023-01-19T07:49:53.342Z","type":"start-project"}
error: Missing environment variable DEFAULT_REQUIRED_VARIABLE {"timestamp":"2023-01-19T07:49:53.348Z"}
error: Exiting because of missing environment variables {"data":["DEFAULT_REQUIRED_VARIABLE"],"timestamp":"2023-01-19T07:50:05.447Z"}
node_modules/my-custom-project/util/logger.ts
import * as winston from "winston";
import DailyRotateFile from "winston-daily-rotate-file";

const infoTransport: DailyRotateFile = new DailyRotateFile({
  level: "info",
  filename: "./logs/%DATE%/combined.log",
  datePattern: "YYYY-MM-DD-HH",
  maxSize: "20m",
  maxFiles: "14d",
  utc: true,
});
const warnTransport: DailyRotateFile = new DailyRotateFile({
  level: "warn",
  filename: "./logs/%DATE%/warn.log",
  datePattern: "YYYY-MM-DD-HH",
  maxSize: "20m",
  maxFiles: "14d",
  utc: true,
});
const errorTransport: DailyRotateFile = new DailyRotateFile({
  level: "error",
  filename: "./logs/%DATE%/error.log",
  datePattern: "YYYY-MM-DD-HH",
  maxSize: "20m",
  maxFiles: "14d",
  utc: true,
});

const logger = winston.createLogger({
  format: winston.format.combine(
    winston.format.timestamp(),
    winston.format.json()
  ),
  transports: [infoTransport, warnTransport, errorTransport],
});

if (process.env.NODE_ENV !== "test") {
  logger.add(
    new winston.transports.Console({
      format: winston.format.simple(),
    })
  );
}

export default logger;
node_modules/my-custom-project/util/requireEnvironmentVariables.ts
export default (extraVariables: string[]): boolean => {
  let success = false;
  const missing: string[] = [],
    requiredVariables = [
      "DEFAULT_REQUIRED_VARIABLE",
      ...extraVariables,
    ];

  for (let variable of requiredVariables) {
    if (!(variable in process.env)) {
      missing.push(variable);
      logger.error(`Missing environment variable ${variable}`); // <-- no log file create, but log appears in my console?
    }
  }

  if (missing.length > 0) {
    handleError({
      error: {
        message: "Exiting because of missing environment variables",
        data: missing,
      },
      ...
    });
  } else {
    success = true;
  }
  return success;
};
index.ts
const run = async () => {
  let log: Log = {
    message: `Starting project ${process.env.PROJECT_NAME}`,
    type: "start-project",
    data: new Date().toISOString,
  };
  logger.info(log);
  if (!requireEnvironmentVariables(['NON_DEFAULT_REQUIRED_VARIABLE']) process.exit();
  ...
};

run().catch((error) => handleError(error));

I tried the following:

  • Moving node_modules/my-custom-project/util/logger.ts and node_modules/my-custom-project/util/requireEnvironmentVariables.ts to my local project.
  • Calling logger.info() before checking the variables. No log files are created.
  • If all environment variables are present, and the first logger.info() is called AFTER this function has ran, it seems to work fine?

Edit:

I found logger.on method, it can be used to listen to the finish event:

logger.on('finish', (info) => {
  // Still nog logs written here...
})

But the logs don't exist at that point. Also, the info parameter here is undefined and useless.

HotFix
  • 157
  • 1
  • 11

1 Answers1

0

I eventually found out that this issue is hard to solve with the winston logger. It has an issue open on GitHub about this. I resorted to pino where I found this example about MultiStreams. Eventually this was my solution:

import { createWriteStream, existsSync, mkdirSync } from "fs";
import path from "path";
import pino, { stdTimeFunctions } from "pino";
import pretty from "pino-pretty";

import getLogDir from "./getLogDir";
import getLogFileName from "./getLogFileName";
import LogSequence from "./LogSequence";

const logSequence = LogSequence.getInstance(),
  logDir = getLogDir();

let nextSequenceNumberFound = false,
  logFileName = getLogFileName(logSequence.sequence),
  logFilePath = "";

// Create logs folder if it does not exist
if (!existsSync(logDir)) mkdirSync(logDir, { recursive: true });

// Decide filename with unique sequence, within every hour the sequence gets upped
while (nextSequenceNumberFound === false) {
  logFilePath = path.join(logDir, logFileName);

  // Try to find file with sequence number
  let fileExists = existsSync(logFilePath);

  // If it exists, try to find the next one
  if (fileExists) {
    logSequence.incrementSequence();
    logFileName = getLogFileName(logSequence.sequence);

    // Else, we know what to call the next file
  } else nextSequenceNumberFound = true;
}

const fileStream = createWriteStream(logFilePath),
  streams = [
    { stream: fileStream },
    {
      stream: pretty({
        colorize: true,
        translateTime: true,
        ignore: "pid",
      }),
    },
  ];

const logger = pino(
  {
    enabled:
      process.env.NODE_ENV !== "test" && process.env.NODE_ENV !== "production",
    formatters: {
      level(label) {
        return { level: label };
      },
    },
    level: "debug",
    nestedKey: "payload",
    timestamp: stdTimeFunctions.isoTime,
  },
  pino.multistream(streams)
);

export default logger;

Then for example in my tests I could do:

beforeAll((done) => {
  logger.info("Testing...");
  logger.flush();

  done();
});

test("getLog", () => {
  fileStream.once("close", () => {
    // Log files are available here
  });
});
HotFix
  • 157
  • 1
  • 11