Default log function hides errors from developers

[joeytwiddle]

If a callback function throws an error (due to a typo, unexpected condition, or whatever) strophe will catch the error and then hide it from the developer! Nothing will be logged.

This is due to the default log function doing nothing.

It is rather surprising to discover that errors everywhere in my code will throw, except errors inside callbacks passed to Strophe, which will fail silently.

My first thought is for default behaviour that leaves log, debug and info silent, but makes warn, error and fatal log the message, using console.warn().

If that is not possible, my alternative suggestion is that fatal should throw an error. This will at least expose the most heinous cases (such as the errors in callbacks described above).

[jcbrand]

From what I can tell, this behavior is on purpose. Errors are caught and then logged (with the expectation being that the client using strophe.js will handle logging) so that an error doesn't cause the app to crash, thereby dropping the XMPP session and losing functionality.

That said, I think adding some rudimentary logging (i.e. console.warn and console.error) is probably a good idea, since this has confused many people (including myself) in the past.

[joeytwiddle]

Apologies for verbose brain-dump...

Here are two possible reasons the code might be how it is now:

1. The developer wanted the default behaviour to work in all environments, but could not guarantee that console.log() was available in all environments. I do not know whether that is still true or not! (console.log() is available in all the environments I currently use, but it is not part of the ES spec. It's probably not available in old versions of Rhino for example.)

2. The developer wanted the user to be able to easily set a logging function for all levels. But then if a default was set, the user would see logging for all levels, which would be too spammy!

The first concern could be mitigated by checking for the presence of console.log before trying to use it.

The second could be mitigated by having different defaults for warning level and above. Perhaps just two functions that the user can override, instead of one? Or encourage them to override any of the 5 they want to.

---

Anyway, I'm seriously thinking whether we should just re-throw (or never catch) errors from callback functions. Most developers would expect an error in that situation, and developer tools can sometimes help the developer if an error is thrown (e.g. by pausing the debugger, or by logging the stack-trace and allowing clicks to the source code, or even logging the error to a DB for next-day analysis).

However, re-throwing the Error would be a change in behaviour - a breaking change - so it should really only be part of a major version increment. (There could well be apps in the wild which rely on this behaviour to prevent their node server from crashing!)

I guess I've talked myself back to just logging again! Or make throwing the error opt-in behaviour.

Either way, I think we should ensure that the stack (or at least the line number) is logged when an error occurs, to assist debugging.

[jcbrand]

I'm quite happy with how logging is done in converse.js (which uses strophe.js):

https://github.com/jcbrand/converse.js/blob/8997af7890bdc92131188b65648cd184b07a3c50/src/converse-core.js#L138

It uses console.error, console.debug etc. if those are available, otherwise it falls back to console.log.

Two issues...

1. it relies on lodash, so that dependency would need to be removed if we were to write similar code for strophe.
2. It assumes that console.log exists, which I gather from what you wrote might not always be the case.