Add metalsmith.debug/log method

[Zearin]

Summary

It would be awesome if there were some sort of convention for plugins and logging. Perhaps we could draft up a recommendation?

I’m just imagining something that users could pass to the plugin’s configuration as an option, or some such. It would still be up to the plugin authors to use it responsibly.

Rationale

One of Metalsmith’s strengths is its hands-off approach to plugins. This promotes experimentation, which IMO is a good thing.

It also promotes using lots of plugins. This is IMO also a good thing…until something goes wrong.

This leads to errors that become harder and harder to track down as the number of plugins increases.

• Did the error occurred while running newlyAddedPlugin? Or did newlyAddedPlugin work “correctly” but cause something to break further down the pipeline?
• If a single plugin performs multiple sub-steps, which one failed?

A set of logging conventions would provide a little unity in terms of user-friendliness, while still preserving the ultimate freedoms that Metalsmith plugins enjoy.

[woodyrew]

Metalsmith and many plugins use debug. Run your build with DEBUG=* node build.js to see all the debugging for Metalsmith and the plugins. I tend to run with DEBUG=*:info,*:error node build.js to see info and error messages.

It would be good to have a plugins best practices document.

[Zearin]

It would be good to have a plugins best practices document.

THIS. 👍

Encourages best practices while not restricting freedom or experimentation.

[Zearin]

(It’s been a while! :) Good to see Metalsmith dev is alive and well.)

Metalsmith and many plugins use debug.

TL;DR

Q: I checked out debug. I like it. But I’m curious—any reasons against npmlog ?

---

Reasoning

Personally, I love npmlog because it has good defaults, but allows you to really fine-tune it if you want: prefixes, optional heading, colors, pause/resume and flush messages that accumulated while paused, and common-sense log levels (that can be further fine-tuned if needed).

---

EDIT: Forgot I said this in my original post! /facepalm :P

The reason I’m interested in this is because of Metalsmith’s great simplicity. Metalsmith’s flexibility is that is basically a processing pipeline that you build with plugins. This is a wonderful, powerful design—and it encourages the use of many plugins.

But the more plugins you add, the more places there is for something to go wrong! So the more I embrace Metalsmith’s pluggable nature, the more likely I am to run into something I want to inspect at an arbitrary level of detail.

---

There is a long debate about whether the debug package’s major version should either move towards this sort of configurability, or maintain a small and minimalist API. In that discussion, TJ Holowaychuk said he thinks the debug package has already become more complex than its original intended design.

Failing that, maybe we could stick to Node.js’s builtin console package. Perhaps if it were pre-configured with sensible defaults, Metalsmith could export it as a ready-to-use logger for plugin authors.

(Regardless of the debugger, a good “Best Practices” doc for plugin authors is still a solid good idea.)

[leviwheatcroft]

@zerin debug sure does have it's limitations. I get what you're saying re: "more complex than originally intended", but that same thread does have significant support for improvements.

I think one of the big problems you would face in trying to change to a new defacto standard, is that you'd never really be able to leave debug behind. Suppose we wrote a best practice doc saying "use npmlog", loads of maintainers just wouldn't even be aware of the community change. Even when PRs are submitted many maintainers just aren't interested in reviewing & patching.

Usually I'm the last person to say "just keep doing what we're doing because it will suck to change", but in this case the sedentary nature of the plugin ecosystem will be a big problem to overcome.

Re: the possible improvements linked above, they notably include a middleware layer. I don't really understand how they intend to implement, but based on @thebigredgeek 's example, you might be able to, say, add middleware to redirect all debug output to npmlog.

Re: your original post about lots of plugins, difficult to track down.. I published metalsmith-debug-ui the other day which aims to alleviate this exact problem. Basically lets you step through the build process and presents the files & metadata structures in a nice navigable browser based ui after each plugin. It's new, needs some improvements, but generally works and is super effective! As an aside, debug-ui struggles with the same problem of trying to re-route debug output to the browser, until debug v3 is released debug-ui will require explicit support from plugins, which seems unlikely.

[thebigredgeek]

We are very much open to expanding debug's functionality. Please feel free to chime in on the v3 discussion issue.

[leviwheatcroft]

Having thought through this a little more, and reviewed the debug v3 discussion issue, it might be a good idea to have metalsmith core provide access to debug.

The problem with using debug in the decentralised way it's used in metalsmith is that there's no point from which you can effect all debug instances. For example, suppose you want to build with a cron job and store debug output, or in the case of metalsmith-debug-ui you want to listen to all debug output and display it in the browser as well as the console output.

Currently debug allows you to switch out debug.log like this:

import debug from 'debug'
const dbg = debug('metalsmith-awesome')
doNormalThing = debug.log
debug.log = (...) => {
  doCustomThing(args)
  doNormalThing(args)
}

This doesn't really work with metalsmith plugin style structure because whilst changing debug.log does change the log function for all instances (in other modules) created from that version of debug, plugins will depend on a variety of versions of debug. So changing debug.log will only effect the behaviour of some instances, not all.

Looking through the debug v3 discussion thread, I don't think that v3 is intended to resolve this difficulty. The middleware deal would merely allow more complex augmentations of debug.log but I think the underlying version problem would still exist.

One way to solve this would be for metalsmith core to expose access to debug through it's api, something like

import { Metalsmith, debug } from 'metalsmith'
dbg = debug('metalsmith-awesome')

then if you masked debug.log, you'd at least effect the behaviour of all plugins using the debug provided by metalsmith.

I get that metalsmith core is very resistant to including this kind of kitchen sink functionality, but I'll point out that this particular improvement is firstly, not possible to implement with a plugin (plugins can't mutate the metalsmith instance), and secondly concerns abstracting the metalsmith build environment rather than offering some kind of plugin type functionality.

As an aside, not having this kind of functionality hasn't really cost us much in the past, however the debug v3 improvements like middleware would be unusable by metalsmith & plugins.

[webketje]

Most core plugins now have an explicit Debug section in the readme.
In the new metalsmith.io docs, more elaborate debug docs will be provided.

As the logging guidelines issue is at my top-of-mind, I'm repurposing this issue as a feature request for a Metalsmith#debug method. Given that 2.4 will have a metalsmith.match method (see #338) the path for adding some utilities to core has been set.
I'm all for adding a Metalsmith#debug method, as this would allow plugins to require even less dependencies.

Another option would be to define it as peerDependency, but this would put more burden on the user and also we would not be able to guarantee compatibility.

The only remaining question I am split on is whether to call the method log or debug but I'm leaning towards debug as that would be more consistent with the library name and the readme sections