code.grnet.gr Git - aquarium/blob - src/main/scala/gr/grnet/aquarium/util/ContextualLogger.scala

   1 /*
   2  * Copyright 2011 GRNET S.A. All rights reserved.
   3  *
   4  * Redistribution and use in source and binary forms, with or
   5  * without modification, are permitted provided that the following
   6  * conditions are met:
   7  *
   8  *   1. Redistributions of source code must retain the above
   9  *      copyright notice, this list of conditions and the following
  10  *      disclaimer.
  11  *
  12  *   2. Redistributions in binary form must reproduce the above
  13  *      copyright notice, this list of conditions and the following
  14  *      disclaimer in the documentation and/or other materials
  15  *      provided with the distribution.
  16  *
  17  * THIS SOFTWARE IS PROVIDED BY GRNET S.A. ``AS IS'' AND ANY EXPRESS
  18  * OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
  19  * WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
  20  * PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL GRNET S.A OR
  21  * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
  22  * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
  23  * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
  24  * USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED
  25  * AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
  26  * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN
  27  * ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
  28  * POSSIBILITY OF SUCH DAMAGE.
  29  *
  30  * The views and conclusions contained in the software and
  31  * documentation are those of the authors and should not be
  32  * interpreted as representing official policies, either expressed
  33  * or implied, of GRNET S.A.
  34  */
  35
  36 package gr.grnet.aquarium.util
  37
  38 import org.slf4j.Logger
  39 import com.ckkloverdos.maybe.{Failed, Just, Maybe}
  40
  41 /**
  42  * A logger that keeps track of working context and indentation level.
  43  *
  44  * This is mostly useful in single-threaded debugging sessions.
  45   *
  46   * A sample output follows:
  47   *
  48   * {{{
  49  [DEBUG] 2012-02-13 12:54:53,653 main -                 doFullMonthlyBilling(2012-01) BEGIN
  50  [DEBUG] 2012-02-13 12:54:53,653 main -     findUserStateAtEndOfBillingMonth(2011-12)   BEGIN
  51  [DEBUG] 2012-02-13 12:54:53,661 main -     findUserStateAtEndOfBillingMonth(2011-12)     Found 0 out of sync events, will have to (re)compute user state
  52  [DEBUG] 2012-02-13 12:54:53,661 main -     findUserStateAtEndOfBillingMonth(2011-12)     Computing full month billing
  53  [DEBUG] 2012-02-13 12:54:53,662 main -                 doFullMonthlyBilling(2011-12)     BEGIN
  54  [DEBUG] 2012-02-13 12:54:53,662 main -     findUserStateAtEndOfBillingMonth(2011-11)       BEGIN
  55  [DEBUG] 2012-02-13 12:54:53,663 main -     findUserStateAtEndOfBillingMonth(2011-11)         Found 0 out of sync events, will have to (re)compute user state
  56  [DEBUG] 2012-02-13 12:54:53,663 main -     findUserStateAtEndOfBillingMonth(2011-11)         Computing full month billing
  57  [DEBUG] 2012-02-13 12:54:53,664 main -                 doFullMonthlyBilling(2011-11)         BEGIN
  58  [DEBUG] 2012-02-13 12:54:53,664 main -     findUserStateAtEndOfBillingMonth(2011-10)           BEGIN
  59  [DEBUG] 2012-02-13 12:54:53,667 main -     findUserStateAtEndOfBillingMonth(2011-10)             User did not exist before 2011-11-01 00:00:00.000. Returning UserState(Christos,0,0,false,null,ImplicitOFFResourceEventsSnapshot(Map(),0),List(),List(),LatestResourceEventsSnapshot(Map(),0),0,ActiveStateSnapshot(false,0),CreditSnapshot(0.0,0),AgreementSnapshot(List(Agreement(default,0,-1)),0),RolesSnapshot(List(),0),OwnedResourcesSnapshot(List(),0))
  60  [DEBUG] 2012-02-13 12:54:53,668 main -     findUserStateAtEndOfBillingMonth(2011-10)           END
  61  [DEBUG] 2012-02-13 12:54:53,672 main -                 doFullMonthlyBilling(2011-11)           previousResourceEvents = LatestResourceEventsWorker(Map())
  62  [DEBUG] 2012-02-13 12:54:53,673 main -                 doFullMonthlyBilling(2011-11)           theImplicitOFFs = ImplicitOFFResourceEventsWorker(Map())
  63  [DEBUG] 2012-02-13 12:54:53,680 main -                 doFullMonthlyBilling(2011-11)           resourceEventStore = MemStore(Map(UserState -> 0, WalletEntry -> 0, ResourceEvent -> 5, PolicyEntry -> 0, UserEvent -> 0))
  64  [DEBUG] 2012-02-13 12:54:53,681 main -                 doFullMonthlyBilling(2011-11)           Found 0 resource events, starting processing...
  65  [DEBUG] 2012-02-13 12:54:53,683 main -                 doFullMonthlyBilling(2011-11)         END
  66  [DEBUG] 2012-02-13 12:54:53,683 main -     findUserStateAtEndOfBillingMonth(2011-11)       END
  67  [DEBUG] 2012-02-13 12:54:53,684 main -                 doFullMonthlyBilling(2011-12)       previousResourceEvents = LatestResourceEventsWorker(Map())
  68  [DEBUG] 2012-02-13 12:54:53,684 main -                 doFullMonthlyBilling(2011-12)       theImplicitOFFs = ImplicitOFFResourceEventsWorker(Map())
  69  [DEBUG] 2012-02-13 12:54:53,685 main -                 doFullMonthlyBilling(2011-12)       resourceEventStore = MemStore(Map(UserState -> 0, WalletEntry -> 0, ResourceEvent -> 5, PolicyEntry -> 0, UserEvent -> 0))
  70  [DEBUG] 2012-02-13 12:54:53,686 main -                 doFullMonthlyBilling(2011-12)       Found 0 resource events, starting processing...
  71  [DEBUG] 2012-02-13 12:54:53,686 main -                 doFullMonthlyBilling(2011-12)     END
  72  [DEBUG] 2012-02-13 12:54:53,687 main -     findUserStateAtEndOfBillingMonth(2011-12)   END
  73  [DEBUG] 2012-02-13 12:54:53,687 main -                 doFullMonthlyBilling(2012-01)   previousResourceEvents = LatestResourceEventsWorker(Map())
  74  [DEBUG] 2012-02-13 12:54:53,688 main -                 doFullMonthlyBilling(2012-01)   theImplicitOFFs = ImplicitOFFResourceEventsWorker(Map())
  75  [DEBUG] 2012-02-13 12:54:53,688 main -                 doFullMonthlyBilling(2012-01)   resourceEventStore = MemStore(Map(UserState -> 0, WalletEntry -> 0, ResourceEvent -> 5, PolicyEntry -> 0, UserEvent -> 0))
  76  [DEBUG] 2012-02-13 12:54:53,689 main -                 doFullMonthlyBilling(2012-01)   Found 4 resource events, starting processing...
  77  [DEBUG] 2012-02-13 12:54:53,690 main -                 doFullMonthlyBilling(2012-01)     Processing EVENT(2, [2012-01-01 03:00:00.000], 99.0 [MB/Hr], diskspace::pithos/diskspace/DISK.1, Map(), Christos, pithos)
  78  [DEBUG] 2012-02-13 12:54:53,691 main -                 doFullMonthlyBilling(2012-01)       0 previousResourceEvents
  79  [DEBUG] 2012-02-13 12:54:53,691 main -                 doFullMonthlyBilling(2012-01)       0 theImplicitOFFs
  80  [DEBUG] 2012-02-13 12:54:53,694 main -                 doFullMonthlyBilling(2012-01)       Processing: ResourceEvent(2,1325379600000,1325379600000,Christos,pithos,diskspace,pithos/diskspace/DISK.1,1.0,99.0,Map())
  81  [DEBUG] 2012-02-13 12:54:53,704 main -                 doFullMonthlyBilling(2012-01)     Processing EVENT(0, [2012-01-02 01:00:00.000], ON, vmtime::synnefo/vmtime/VM.1, Map(), Christos, synnefo)
  82  [DEBUG] 2012-02-13 12:54:53,705 main -                 doFullMonthlyBilling(2012-01)       1 previousResourceEvents
  83  [DEBUG] 2012-02-13 12:54:53,708 main -                 doFullMonthlyBilling(2012-01)         EVENT(2, [2012-01-01 03:00:00.000], 99.0 [MB/Hr], diskspace::pithos/diskspace/DISK.1, Map(), Christos, pithos)
  84  [DEBUG] 2012-02-13 12:54:53,709 main -                 doFullMonthlyBilling(2012-01)       0 theImplicitOFFs
  85  [DEBUG] 2012-02-13 12:54:53,709 main -                 doFullMonthlyBilling(2012-01)       Ignoring not billable EVENT(0, [2012-01-02 01:00:00.000], ON, vmtime::synnefo/vmtime/VM.1, Map(), Christos, synnefo)
  86  [DEBUG] 2012-02-13 12:54:53,711 main -                 doFullMonthlyBilling(2012-01)     Processing EVENT(3, [2012-01-02 04:00:00.000], 23.0 [MB/Hr], diskspace::pithos/diskspace/DISK.1, Map(), Christos, pithos)
  87  [DEBUG] 2012-02-13 12:54:53,712 main -                 doFullMonthlyBilling(2012-01)       2 previousResourceEvents
  88  [DEBUG] 2012-02-13 12:54:53,713 main -                 doFullMonthlyBilling(2012-01)         EVENT(0, [2012-01-02 01:00:00.000], ON, vmtime::synnefo/vmtime/VM.1, Map(), Christos, synnefo)
  89  [DEBUG] 2012-02-13 12:54:53,714 main -                 doFullMonthlyBilling(2012-01)         EVENT(2, [2012-01-01 03:00:00.000], 99.0 [MB/Hr], diskspace::pithos/diskspace/DISK.1, Map(), Christos, pithos)
  90  [DEBUG] 2012-02-13 12:54:53,714 main -                 doFullMonthlyBilling(2012-01)       0 theImplicitOFFs
  91  [DEBUG] 2012-02-13 12:54:53,715 main -                 doFullMonthlyBilling(2012-01)       Processing: ResourceEvent(3,1325469600000,1325469600000,Christos,pithos,diskspace,pithos/diskspace/DISK.1,1.0,23.0,Map())
  92  [DEBUG] 2012-02-13 12:54:53,716 main -                 doFullMonthlyBilling(2012-01)       Previous  : ResourceEvent(2,1325379600000,1325379600000,Christos,pithos,diskspace,pithos/diskspace/DISK.1,1.0,99.0,Map())
  93  [DEBUG] 2012-02-13 12:54:53,718 main -                 doFullMonthlyBilling(2012-01)     Processing EVENT(1, [2012-01-02 10:00:00.000], OFF, vmtime::synnefo/vmtime/VM.1, Map(), Christos, synnefo)
  94  [DEBUG] 2012-02-13 12:54:53,719 main -                 doFullMonthlyBilling(2012-01)       2 previousResourceEvents
  95  [DEBUG] 2012-02-13 12:54:53,719 main -                 doFullMonthlyBilling(2012-01)         EVENT(0, [2012-01-02 01:00:00.000], ON, vmtime::synnefo/vmtime/VM.1, Map(), Christos, synnefo)
  96  [DEBUG] 2012-02-13 12:54:53,721 main -                 doFullMonthlyBilling(2012-01)         EVENT(3, [2012-01-02 04:00:00.000], 23.0 [MB/Hr], diskspace::pithos/diskspace/DISK.1, Map(), Christos, pithos)
  97  [DEBUG] 2012-02-13 12:54:53,721 main -                 doFullMonthlyBilling(2012-01)       0 theImplicitOFFs
  98  [DEBUG] 2012-02-13 12:54:53,722 main -                 doFullMonthlyBilling(2012-01)       Processing: ResourceEvent(1,1325491200000,1325491200000,Christos,synnefo,vmtime,synnefo/vmtime/VM.1,1.0,0.0,Map())
  99  [DEBUG] 2012-02-13 12:54:53,735 main -                 doFullMonthlyBilling(2012-01)       Previous  : ResourceEvent(0,1325458800000,1325458800000,Christos,synnefo,vmtime,synnefo/vmtime/VM.1,1.0,1.0,Map())
 100  [DEBUG] 2012-02-13 12:54:53,736 main -                 doFullMonthlyBilling(2012-01) END
 101  * }}}
 102  *
 103  * @author Christos KK Loverdos <loverdos@gmail.com>
 104  */
 105 final class ContextualLogger(val logger: Logger, fmt: String, args: Any*) {
 106   val ctx = ContextualLogger.fixCtx(fmt.format(args:_*))
 107
 108   private[this] var _nesting = 0
 109
 110   private def nestMsg(fmt: String, args: Any*) = {
 111     val msg = fmt.format(args: _*)
 112     _nesting match {
 113       case 0 ⇒
 114         msg
 115       case n ⇒
 116         val buffer = new java.lang.StringBuilder(n + msg.size)
 117         var _i = 0
 118         while(_i < (n * 2)) {
 119           buffer.append(' ')
 120           _i = _i + 1
 121         }
 122         buffer.append(msg)
 123         buffer.toString
 124     }
 125   }
 126
 127   def nesting = _nesting
 128
 129   def indentAs(other: ContextualLogger): this.type = {
 130     _nesting = other.nesting
 131     this
 132   }
 133
 134   def indent(): this.type   = {
 135     _nesting = _nesting + 1
 136     this
 137   }
 138
 139   def unindent(): this.type = {
 140     _nesting = _nesting - 1
 141     this
 142   }
 143
 144   def debug(fmt: String, args: Any*): Unit = {
 145     if(logger.isDebugEnabled) {
 146       val msg = ctx + " " + nestMsg(fmt, args:_*)
 147       logger.debug(msg)
 148     }
 149   }
 150
 151   def warn(fmt: String, args: Any*): Unit = {
 152     if(logger.isWarnEnabled) {
 153       val msg = ctx + " " + nestMsg(fmt, args:_*)
 154       logger.warn(msg)
 155     }
 156   }
 157
 158   def error(fmt: String, args: Any*): Unit = {
 159     if(logger.isErrorEnabled) {
 160       val msg = ctx + " " + nestMsg(fmt, args:_*)
 161       logger.error(msg)
 162     }
 163   }
 164
 165   def error(t: Throwable, fmt: String, args: Any*): Unit = {
 166     if(logger.isErrorEnabled) {
 167       val msg = ctx + " " + nestMsg(fmt, args:_*)
 168       logger.error(msg, t)
 169     }
 170   }
 171
 172   def error(failed: Failed): Unit = {
 173     this.error(failed.exception, "%s", failed.explanation)
 174   }
 175
 176   def begin(): Unit = {
 177     debug("BEGIN")
 178     indent()
 179   }
 180
 181   def end(): Unit = {
 182     unindent()
 183     debug("END")
 184   }
 185
 186   def endWith[A](f: A): A = {
 187     val retval = f
 188     end()
 189     retval
 190   }
 191 }
 192
 193 /**
 194  * Companion object of [[gr.grnet.aquarium.util.ContextualLogger]].
 195  *
 196  * @author Christos KK Loverdos <loverdos@gmail.com>
 197  */
 198 object ContextualLogger {
 199   final val MaxCtxLength = 40
 200   final val ELLIPSIS = "…" // U+2026
 201
 202   def fixCtx(ctx: String): String = {
 203     val ctxLen = ctx.length()
 204     if(ctxLen == MaxCtxLength) {
 205       ctx
 206     } else if(ctxLen > MaxCtxLength) {
 207       ELLIPSIS + ctx.substring(ctxLen - MaxCtxLength + 1, ctxLen)
 208     } else {
 209       val buffer = new java.lang.StringBuilder(MaxCtxLength)
 210       val prefixLen = MaxCtxLength - ctxLen
 211       var _i = 0
 212       while(_i < prefixLen) {
 213         buffer.append(' ')
 214         _i = _i + 1
 215       }
 216       buffer.append(ctx)
 217       buffer.toString
 218     }
 219   }
 220
 221   def fromOther(clogM: Maybe[ContextualLogger], logger: Logger,  fmt: String, args: Any*): ContextualLogger = {
 222     clogM match {
 223       case Just(clog) ⇒
 224         new ContextualLogger(clog.logger, fmt, args:_*).indentAs(clog)
 225       case _ ⇒
 226         new ContextualLogger(logger, fmt, args:_*)
 227     }
 228   }
 229 }