Eliminate high coupling to `debug`

Feature Description

Reduce coupling and footprint of minified file by using anylogger i.s.o debug

The problem

Currently, this library has a dependency on debug. Though that is an excellent library, this dependency has 2 major drawbacks:

This library is now forcing debug onto all developers that use this library (high coupling)
debug is 3.1kB minified and gzipped, directly adding 3.1kB to the minimum footprint of this library

The solution

Please have a look at anylogger. It's a logging facade specifically designed for libraries. It achieves these goals:

Decouple the library from the underlying logging framework
Reduce the minimal bundle footprint. Anylogger is only 370 bytes.

The decoupling is achieved by only including the minimal facade to allow client code to do logging and using adapters to back that facade with an actual logging framework. The reduced minimal footprint follows naturally from this decoupling as the bulk of the code lives in the adapter or logging library.

There are already adapters for some popular logging frameworks and more adapters can easily be created:

anylogger-console (to use the console i.s.o some logging framework)
anylogger-debug
anylogger-loglevel
anylogger-log4js
ulog (logger with native anylogger support)

If this library were to switch to anylogger, you could still install debug as a dev-dependency and then require('anylogger-debug') in your tests to have your tests work exactly as they always did, with debug as the logging framework, while still decoupling it from debug for all clients.

Workarounds

We can use a Webpack alias to alias debug to anylogger, then use an anylogger adapter to route it to the logging framework we choose, but it requires specific configuration in Webpack and it would be much better if it worked like this out of the box.

Contributions

I would be willing to contribute a Pull Request for this feature if the Knex developers agree it would be useful

Disclaimer

anylogger was written by me so I'm self-advertising here. However I do honestly believe it is the best solution in this situation and anylogger was written specifically to decrease coupling between libraries and logging frameworks because for any large application, devs typically end up with multiple loggers in their application because some libraries depend on debug, others on loglevel, yet others on log4js and so on. This hurts bundle size badly as we add multiple kB of logging libraries to it.

I don't see any reason why knex should change to any specific logging libraries at all... we already provide logging hooks, which user can override with any preferred library.

One can stub debug library out from package, if one likes to save that 3kB from packed lib. One has to do that anyways to prevent for example unnecessary dialects from lurking in.

If we are going to re-iterate knex's logging it need to be discussed throughly considering all side effects and preferably not include any libraries in by default.

I don't see any reason why knex should change to any specific logging libraries at all

That's kind of the idea of anylogger. It's not a logging library but just a facade, to decouple libraries from the actual logging framework.

One can stub debug library out from package

Do you mean with a Webpack alias? Or how would you do this?

In any case if you stub it out you also lose the logging. Personally, I like to leave some logging code, even in the production build, because it allows me to more easily diagnose problems that occur on the live site. But it is kinda annoying to have multiple loggers living in the app, each of which has slightly different output and needs to be configured differently etc. But consolidating all libraries in use by an app to use the same logger is tricky as most libraries are hard-coupled to their logger of choice. Decoupling that is the goal of anylogger. Getting a smaller footprint is just a happy side-effect of the decoupling.

If we are going to re-iterate knex's logging it need to be discussed throughly

Agreed! It's an important aspect of any library. I would be willing to prepare a branch for you that has debug replaced with anylogger, and maybe prepare a demo project that demonstrates how you could use this branch of Knex with anylogger to have Knex use e.g. loglevel to do it's logging instead of debug, just by installing a different adapter. Let me know if you are interested in this and I will make a PR. I find it's easier to discuss such things if you have an actual PR to base the discussion on.

In any case if you stub it out you also lose the logging

No. It should not lose logging. Knex has internal log handlers, which should be are still called, even if debug library implementation is dropped.

http://knexjs.org/#Installation-log

That is how you should be able to setup your own log library to be used by knex. No need to introduce additional dependencies.

Removing 'debug' library from knex is then a separate issue... that could be moved to some separate npm package which provides logger function implementations for debug lib for people who likes to maintain backwards compatible logging.

I still fail to see any benefit in introducing direct dependency to anylogger. You can provide knex-anylogger npm package, which provides logger functions with anylogger implementation and then allows one to use any of those backends it offers.

That way everyone can use their preferred logger and design is kept even more modular than with relying on anylogger.

anylogger unpacked size: 46.5 kB. Huh?..

Personally, I would be more in favour of making debug an optional dependency that is not used when not available. Not sure we need anything more advanced than that.

Personally, I would be more in favour of making debug an optional dependency that is not used when not available. Not sure we need anything more advanced than that.

I would like to make it so that one has to explicitly provide knex-legacy-logging to config or something like that to enable that. Automatic imports if something exists sounds a bit nasty. Specially if that debug comes from dependencies of some other library...

Thanks for all your comments guys! Enjoying the discussion 👍

Personally, I would be more in favour of making debug an optional dependency

Optional dependencies are very tricky on the web. It's very hard to get them right, because Webpack and other bundlers have to either include the dependency in the bundle, or not. They have to do that analysis at build time, which is why they want your require calls to be statically analyzable. Have a look at Webpacks docs on dependency management. They show this example:

