1
/*
2
Debug logger for any node.js server.
3

4
There is used both by the hub(s) and project(s).
5

6
This is an implementation of basically how winston works for us,
7
but using the vastly simpler super-popular debug module.
8
*/
9

10
// setting env var must come *BEFORE* debug is loaded the first time
11
process.env.DEBUG_HIDE_DATE = "yes"; // since we supply it ourselves
12
// otherwise, maybe stuff like this works: (debug as any).inspectOpts["hideDate"] = true;
13

14
import debug, { Debugger } from "debug";
15
import { mkdirSync, createWriteStream, statSync, ftruncate } from "fs";
16
import { format } from "util";
17
import { dirname, join } from "path";
18
import { logs } from "./data";
19

20
const MAX_FILE_SIZE_BYTES = 20 * 1024 * 1024; // 20MB
21

22
const COCALC = debug("cocalc");
23

24
let _trimLogFileSizePath = "";
25
export function trimLogFileSize() {
26
  // THIS JUST DOESN'T REALLY WORK!
27
  return;
28
  
29
  if (!_trimLogFileSizePath) return;
30
  let stats;
31
  try {
32
    stats = statSync(_trimLogFileSizePath);
33
  } catch(_) {
34
    // this happens if the file doesn't exist, which is fine since "trimming" it would be a no-op
35
    return;
36
  }
37
  if (stats.size > MAX_FILE_SIZE_BYTES) {
38
    const fileStream = createWriteStream(_trimLogFileSizePath, { flags: "r+" });
39
    fileStream.on("open", (fd) => {
40
      ftruncate(fd, MAX_FILE_SIZE_BYTES, (truncateErr) => {
41
        if (truncateErr) {
42
          console.error(truncateErr);
43
          return;
44
        }
45
        fileStream.close();
46
      });
47
    });
48
  }
49
}
50

51
function myFormat(...args): string {
52
  if (args.length > 1 && typeof args[0] == "string" && !args[0].includes("%")) {
53
    // This is something where we didn't use printf formatting.
54
    const v: string[] = [];
55
    for (const x of args) {
56
      try {
57
        v.push(typeof x == "object" ? JSON.stringify(x) : `${x}`);
58
      } catch (_) {
59
        // better to not crash everything just for logging
60
        v.push(`${x}`);
61
      }
62
    }
63
    return v.join(" ");
64
  }
65
  // use printf formatting.
66
  return format(...args);
67
}
68

69
function defaultTransports(): { console?: boolean; file?: string } {
70
  if (process.env.SMC_TEST) {
71
    return {};
72
  } else if (process.env.COCALC_DOCKER) {
73
    return { file: "/var/log/hub/log" };
74
  } else if (process.env.NODE_ENV == "production") {
75
    return { console: true };
76
  } else {
77
    return { file: join(logs, "log") };
78
  }
79
}
80

81
function initTransports() {
82
  if (!process.env.DEBUG) {
83
    // console.log("DEBUG is not set, so not setting up debug logging transport");
84
    return;
85
  }
86
  const transports = defaultTransports();
87
  if (process.env.DEBUG_CONSOLE) {
88
    transports.console =
89
      process.env.DEBUG_CONSOLE != "no" && process.env.DEBUG_CONSOLE != "false";
90
  }
91
  if (process.env.DEBUG_FILE != null) {
92
    transports.file = process.env.DEBUG_FILE;
93
  }
94
  let fileStream;
95
  if (transports.file) {
96
    const { file } = transports;
97
    // ensure directory exists
98
    mkdirSync(dirname(file), { recursive: true });
99
    // create the file stream; using a stream ensures
100
    // that everything is written in the right order with
101
    // no corruption/collision between different logging.
102
    // We use append mode because we mainly watch the file log
103
    // when doing dev, and nextjs constantly restarts the process.
104
    fileStream = createWriteStream(file, {
105
      flags: "a",
106
    });
107
    _trimLogFileSizePath = file;
108
    trimLogFileSize();
109
  }
110
  let firstLog: boolean = true;
111
  COCALC.log = (...args) => {
112
    if (!transports.file && !transports.console) return;
113
    if (firstLog && transports.file) {
114
      const announce = `***\n\nLogging to "${transports.file}"${
115
        transports.console ? " and console.log" : ""
116
      } via the debug module\nwith  DEBUG='${
117
        process.env.DEBUG
118
      }'.\nUse   DEBUG_FILE='path' and DEBUG_CONSOLE=[yes|no] to override.\nUsing e.g., something like DEBUG='cocalc:*,-cocalc:silly:*' to control log levels.\n\n***`;
119
      console.log(announce);
120
      if (transports.file) {
121
        // the file transport
122
        fileStream.write(announce);
123
      }
124
      firstLog = false;
125
    }
126
    // Similar as in debug source code, except I stuck a timestamp
127
    // at the beginning, which I like... except also aware of
128
    // non-printf formatting.
129
    const line = `${new Date().toISOString()}: ${myFormat(...args)}\n`;
130

131
    if (transports.console) {
132
      // the console transport:
133
      console.log(line);
134
    }
135
    if (transports.file) {
136
      // the file transport
137
      fileStream.write(line);
138
    }
139
  };
140
}
141

142
initTransports();
143

144
const DEBUGGERS = {
145
  error: COCALC.extend("error"),
146
  warn: COCALC.extend("warn"),
147
  info: COCALC.extend("info"),
148
  http: COCALC.extend("http"),
149
  verbose: COCALC.extend("verbose"),
150
  debug: COCALC.extend("debug"),
151
  silly: COCALC.extend("silly"),
152
};
153

154
type Level = keyof typeof DEBUGGERS;
155

156
const LEVELS: Level[] = [
157
  "error",
158
  "warn",
159
  "info",
160
  "http",
161
  "verbose",
162
  "debug",
163
  "silly",
164
];
165

166
class Logger {
167
  private name: string;
168
  private debuggers: { [level: string]: Debugger } = {};
169

170
  constructor(name: string) {
171
    this.name = name;
172
    for (const level of LEVELS) {
173
      this.debuggers[level] = DEBUGGERS[level].extend(name);
174
      this[level] = (...args) => {
175
        this.counter(level);
176
        // @ts-ignore
177
        this.debuggers[level](...args);
178
      };
179
    }
180
  }
181

182
  public isEnabled(level: Level): boolean {
183
    return this.debuggers[level].enabled;
184
  }
185

186
  public extend(name: string) {
187
    return new Logger(`${this.name}:${name}`);
188
  }
189

190
  private counter(level: Level): void {
191
    if (counter == null) return;
192
    counter.labels(this.name, level).inc(1);
193
  }
194
}
195

196
export interface WinstonLogger {
197
  error: Function;
198
  warn: Function;
199
  info: Function;
200
  http: Function;
201
  verbose: Function;
202
  debug: Function;
203
  silly: Function;
204
  extend: (name: string) => WinstonLogger;
205
  isEnabled: (level: Level) => boolean;
206
}
207

208
const cache: { [name: string]: WinstonLogger } = {};
209
export default function getLogger(name: string): WinstonLogger {
210
  if (cache[name] != null) {
211
    return cache[name];
212
  }
213
  // smash it over since we build Logger pretty generically so typescript
214
  // doesn't get it.  But we care that all *client* code uses the WinstonLogger
215
  // interface.
216
  return (cache[name] = new Logger(name) as unknown as WinstonLogger);
217
}
218

219
export { getLogger };
220

221
let counter: any = undefined;
222
export function setCounter(f) {
223
  counter = f;
224
}
225

226