She logs me, she logs me not

motif

Logging. An old friend. So critical for a production deployment and so hidden away. Much has been said and done in this area, and we’ve seen both success and total domination by log4j, as well as an abysmal failure of java.util. (still hearing the chorus of WTFs and raised eye brows).

With the introduction of Mule 3 the playing field has changed dramatically, but something was still missing. Multiple applications in runtime were still writing to the same single log file. And while it was easy to split out log entries for your custom classes and packages,  in practice it had little value without the larger context of Mule and 3rd-party library log entries. Besides, re-configuring logging at runtime wasn’t quite possible. And with multiple applications running in a single Mule instance, one-config-fits-all was no longer an ideal choice.

So, without further ado, welcome the new Logging in Mule 3.1.2. No, it’s not a rewrite, and you aren’t locked into any logging API in your code either (same as before). However, those extra 20% of functionality and usability which often are never implemented make up for a huge difference. Below are some highlights of what to expect.

Every app gets its own log file

As simple as that. For each app deployed in Mule there will be a dedicated log file. The exciting part here is Mule and any 3rd-party library log entries are written to the same file, as if it were the only app running. No scouting for big picture across multiple log files needed.

Every app can have its own logging configuration (if it choses to)

Defaults work great and most of the time no further action required from a user. But if your deployment calls for a more complex logging setup (e.g. central logging sink into MongoDB), we got you covered, just bundle your complete log4j configuration with the application.

Did I say logging can be reloaded on the fly? Yes it can!

Yes, hot on the wheels of hot deployment in Mule 3, logging configurations can be reloaded without restarting neither app nor Mule server. Made a fatal mistake in your config? No worries, correct it and save the file again. Sure enough, if you have an app-specific logging setup, it will be hot-reloaded as well, enjoy 🙂

It just works, baby

This is my personal favorite. There was a tremendous amount of voodoo coding and hacking involved in the making of it, but at the end of the day we have:

  • Absolutely no changes required on the user side
  • It’s robust (and believe me, I tried hard to break things), this is not some new experimental logging feature of the log4j
  • We went to great lengths to guarantee no memory leaks coming from the logging subsystem. Of course, you’re always welcome to write some bad memory-leaking code, just don’t blame logging 😉

The only thing Mule asks in return is you run it in standalone mode.

There’s plenty more details, head over to the official reference page for all your doc needs (free community account required).

How’s Stuff Made

Technically, it was a great and exciting challenge. If words ‘classloader hierarchy, phantom references, thread CCL, and GC root paths’ are your night’s read, feel free to browse the source (and maybe even give some feedback). I would also like to ask authors of commons-logging, log4j and slf4j libraries of the following:

  • Design for extension. No, there’s no need for making core methods private. And if you think they aren’t core, think twice and open them up for Pete’s sake.
  • Again, design for extension. Creating an API is tough, but creating a great API is more than tough. Just realize your code may (and will be) used in ways you would have never imagined, tailor to your users’ needs and not today’s limited vision
  • Ban ‘package-friendly’ modifier. It gives one a false sense of scope and gives nothing but pain in the back to the next guy. Since I remember myself, I can’t think of a single time it was warranted in the design, but can share numerous WTFs instead.

Are you still reading this? Go download Mule development snapshots (both 3.1.2 and 3.2.0 have this feature) and tell us what you think! And if you like it, tell the other guy, spread the word!


We'd love to hear your opinion on this post


9 Responses to “She logs me, she logs me not”

  1. Really good news, I’m so happy you made this possible.

    /Tomas Blohm

  2. Hi Tomas, glad you like it 🙂

    Since the article was published, there were some more usability improvements (coming up in the same release) . Now Mule provides more feedback on app deployment progress and prints a summary of failed/deployed apps once started in a nice table. Nothing groundbreaking, but small things do add up.

  3. Hi Andrew,

    once again, this logging features made my life much easier so thank you. Since you’re digging deep in the world of classloaders 🙂 , do you think it will be possible to have different apps answering on the same http port, separated by paths? I guess that is in the same problem area. I would really like to serve different versions of the same service (app) and not allocate a new port every time, I’d rather make the version a part of the path. By doing that I can make Maven generate the path from version and doesn’t have to worry about firewalls and stuff when publishing a new version.
    I should probably post this somewhere else and I know it’s not an easy thing to do but since I have your attention I thought I might be able to make your mind spin 🙂

    /Tomas Blohm

  4. Hi Thomas, thanks for kind words, that’s a refresher from the user list’s “want! and it’s broken!” 🙂

    I doubt we’ll do it this way in the coming future. Mostly because apps are intentionally isolated from each other. Now, in theory there are a few tricks we can use (and which e.g. Mule Management Console agent employs too), but not sure it’s the same. Typically, such transparent upgrade is better handled by an external loadbalancer, and the user-facing URI stays intact. Or maybe I don’t understand your use case well enough yet.

  5. Hi Thomas,

    A client of mine is solving the problem you describe by having a generic frontal HTTP dispatching application that sends messages to an embedded JMS broker. Specialized app then consume messages using a selector on the original request URI.

    HTH
    D.

  6. Hi,

    that’s actually the way I was thinking about, and then use async to reply. Thank you for sharing ideas, it’s absolutely great to have people like you guys to talk to about these kind of things.

    /Tomas

  7. You’re welcome. Feel free to post any feedback (or just to initiate free-form discussions) on our user list or forums http://forums.mulesoft.org

    We talk to our customers and users a lot, but then, there are even more people who stay silent for various reasons. This kind of feedback ‘from within’ is invaluable

  8. Hi again,

    as pointed out in the post this feature will be available in 3.1.2. Could you please give me a hint when 3.1.2 will be released? I have this upcoming release for a client and would really like to add individual logging but can’t as long as 3.1.2 is SNAPSHOT. Thanks in advance!

    /Tomas

  9. […] Each application now gets its own log file and its own log configuration.  This is discussed here and documented […]