Help me understand the logs

Can you help me make sense of what this particular informational log means?

The “message” is just “Exit exit()”, but that doesn’t really tell me much. Is this message from a particular subsystem/application?

Here’s the code emitting that log:

export async function exit(args: {
  reason: string
  status: number
  error?: any
}) {
  logger().log(args.status === 0 ? LogLevels.info : LogLevels.warn, "exit()", {
    ...args,
    ending: ending()
  })

And the GELF formatter:

export class GelfLogFormatter implements LogFormatter {
  formatLogEntry(logEntry: LogEntry): string {
    const payload: Payload = {
      version: "1.1",
      level: level2syslog(logEntry.l) ?? 7,
      host: SimpleAppName,
      timestamp: logEntry.ts / 1000,
      short_message: stripAnsiEsc(
        uniq(compactBlanks([logEntry.ctx, logEntry.msg])).join(" ")
      ),
      full_message: map(logEntry.meta?.error, errorToVerbose)
    }

    return stringify({
      ...payload,
      ...extractFrom(logEntry.from),
      ...fromEntries(
        entries(prepMeta(logEntry.meta, 3) ?? {}).map(([k, v]) =>
          k === "id" ? undefined : ["_" + k, stringify(v)]
        )
      )
    })
  }

Getting back to your log entry:

  1. You can tell the process is a PhotoStructure “worker” (a way that sync parallelizes work) by the service field. This field will be main, web, sync, or worker. Only sync has workers currently.

  2. “ending()” is true, which means that something in that process already requested a shutdown and Endable instances are being told to end.

  3. “stdin:close” is the reason exit() got called. sync tells workers to exit, and then closes their streams (stdin, stdout, stderr) to ensure the process exits cleanly.

  4. I don’t know why there’s an error here: is this from the alpha.7 build?

Yes, from alpha.7… I don’t think it’s an error, I just want to be able to make sense of what I’m looking at.

A couple thoughts: if worker always belongs to another service, would it be possible report it as [service].worker? So, in this case, it would be sync.worker. Also, most other loggers fill this information in the application_name field. That’s not a big deal, as I can just rename it for photostructure in graylog, but I just wanted to point it out!

Lastly, while having everything split into fields is GREAT for searchability, it’s not so great for human-readability. If all of your log messages are consistent, then it’s easy enough in graylog to append fields together into something that IS human readable. However, it seems like your log messages have different fields depending on which process wrote the log. If it’s possible, perhaps you could make the message field a bit more fully fleshed out. As an example, in this case it could say sync sent command exit() to service worker for reason stdin:close.

This entire request is NOT IMPORTANT, but I wanted to get my thoughts down in case there comes a day when you want to tweak your logging.

Thanks again for everything you do with Photostructure!!!