pinojs / pino-pretty

🌲Basic prettifier for Pino log lines
MIT License
1.25k stars 149 forks source link

No color on node 12 server #220

Closed bohendo closed 3 years ago

bohendo commented 3 years ago

Noticed after upgrading to pino-pretty 6.0.0 so some problem was probably introduced by colorette in PR #218

In my utils I have:

import pino from "pino";
import prettifier from "pino-pretty";

export const getLogger = (level = "warn"): pino.Logger => pino({
  level,
  prettyPrint: {
    colorize: true,
    ignore: "pid,hostname,module",
    messageFormat: `[{module}] {msg}`,
    translateTime: true,
  },
  prettifier,
});

Then on my server I have:

import { getLogger } from "@valuemachine/utils";

import { env } from "./env";

const log = getLogger(env.logLevel).child({ module: "Utils" });
log.info(`Logger loaded!`);

Result is white text: Screenshot from 2021-08-24 13-53-14

Downgrading to pino-pretty 5.1.3 results in colored output: Screenshot from 2021-08-24 13-55-28

This server is based on the node:12.16.1-alpine3.11 docker image so it shouldn't be affected by colorette's problems w node v13

kibertoad commented 3 years ago

@jorgebucaran

kibertoad commented 3 years ago

@jorgebucaran Wonder if env.COLOR_TERM check needs to be added to colorette. any ideas what term alpine uses?

jorgebucaran commented 3 years ago

I'm not familiar with COLOR_TERM, but I think Alpine uses xterm.

jorgebucaran commented 3 years ago

Running docker run -it node:12.16.1-alpine3.11 sh and trying Colorette in the Node REPL produced the desired output.

kibertoad commented 3 years ago

@bohendo Could you share contents of your process.env when running under that environment?

kibertoad commented 3 years ago

@bohendo Ping? We'd love to fix this issue, but we need to understand which particular env values we could use in your particular case, looks like the one we already use are not sufficient in your environment.

bohendo commented 3 years ago

Could you share contents of your process.env when running under that environment?

process.env = {
  "HOME": "/root",
  "HOSTNAME": "81e0ffa75a6f",
  "NODE_VERSION": "14.15.4",
  "OLDPWD": "/root",
  "PATH": "/root/modules/server/node_modules/.bin:./node_modules/.bin:/root/node_modules/.bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin",
  "PWD": "/root/modules/server"
  "SHLVL": "1",
  "VM_COVALENT_KEY": "redacted",
  "VM_ETHERSCAN_KEY": "redacted",
  "VM_LOG_LEVEL": "info",
  "VM_PORT": "8080",
  "VM_PROD": "false",
  "YARN_VERSION": "1.22.5",
}

(env vars prefixed with VM_ were added by me)

Btw, I'm using bash in my container instead of sh, not sure if that makes a difference. For reference, the dockerfile I'm using to build this server is below

FROM node:12.16.1-alpine3.11
WORKDIR /root
ENV HOME /root
RUN apk add --update --no-cache bash curl git jq make openssl py-pip python 
RUN apk add --no-cache --repository="http://dl-cdn.alpinelinux.org/alpine/v3.8/main" --repository="http://dl-cdn.alpinelinux.org/alpine/v3.8/community" pdftk
RUN npm config set unsafe-perm true
RUN npm install -g npm@6.14.0
RUN pip install --upgrade pip fdfgen
RUN curl https://raw.githubusercontent.com/vishnubob/wait-for-it/ed77b63706ea721766a62ff22d3a251d8b4a6a30/wait-for-it.sh > /bin/wait-for && chmod +x /bin/wait-for
COPY ops ops
COPY dist dist

ENTRYPOINT ["bash", "ops/entry.sh"]
bohendo commented 3 years ago

Oh wow, I just noticed in the env: "NODE_VERSION": "14.15.4" probably bc this server uses nodemon & ts-node in dev-mode which is where I'm seeing the lack of color. So this could actually be an issue w colorette not playing nice w node versions >12

fwiw, the command being executed is:

  exec ./node_modules/.bin/nodemon \
    --delay 1 \
    --exitcrash \
    --ignore ./*.test.ts \
    --ignore ./*.swp \
    --legacy-watch \
    --polling-interval 1000 \
    --watch src \
    --exec "node -r ts-node/register" \
    src/entry.ts
kibertoad commented 3 years ago

@bohendo I don't think this is related to Node version, Node 14 should be fine. There doesn't seem to be anything in your env that would allow Colorette to understand that your terminal supports colours.

See lines 3-18 in https://github.com/jorgebucaran/colorette/blob/main/index.js

That said, I am very surprised that it used to work with Chalk in the past. See how they are doing their checks: https://github.com/chalk/supports-color/blob/main/index.js

@jorgebucaran I think what is happening is this: previously colorize: true used to work as a hard colourizing override, if it is enabled, then no further checks are being made, Chalk was instructed to try colourizing either way. There doesn't seem to be a way to do the same for Colourette, because it invokes all of its logic simply on import, there is no init function to call. Would you be open to adding support for instantiating encapsulated instances of Colourette that would not rely on global state for determining whether or not colours are enabled? If we are back to having to override shared state, I'm afraid we'd have to revert this change altogether.

jorgebucaran commented 3 years ago

I suggest opening an issue on Colorette so we can discuss your suggestion.

yuser1337 commented 3 years ago

You can use something like:

FORCE_COLOR=1 pino-pretty -c

My full example: ts-node-dev --respawn --poll -r tsconfig-paths/register src/server.ts | FORCE_COLOR=1 pino-pretty -c -t -l

It sucks obviously

mcollina commented 3 years ago

I'm currently suffering from the same problem.

I have

TERM=screen-256color

in my env.

kibertoad commented 3 years ago

@mcollina Will be fixed in the nearby future upstream, we've already discussed path forward with @jorgebucaran in https://github.com/jorgebucaran/colorette/issues/42

That's an interesting TERM, will check if we need to expand colorette condition list.

kibertoad commented 3 years ago

@mcollina I've checked colorette code, and it actually should work out-of-the-box with such ENV, unless you have "env.NO_COLOR"

update: actually, no, there are additional conditions. you also need to have "process.stdout.isTTY" @jorgebucaran Is that part actually necessary?

jorgebucaran commented 3 years ago

Which part: process.stdout.isTTY? Yes, IIRC that's how we check if we're running through a pipe.

mcollina commented 3 years ago

You should use https://nodejs.org/dist/latest-v16.x/docs/api/tty.html#tty_tty_isatty_fd with fd = 1 instead. process.stdout is not a TTY inside worker_threads.

mcollina commented 3 years ago

This should be fixed in the latest version of colorette, let us know.

bohendo commented 3 years ago

I've upgraded & am now using pino@6.13.2 & pino-pretty@7.0.0 & sadly, I still see the same lack of color as before.

Fwiw, process.stdout.isTTY is undefined and process.stdout.fd equals 1

I've updated my server's base image to node:14.17.6-alpine3.14

I've added export FORCE_COLOR=1 to my server's entry script so now I have color & I'm content w this solution. If you still want to fix it, let me know what other info you need & I'll do whatever I can to help.

mcollina commented 3 years ago

cc @kibertoad

mcollina commented 3 years ago

I think the problem is on our end as we do not enforce the colorize option properly.. that should take over any checks for TTY.

kibertoad commented 3 years ago

I know. I'm waiting for https://github.com/jorgebucaran/colorette/issues/42 to land in 2.0.0

bohendo commented 3 years ago

I've tested & confirmed that this issue is now 100% resolved as of version 7.0.1. Great job, thank you!