require('./template/' + name + '.ejs');

What happens if you do something like this, where the filename you are requiring is not statically analyzable, is they will create a context with a folder name and a regex that matches all filenames in that folder that you could possible end up with. In this example it would be

Directory: ./template
Regular expression: /^.*\.ejs$/`

So Webpack would end up bundling all .ejs files in the ./template folder...

Another example is something like:

var debug
if (request.query.debug) {
  debug = require('debug')
}

Even though it seems like debug is optional, because Webpack cannot evaluate request.query.debug at build time, it will have to assume it might evaluate to true and thus it will include the debug package in the bundle anyway.

Usually this is not what we want and 'optional' dependencies like this don't help us.

So in general you cannot really use any runtime criteria to decide whether to include a dependency or not.... which makes sense if you think about it. Because if Webpack or some other bundler combines all your Javascript into one single bundle.js, then logically if there is any chance that some dependency might be required at runtime, it must be included in the bundle. So basically the only thing you can do is use some search replace magic... Currently what people often do is something like this:

var debug
if (process.env.NODE_ENV !== 'production') {
  debug = require('debug')
}
debug && debug('some debug logging')

This will make it optional on Node JS without any changes.

This would still not be statically analyzable though, but they then use something like Webpack's ProvidePlugin to basically search-replace process.env.NODE_ENV for a concrete string value that is static. Then when you make a production build and set process.env.NODE_ENV to 'production', after the search-replace the code will read:

var debug
if ('production' !== 'production') {
  debug = require('debug')
}
debug && debug('some debug logging')

and then the if around the require call is static and the minifier can figure out that the code inside the if is dead code and remove it, and that as a consequence the code debug && ... is also dead code and also remove that. Than it will notice debug is not used at all and remove it from the bundle completely through dead code removal.

BUT

The downside of this is that you are completely removing it at build time. And you need to guard every single line that does logging with an extra condition so it will become dead code in production. If you forget this just once, the entire module will still be included. So if, as an app developer, I include a bunch of libraries that depend on debug and just one of them is not creating builds where it is guarded in conditions like this, I still end up with debug in my bundle.

And, more importantly

I don't necessarily want to completely remove all logging from my app.... Making the dependency optional, if done right which is hard, only fixes the issue that we pull in 3.1kB of unwanted logging library. It does nothing to help us consolidate logging. I just want to use some other logging framework, not completely remove it. Maybe I want to use loglevel, or bunyan or log4js or whatever... I would like Knex to respect my choice for logging framework and use it, instead of forcing it's choice of logger on me. That's exactly what anylogger provides.

Not sure we need anything more advanced than that.

I think if you investigate a bit further, you will come to the conclusion that using 'optional dependencies' on the web is actually much more advanced than simply using a facade object. Anylogger is not magic. Actually, it's very simple. Please have a moment to look at the source of anylogger (just a single small file with mostly comments) then look at the full source code for anylogger-debug below and I think you can see it is not very advanced at all:

anylogger-debug.js

import anylogger from 'anylogger'
import debug from 'debug'

// override anylogger.ext() to make every log method use debug
anylogger.ext = function(logger) {
  var method = debug(logger.name)
  for (var level in anylogger.levels) {
    logger[level] = method
  }
  logger.enabledFor = debug.enabled.bind(logger, logger.name)
  return logger
}

Yeah, that's it! It's a very simple facade/adapter pattern.

http://knexjs.org/#Installation-log

That's great that you make this configurable! But... You did invent your own mechanism here... Just like many, many other libraries did. As an app developer, I have to learn each of these mechanisms and make sure I include the code to select my logging framework of choice for each of these libraries.

If Knex were to use anylogger and I'm installing Knex in my project, I can do this:

npm install --save knex anylogger debug anylogger-debug

index.js

require('anylogger-debug')
// do stuff with knex

and Knex (and all other libraries using anylogger) will start to use debug. However I can also do this:

npm install --save knex anylogger loglevel anylogger-loglevel

index.js

require('anylogger-loglevel')
// do stuff with knex

and now Knex and all those other libraries will be using loglevel instead.

So basically, if you replace debug with anylogger:

The minimal footprint goes down by about 2.7kB without needing to use optional dependencies with all their caveats on the web
The logging becomes completely pluggable without the need for log handlers or special configuration of any kind
The mechanism to configure the logging framework becomes uniform across all libraries using anylogger
Knex can simply forget about all of it and drop the code for configuring logging and the docs describing it. Instead we can simply add something like 'Knex uses anylogger so you can configure the logging exactly as you see fit. Read the anylogger docs for more info'.

anylogger unpacked size: 46.5 kB. Huh?..

That's the size of the package on NPM... includes sources and README etc. E.g. unpacked size of debug on NPM is 41.1 kB. But trust me, that's not the amount of code you will get in your bundle. Traditionally we measure the minified/gzipped size of the bundle that's generated for the web (as for Node JS, size is much less relevant). You can easily check the bundled size by using something like wzrd.in to create a 'browserified' bundle and then just zip that file and look at it's size. E.g for debug you can download wzrd.in/standalone/debug@latest (may take a minute or so on the first request as it's downloading and building debug in the background). You can then download wzrd.in/standalone/anylogger@latest and compare. But you can already see with the naked eye that there is a big difference:

debug, minified

!function(e){if("object"==typeof exports&&"undefined"!=typeof module)module.exports=e();else if("function"==typeof define&&define.amd)define([],e);else{("undefined"!=typeof window?window:"undefined"!=typeof global?global:"undefined"!=typeof self?self:this).debug=e()}}(function(){return function(){return function e(n,t,r){function o(i,c){if(!t[i]){if(!n[i]){var u="function"==typeof require&&require;if(!c&&u)return u(i,!0);if(s)return s(i,!0);var a=new Error("Cannot find module '"+i+"'");throw a.code="MODULE_NOT_FOUND",a}var f=t[i]={exports:{}};n[i][0].call(f.exports,function(e){return o(n[i][1][e]||e)},f,f.exports,e,n,t,r)}return t[i].exports}for(var s="function"==typeof require&&require,i=0;i<r.length;i++)o(r[i]);return o}}()({1:[function(e,n,t){var r,o,s=n.exports={};function i(){throw new Error("setTimeout has not been defined")}function c(){throw new Error("clearTimeout has not been defined")}function u(e){if(r===setTimeout)return setTimeout(e,0);if((r===i||!r)&&setTimeout)return r=setTimeout,setTimeout(e,0);try{return r(e,0)}catch(n){try{return r.call(null,e,0)}catch(n){return r.call(this,e,0)}}}!function(){try{r="function"==typeof setTimeout?setTimeout:i}catch(e){r=i}try{o="function"==typeof clearTimeout?clearTimeout:c}catch(e){o=c}}();var a,f=[],l=!1,C=-1;function d(){l&&a&&(l=!1,a.length?f=a.concat(f):C=-1,f.length&&p())}function p(){if(!l){var e=u(d);l=!0;for(var n=f.length;n;){for(a=f,f=[];++C<n;)a&&a[C].run();C=-1,n=f.length}a=null,l=!1,function(e){if(o===clearTimeout)return clearTimeout(e);if((o===c||!o)&&clearTimeout)return o=clearTimeout,clearTimeout(e);try{o(e)}catch(n){try{return o.call(null,e)}catch(n){return o.call(this,e)}}}(e)}}function m(e,n){this.fun=e,this.array=n}function h(){}s.nextTick=function(e){var n=new Array(arguments.length-1);if(arguments.length>1)for(var t=1;t<arguments.length;t++)n[t-1]=arguments[t];f.push(new m(e,n)),1!==f.length||l||u(p)},m.prototype.run=function(){this.fun.apply(null,this.array)},s.title="browser",s.browser=!0,s.env={},s.argv=[],s.version="",s.versions={},s.on=h,s.addListener=h,s.once=h,s.off=h,s.removeListener=h,s.removeAllListeners=h,s.emit=h,s.prependListener=h,s.prependOnceListener=h,s.listeners=function(e){return[]},s.binding=function(e){throw new Error("process.binding is not supported")},s.cwd=function(){return"/"},s.chdir=function(e){throw new Error("process.chdir is not supported")},s.umask=function(){return 0}},{}],2:[function(e,n,t){var r=1e3,o=60*r,s=60*o,i=24*s,c=7*i,u=365.25*i;function a(e,n,t,r){var o=n>=1.5*t;return Math.round(e/t)+" "+r+(o?"s":"")}n.exports=function(e,n){n=n||{};var t=typeof e;if("string"===t&&e.length>0)return function(e){if((e=String(e)).length>100)return;var n=/^((?:\d+)?\-?\d?\.?\d+) *(milliseconds?|msecs?|ms|seconds?|secs?|s|minutes?|mins?|m|hours?|hrs?|h|days?|d|weeks?|w|years?|yrs?|y)?$/i.exec(e);if(!n)return;var t=parseFloat(n[1]);switch((n[2]||"ms").toLowerCase()){case"years":case"year":case"yrs":case"yr":case"y":return t*u;case"weeks":case"week":case"w":return t*c;case"days":case"day":case"d":return t*i;case"hours":case"hour":case"hrs":case"hr":case"h":return t*s;case"minutes":case"minute":case"mins":case"min":case"m":return t*o;case"seconds":case"second":case"secs":case"sec":case"s":return t*r;case"milliseconds":case"millisecond":case"msecs":case"msec":case"ms":return t;default:return}}(e);if("number"===t&&!1===isNaN(e))return n.long?function(e){var n=Math.abs(e);if(n>=i)return a(e,n,i,"day");if(n>=s)return a(e,n,s,"hour");if(n>=o)return a(e,n,o,"minute");if(n>=r)return a(e,n,r,"second");return e+" ms"}(e):function(e){var n=Math.abs(e);if(n>=i)return Math.round(e/i)+"d";if(n>=s)return Math.round(e/s)+"h";if(n>=o)return Math.round(e/o)+"m";if(n>=r)return Math.round(e/r)+"s";return e+"ms"}(e);throw new Error("val is not a non-empty string or a valid number. val="+JSON.stringify(e))}},{}],3:[function(e,n,t){n.exports=function(n){function t(e){let n=0;for(let t=0;t<e.length;t++)n=(n<<5)-n+e.charCodeAt(t),n|=0;return r.colors[Math.abs(n)%r.colors.length]}function r(e){let n;function i(...e){if(!i.enabled)return;const t=i,o=Number(new Date),s=o-(n||o);t.diff=s,t.prev=n,t.curr=o,n=o,e[0]=r.coerce(e[0]),"string"!=typeof e[0]&&e.unshift("%O");let c=0;e[0]=e[0].replace(/%([a-zA-Z%])/g,(n,o)=>{if("%%"===n)return n;c++;const s=r.formatters[o];if("function"==typeof s){const r=e[c];n=s.call(t,r),e.splice(c,1),c--}return n}),r.formatArgs.call(t,e),(t.log||r.log).apply(t,e)}return i.namespace=e,i.enabled=r.enabled(e),i.useColors=r.useColors(),i.color=t(e),i.destroy=o,i.extend=s,"function"==typeof r.init&&r.init(i),r.instances.push(i),i}function o(){const e=r.instances.indexOf(this);return-1!==e&&(r.instances.splice(e,1),!0)}function s(e,n){const t=r(this.namespace+(void 0===n?":":n)+e);return t.log=this.log,t}function i(e){return e.toString().substring(2,e.toString().length-2).replace(/\.\*\?$/,"*")}return r.debug=r,r.default=r,r.coerce=function(e){return e instanceof Error?e.stack||e.message:e},r.disable=function(){const e=[...r.names.map(i),...r.skips.map(i).map(e=>"-"+e)].join(",");return r.enable(""),e},r.enable=function(e){let n;r.save(e),r.names=[],r.skips=[];const t=("string"==typeof e?e:"").split(/[\s,]+/),o=t.length;for(n=0;n<o;n++)t[n]&&("-"===(e=t[n].replace(/\*/g,".*?"))[0]?r.skips.push(new RegExp("^"+e.substr(1)+"$")):r.names.push(new RegExp("^"+e+"$")));for(n=0;n<r.instances.length;n++){const e=r.instances[n];e.enabled=r.enabled(e.namespace)}},r.enabled=function(e){if("*"===e[e.length-1])return!0;let n,t;for(n=0,t=r.skips.length;n<t;n++)if(r.skips[n].test(e))return!1;for(n=0,t=r.names.length;n<t;n++)if(r.names[n].test(e))return!0;return!1},r.humanize=e("ms"),Object.keys(n).forEach(e=>{r[e]=n[e]}),r.instances=[],r.names=[],r.skips=[],r.formatters={},r.selectColor=t,r.enable(r.load()),r}},{ms:2}],4:[function(e,n,t){(function(r){t.log=function(...e){return"object"==typeof console&&console.log&&console.log(...e)},t.formatArgs=function(e){if(e[0]=(this.useColors?"%c":"")+this.namespace+(this.useColors?" %c":" ")+e[0]+(this.useColors?"%c ":" ")+"+"+n.exports.humanize(this.diff),!this.useColors)return;const t="color: "+this.color;e.splice(1,0,t,"color: inherit");let r=0,o=0;e[0].replace(/%[a-zA-Z%]/g,e=>{"%%"!==e&&(r++,"%c"===e&&(o=r))}),e.splice(o,0,t)},t.save=function(e){try{e?t.storage.setItem("debug",e):t.storage.removeItem("debug")}catch(e){}},t.load=function(){let e;try{e=t.storage.getItem("debug")}catch(e){}!e&&void 0!==r&&"env"in r&&(e=r.env.DEBUG);return e},t.useColors=function(){if("undefined"!=typeof window&&window.process&&("renderer"===window.process.type||window.process.__nwjs))return!0;if("undefined"!=typeof navigator&&navigator.userAgent&&navigator.userAgent.toLowerCase().match(/(edge|trident)\/(\d+)/))return!1;return"undefined"!=typeof document&&document.documentElement&&document.documentElement.style&&document.documentElement.style.WebkitAppearance||"undefined"!=typeof window&&window.console&&(window.console.firebug||window.console.exception&&window.console.table)||"undefined"!=typeof navigator&&navigator.userAgent&&navigator.userAgent.toLowerCase().match(/firefox\/(\d+)/)&&parseInt(RegExp.$1,10)>=31||"undefined"!=typeof navigator&&navigator.userAgent&&navigator.userAgent.toLowerCase().match(/applewebkit\/(\d+)/)},t.storage=function(){try{return localStorage}catch(e){}}(),t.colors=["#0000CC","#0000FF","#0033CC","#0033FF","#0066CC","#0066FF","#0099CC","#0099FF","#00CC00","#00CC33","#00CC66","#00CC99","#00CCCC","#00CCFF","#3300CC","#3300FF","#3333CC","#3333FF","#3366CC","#3366FF","#3399CC","#3399FF","#33CC00","#33CC33","#33CC66","#33CC99","#33CCCC","#33CCFF","#6600CC","#6600FF","#6633CC","#6633FF","#66CC00","#66CC33","#9900CC","#9900FF","#9933CC","#9933FF","#99CC00","#99CC33","#CC0000","#CC0033","#CC0066","#CC0099","#CC00CC","#CC00FF","#CC3300","#CC3333","#CC3366","#CC3399","#CC33CC","#CC33FF","#CC6600","#CC6633","#CC9900","#CC9933","#CCCC00","#CCCC33","#FF0000","#FF0033","#FF0066","#FF0099","#FF00CC","#FF00FF","#FF3300","#FF3333","#FF3366","#FF3399","#FF33CC","#FF33FF","#FF6600","#FF6633","#FF9900","#FF9933","#FFCC00","#FFCC33"],n.exports=e("./common")(t);const{formatters:o}=n.exports;o.j=function(e){try{return JSON.stringify(e)}catch(e){return"[UnexpectedJSONParseError]: "+e.message}}}).call(this,e("_process"))},{"./common":3,_process:1}]},{},[4])(4)});

compare with

anylogger, minified

!function(e){if("object"==typeof exports&&"undefined"!=typeof module)module.exports=e();else if("function"==typeof define&&define.amd)define([],e);else{("undefined"!=typeof window?window:"undefined"!=typeof global?global:"undefined"!=typeof self?self:this).anylogger=e()}}((function(){var define,module,exports;return function e(n,r,o){function t(i,u){if(!r[i]){if(!n[i]){var l="function"==typeof require&&require;if(!u&&l)return l(i,!0);if(f)return f(i,!0);var a=new Error("Cannot find module '"+i+"'");throw a.code="MODULE_NOT_FOUND",a}var c=r[i]={exports:{}};n[i][0].call(c.exports,(function(e){return t(n[i][1][e]||e)}),c,c.exports,e,n,r,o)}return r[i].exports}for(var f="function"==typeof require&&require,i=0;i<o.length;i++)t(o[i]);return t}({1:[function(require,module,exports){var m=Object.create(null),a=function(e,n){return e?m[e]||(m[e]=a.ext(a.new(e,n))):m};a.levels={error:1,warn:2,info:3,log:4,debug:5,trace:6},a.new=function(n,c,r){return eval("r={'"+n+"':function(){a.log(n,[].slice.call(arguments))}}[n]"),r.name?r:Object.defineProperty(r,"name",{get:function(){return n}})},a.log=function(e,n){m[e][n.length>1&&a.levels[n[0]]?n.shift():"log"].apply(m[e],n)},a.ext=function(e,n){for(v in n="undefined"!=typeof console&&console,a.levels)e[v]=n&&(n[v]||n.log)||function(){};return e},module.exports=a},{}]},{},[1])(1)}));

@Download one more time... why couldn't anylogger be a separate knex-anylogger package that provides the support for knex?

Knex already provides very simple and small footpring logging hooks and then one could setup knex with anylogger for example like this:

const knex = require('knex')({
  client: 'pg', 
  log: require('knex-anylogger')
});

Is there any (good) reason why knex should be tightly coupled with anylogger instead of providing it as a separate package?

Hi @elhigu

one more time... why couldn't anylogger be a separate knex-anylogger package that provides the support for knex?

Yes I think that could definitely be possible.

one more time...

I guess you are saying it this way because I failed to address your previous comment

I still fail to see any benefit in introducing direct dependency to anylogger.

I'm so sorry about that you are absolutely right. I kinda went overboard in my enthousiasm there. So I did fail to address this. You are right. There is no benefit to introducing a direct dependency to 'anylogger'. If possible, I would avoid it. However, I am proposing to replace one direct dependency with another. To replace the direct dependency on debug (3.1kB) with one on anylogger (370 bytes). In more conceptual terms, I want to replace a direct dependency on a specific logging framework with a direct dependency on a facade object. The facade object is not a logger. In fact standalone it's basically one big fancy noop-factory. However it is specifically designed to be a very generic facade that can be used to do all kinds of logging, just by backing it with a suitable logging framework via an adapter. Basically, anylogger is my implementation of your logger class, made way more generic, factored out into a separate NPM package and supplemented with a bunch of adapters to connect it to e.g. debug and loglevel etc.

Let me be a bit more specific. I perused the source code a bit and I see that Knex has 2 separate logging mechanisms going on. Correct me if I'm wrong though because I didn't do a full deep dive in the code. But from what I've seen so far I think it's

Doing it's own internal debug logging with debug
Has a logger class that accepts log methods from configuration, defaulting to the console methods.

I guess what you are proposing as knex-anylogger would use the logger class from knex to tie the second mechanism into anylogger. That would certainly work. But from the big picture perspective it is not the most desirable option I think. Because if I as an application developer am using 10 libraries lke Knex it would be somewhat annoying to have to install a separate adapter for each library. Instead it would be much better if the libraries use the facade object instead of the console or some specific logger directly. Then I as an app developer can just install one adapter to connect the facade object to my chosen logging mechanism.

May I propose that we go one step further? How about we replace both debug and the console with anylogger? This would:

Unify the two logging mechanisms
Decouple from debug
Decouple from the console

The way I would do that is this:

I would

npm uninstall --save debug && npm install --save anylogger
npm install --save-dev debug anylogger-debug

The second line uses the anylogger-debug adapter to bring debug back in, but decoupled for the client code. In e.g. the tests I would add

require('anylogger-debug')

so that logging would be going through debug as always in the tests.

Then in the codebase search-replace require('debug') => require('anylogger') to decouple completely from debug.

Then I would make the logger class use anylogger instead of the console as the default/fallback methods. This way:

Knex remains backward-compatible in terms of API and configuration
Knex has no runtime dependency on any specific logging framework anymore, only on the anylogger facade object
Both the internal/debug logging of Knex as well as the logging from the logger class are unified
Knex will automatically take part in logger configuration with anylogger adapters
Knex logging can still be overridden by supplying log methods in the config as it always could

As far of taking part in the anylogger configuration, what I mean by that is that if an app developer decides he wants to use debug as the logger, he would

npm install --save knex debug anylogger anylogger-debug

and place

require('anylogger-debug')

in his entry point. If instead he prefers loglevel for example, he would

npm install --save knex loglevel anylogger anylogger-loglevel

and add

require('anylogger-loglevel')

in his entry point. Knex would automatically use the chosen logger,

I am willing to prepare a PR to demonstrate this if you are interested in seeing what it would look like. It would be interesting I think to make a bunch of test projects to combine Knex with debug and with loglevel and see the effect of having all logging be unified and pluggable.

Above a PR that demonstrates it.

If you want to quickly test replacing one logger with another in this setup, you can:

npm install loglevel anylogger-loglevel

and then in test/testInitializer.js change

require('anylogger-debug')

require('anylogger-loglevel')

Then run npm test again and see the logging output change.

Ok, sounds like we need to discuss if we like to keep that debug -kind of logger at all.

I never liked the fact that there are multiple loggers with multiple ways to enable them. I would prefer to change all the logging to be changed to be printed through configured log handlers, instead of trying to incrementally improve the bad way. Though it might be very difficult to get rid of global logging functions so we actually might need to drop the instance specific loggers and just provide hooks for setting up global loggers for knex.

Anyways if we are going to the route of having only global logger I still don't see any reason why we should incrementally change one opinionated library to another one.

I still find it a lot better route for knex to just provide internal global hooks for logging to prevent need for tightly coupling knex to a library (that might be good), but is not widely used and could vanish or to be abandoned at anytime (remember leftpad that actually was widely used).

I've thought about this now few days and all the time I'm more convinced that even that the logging system needs refurbishing, we should not relay on any specific logging library, but just provide hooks which allows to plug-in user preferred logger. That is even more modular, simple and robust than using anylogger as a intermediator.

So setting up global logger hooks to use anylogger would be something like this:

const Knex = require('knex');
Knex.setLogger(require('knex-anylogger'));

I never liked the fact that there are multiple loggers with multiple ways to enable them.

I'm not sure what you mean here with 'multiple loggers'. Are you talking about e.g. 'knex:cli', 'knex:client', 'knex:tx' etc? Or are you referring to multiple different ways to log (e.g. with debug or console or other libraries)?

As far as global goes, I think you can do var log = require('debug')('knex') in all your files if you want. It's still a local variable, just getting the same logger assigned to it by debug... If that's what you mean?

const Knex = require('knex');
Knex.setLogger(require('knex-anylogger'));

I can see how this is a great way to completely decouple it. However, just practically speaking, it does require me as the app developer to know this (opiniated) API specifically for Knex. You could say you are now coupled to Knex.setLogger... You see no matter which way you come up with to configure the logging for Knex, you are essentially inventing an API. And there will be many more libraries I'm using so I end up having to learn many of these APIs. What I'm hoping for anylogger to become is a 'standard' API to configure logging for libraries so that we can have uniform configuration for app developers.

Anyways if we are going to the route of having only global logger I still don't see any reason why we should incrementally change one opinionated library to another one.

Mmm yes I understand. I tried to make anylogger as unopiniated as possible. Basically it's API is a merge of debug, loglevel and the console. I did some research, checking out many logging packages and looking at what the client code looks like and tried to make the anylogger API in such a way that for most loggers out there, it's a simple search-replace to change to anylogger. As far as being opiniated, I think the most opiniated pieces of it are:

The way that loggers are created, matching how debug does it
The first parameter to the logger function being interpreted as a level when it matches a level name
The fact that there are the levels error, warn, info, log, debug, trace
The fact that level names must be mapped to a numeric and exposed under anylogger.levels
The fact that loggers must have names
The enabledFor function

Most of these things come from pragmatism. Having log creation matching debug's way makes for a smooth migration path, as I think the PR I submitted shows. The first parameter being interpreted as the level to log at is used in some other libraries out there, easy to implement and does not interfere with debug-style loggers so it increases operability to have it. The levels were derived directly from the console API, which is as close to a logging standard as we have in Javascript. And you can see in the PR how easy that made changing code from using the console directly, to using anylogger. The mapping of level names to numbers is used in nearly all loggers that support levels and anylogger explicitly leaves the order and uniqueness of the values undefined. Most libraries out there require or at least allow loggers to have names, and this is also my experience in other environments (e.g. Java). Having anonymous loggers can become a configuration nightmare. The need for the enabledFor function derives from the fact that the numeric values are undefined, so it is the only way to know in advance whether a message at some level will actually be logged. This is needed sometimes (rarely) for performance reasons.

So yes it's opiniated. But we really need some kind of 'standard' to emerge if we want to go forward with logging in the Javascript ecosystem. At the moment it's a mess when it comes to logging. The console is still not really standardized and even when it finally is, it's not enough. We want to be able to redirect our logging (to a file, network server etc), format it (include date/time, logger name, performance metrics etc) and configure log granularity (levels, thresholds) and the console really doesn't offer it. I don't agree with many eslint rules, but the no-console one I wholeheartedly agree with. If a library logs directly to the console, it becomes unconfigurable from outside unless we somehow monkey-patch the console. Monkey-patching a global (native!) object is not where we want to be. Of course libraries can include configuration mechanisms like Knex does. But we end up with an enormous complex system as each library comes up with their own mechanism. And of course many libraries will simply not offer this option. For app developers that want to take control of logging, the current state of affairs is terrible. You have to dig into the specifics of many libraries, write all kinds of custom code and still end up with a bundle with 3 loggers in it and many messages being logged that cannot be configured, or with multiple config sources.

What prompted me to start building anylogger two years ago, was the frustration as an app developer that i have so little control over the logging, and the frustration as a library developer that I was forcing my library users into a choice about the logger that the library has nothing to do with. The fact that one of my libraries is ulog made it even worse because obviously I want to use my own logger in my other libraries, but at the same time I don't want to force it upon other devs as I realize it is niche and unproven... How can I easily allow devs to use it, without forcing it upon them?

I come from Java and there we at one point had the same problem, with two nearly identical but different loggers dominating the eco system, until at some point someone built slf4j and library builders actually started to use it and it made it much better for app developers. I'm hoping anylogger can do the same for the Javascript ecosystem.

What I am hoping anylogger can become someday is a 'standard' way for libraries to allow customization of their logging. I am hoping others will pick up the ball and run with it and that it will one day be enough to

npm install --save all the libs im using plus anylogger and my-favorite-logger-with-native-anylogger-support

Until that day comes, I think anylogger still helps. I have a bunch of adapters now, and I'm playing with the idea of building some reverse adapters as well. At the moment I can already use a Webpack alias to alias debug to anylogger as they are basically compatible, but I cannot do this with e.g. loglevel as it has a slightly different signature for creating the logger: loglevel.getLogger(name) i.s.o. debug(name) or anylogger(name). It's close though. So what I'm planning to do is create a reverse adapter loglevel-anylogger that will adapt anylogger to the loglevel signature so I can use that adapter in a Webpack alias to reroute loglevel to anylogger as well. But of course it would be much nicer if I wouldn't need Webpack aliasses. And even better if logging libraries start supporting the anylogger api so we don't even need an adapter either! It would be a great day if I ever live to see it but I intend on keep working on getting there. 👍

Basically, I want to do your log configuration work for you/with you. I'm an independent developer, doing this in his spare time, for free, and I'm not going away. I'm in this for the long haul. And I welcome all help. So if you/Knex decide to adopt this and you find you run into issues I will take those seriously. And if you come up with good ideas I will welcome your contributions. Log configuration is a problem that nearly every library has. And just building a 'better' logger is not the answer. We need to standardize the mechanism for the app developer to choose, instead of making the choice for him. And hey if they end up choosing ulog, my personal pet logger project 15 years in the making, that's great! But if they don't, at least I want my other libraries to still be just as useful for them if they use debug or whatever else.

I'm not sure what you mean here with 'multiple loggers'. Are you talking about e.g. 'knex:cli', 'knex:client', 'knex:tx' etc? Or are you referring to multiple different ways to log (e.g. with debug or console or other libraries)?

One that is using knex instance log hooks and is enabled with debug: true configuration attribute and another one that is done with debug library and enabled with environment variable. Two separate systems and one of them shouldn't exist.

I can see how this is a great way to completely decouple it. However, just practically speaking, it does require me as the app developer to know this (opiniated) API specifically for Knex. You could say you are now coupled to Knex.setLogger... You see no matter which way you come up with to configure the logging for Knex, you are essentially inventing an API. And there will be many more libraries I'm using so I end up having to learn many of these APIs.

Yes. That is true. Not too much to request from knex user's. By default if not set it could use for example console log for outputting log messages.

What I'm hoping for anylogger to become is a 'standard' API to configure logging for libraries so that we can have uniform configuration for app developers.

If it will be at some point standard logging library, then it will make sense to consider including it as a part of knex. Though debug was a standard once and now it is not. So having knex decoupled completely from logging libraries is more future proof way to deal with it.

Pretty much only down side of providing support for anylogger as a separate library is that anylogger will not be downloaded with every knex install by default. Though it could be mentioned in knex documentation with examples how to set it up.

I do understand and agree on ideological reasons of having the one true logger, but I don't see that it is beneficial for knex at the moment.

I hear you. Maybe in a year or so I can come back to you if it does get picked up 👍

About your proposal:

const Knex = require('knex');
Knex.setLogger(require('knex-anylogger'));

I think Knex.setLogger does not (yet) exist right? We could consider making it like this:

app.js

const Knex = require('knex');
require('knex-anylogger')
// knex is configured automagically...

knex-anylogger.js

require('knex').setLogger(require('anylogger'))

I propose it this way because it's a closer match to how the rest of anylogger configuration works and this does not require the library user to learn about Knex.setLogger. So it hides the implementation details.

I'm a bit busy at the moment but probably next week I have some time. I could try to unify Knex logging using a mix of your and my proposals:

Remove dependency on debug
Unify all logging to use the logger class
Make logging configurable via Knex.setLogger (or maybe Knex.setLogFactory?)
Make a package knex-anylogger that would configure Knex to use anylogger

Let me now if you would like to see a PR for this 👍

@kibertoad do we want to remove knex instance specific loggers and use global logging everywhere? Or maybe we could just first check out if the instance based logging could be used everywhere?

For global logging with Node, we could eliminate any dependency at all, provided the minimum target version is high enough:

Node v0.11.3 added util.debuglog, which lets you log to a log channel that can be flipped on using NODE_DEBUG environment config instead of DEBUG
Node v14.9.0 added an alias, util.debug(section), to make "is this channel on?" checking more obviously not itself a log statement.

But browser support would require a polyfill for the Node API. (Which is what we already effectively have through the debug package, at the cost of also including debug when targeting Node.)

@jeremy-w Would you be open to submitting a PR adding optional support for Node API here with fallback to (optional) debug?

I’ll take a look. The situation around optional packaging and npm seems less than clear, so I’d appreciate some direction before beginning package surgery. 😸

Assuming:

We do not want NPM to install debug unless especially asked for it.
We want to leave the door open to browser usage, so cannot assume util.debuglog will be there. (Is this indeed a concern?)

The two best options look to be:

Fully optional: Omit the debug package entirely from any listing in package.json. Try to require it, and if it fails, use Node util.debuglog. If that also fails (eg targeting browser without debug package bundled), throw.
Optional peer: Include the debug package in peer dependencies. Use peerDependenciesMeta to stop npm 7 from “helpfully” autoinstalling it.

(Not a good option IMO, but feels like it should be, so it needs mentioning: list it as an optional dependency in package.json. The problem here is NPM sees these as opt OUT rather than opt IN - more like “omissible packages” than a package variant in a desktop packaging system.)

I’m leaning towards the “optional peer” flavor, as it is more discoverable and allows expressing version compatibility ranges. I’m not sure the paranoia around whether the util module is present or not is required or not.

@jeremy-w I agree that optional peer provides better developer experience. Since you've already mentioned browser as a concern, I think we should handle cases when util is not available gracefully.

It looks like browserify (which seems to be the main target for the “browser” field in our package.json) includes a polyfill for node’s util module.

Is there a browser test suite I should run as a check?

I was surprised to see peerDependenciesMeta but no accompanying peerDependencies. Is there a story there?

@jeremy-w There is not one yet, but if you could create a simple smoke one, that would be awesome. Story is this: https://github.com/knex/knex/issues/4437

Thanks! It’s unfortunate - keeping just meta loses the ability to specify a version bound. The package.json docs and examples sure make it sound like peerdeps + optional together can opt out of autoinstall and render them truly optional:

Marking a peer dependency as optional ensures npm will not emit a warning if the soy-milk package is not installed on the host. This allows you to integrate and interact with a variety of host packages without requiring all of them to be installed. (emphasis added)

I can test against a recent Node + npm to see if we can re-introduce the peerDeps and their versions without npm 7 going wild with the installs.

For the browser smoketest, what driver would be most relevant? Sqlite? Mysql?

@jeremy-w Would MySQL even work inside browser? Probably in-memory SQLite is about the only sensible option. Sure, would appreciate testing that!

Sqlite sounds good. 👍🏽

If I work at it, I can come up with scenarios where someone would connect directly to a database server from a frontend. Eg no-install devtools that currently wind up shipping as Electron apps.

@jeremy-w I think you can use airtap for browser testing, see https://github.com/fastify/secure-json-parse/pull/21#event-4255199353 as an example. Not sure if we have any sqlite tests in tap already, but if we don't, we could add some.

knex / knex