Integrate logs from debug module into logger

[jasonkuhrt]

What

• When enabling DEBUG=... we get a bunch of low-level trace-like logs from various libraries including santa itself

• These logs are not structured, example:

  ● info  santa:dev:boot 
  graphql-santa:cli:dev:compiler init +0ms
  graphql-santa:cli:dev:compiler applying ts-node register +1ms
  graphql-santa:file-watcher starting {
  paths: [
    '/Users/jasonkuhrt/projects/prisma-labs/graphql-santa-examples/sans-prisma/api'
  ],
  ignored: [ './node_modules', './.*' ],
  ignoreInitial: true,
  onAll: [Function: onAll],
  cwd: '/Users/jasonkuhrt/projects/prisma-labs/graphql-santa-examples/sans-prisma'
  } +0ms
  graphql-santa:cli:dev:watcher will spawn runner +0ms
  graphql-santa:cli:dev:watcher using runner module at /Users/jasonkuhrt/projects/prisma-labs/graphql-santa/dist/watcher/runner.js +1ms
  graphql-santa:cli:dev:watcher using child-hook-path module at /var/folders/6g/4nk3wj214d3998979vzfm_r80000gn/T/ts-node-dev-hook-3563675597664375.js +0ms
  graphql-santa:cli:dev:watcher file watcher is ready +13ms
  graphql-santa:cli:dev:runner starting context type extraction +0ms
  graphql-santa:compiler found addToContext call 'addToContext' +0ms
  graphql-santa:compiler found addToContext arg '() => {\n' + '  return {\n' + '    db: {\n' + '      users: {\n' + '        newton: {\n' + '          id: "1",\n' + '          birthyear: "1649",\n' + '          name: "Newton"\n' + '        }\n' + '      }\n' + '    }\n' + '  }\n' + '}' +1ms
  graphql-santa:compiler finished compiler extension processing with results {
  graphql-santa:compiler   contextTypeContributions: [
  graphql-santa:compiler     '{ db: { users: { newton: { id: string; birthyear: string; name: string; }; }; }; }'
  graphql-santa:compiler   ]
  graphql-santa:compiler } +26ms
  graphql-santa:cli:dev:runner finished context type extraction +1s
  graphql-santa:schema finding modules... +0ms
  graphql-santa:schema ...found [ 'api/schema' ] +719ms
  graphql-santa:schema ... found final set (with dirs traversed) [
  graphql-santa:schema   '/Users/jasonkuhrt/projects/prisma-labs/graphql-santa-examples/sans-prisma/api/schema/a.ts'
  graphql-santa:schema ] +1ms
  ● info  app:boot

• Make this integrate into the logger system, example: be JSON, at trace level, example:

  ● info  santa:dev:boot 
  — trace app:foo  --  a: 1  b: 2  c: three
  — trace app:foo  --  a: 1  b: 2  c: three
  — trace santa:cli:dev:compiler:init
  — trace santa:cli:dev:compiler:applying ts-node register
  — trace santa:file-watcher:starting --
  
  paths: [
    '/Users/jasonkuhrt/projects/prisma-labs/graphql-santa-examples/sans-prisma/api'
  ]
  ignored: [ './node_modules', './.*' ]
  ignoreInitial: true
  onAll: [Function: onAll]
  cwd: '/Users/jasonkuhrt/projects/prisma-labs/graphql-santa-examples/sans-prisma'
  
  — trace santa:cli:dev:watcher will spawn runner
  — trace santa:cli:dev:watcher using runner module at /Users/jasonkuhrt/projects/prisma-labs/graphql-santa/dist/watcher/runner.js

• investigation will be required to understand how well we can map these things, and what the MVP is, but some points we can notice now:

  • If level trace enabled, all DEBUG logs should thus be shown
  • debug component path mapped to logger concept

Why

• Ugly/confusing for user, two systems to deal with
• If we get #264 then that feature would be quite attractive here, given trace logs are verbose
• As-is, logs would not be parsed into JSON and in a deployed setting (sure production, but also maybe staging kinds of environments too), if ever enabled, likely would not work well, if at all
• log platform might drop them, wrap them in generic unknown/unhelpful schema
• brittle/intolerant downstream processes expecting JSON might fail in unexpected ways

How

• pino a feature like this in spirit already, we should study their method and learn (even use, maybe) what we can

[jasonkuhrt]

Open questions:

1. Would santa still use debug

   Could, maybe not to keeping our codebase simpler

2. How would we handle/react to the DEBUG environment variable

   LOG_LEVEL=trace --> DEBUG=*
   

   But what about this?

   DEBUG=* --> LOG_LEVEL=trace | +Warning? | Error? | ...

   • We could support it, but not advertise it
   • We could do a passthrough where if this env var is found, we do a raw passthrough to debug and let debug do its native behaviour
   • Consider this an escape hatch, especially until #264 since DEBUG offers filtering solution that we might not have ourselves for unknown amount of time.