Oh, I like contextual loggers.
authorChristos KK Loverdos <loverdos@gmail.com>
Thu, 9 Feb 2012 14:00:18 +0000 (16:00 +0200)
committerChristos KK Loverdos <loverdos@gmail.com>
Thu, 9 Feb 2012 14:00:18 +0000 (16:00 +0200)
Really handy when debugging.

src/main/scala/gr/grnet/aquarium/logic/events/ResourceEvent.scala
src/main/scala/gr/grnet/aquarium/store/memory/MemStore.scala
src/main/scala/gr/grnet/aquarium/user/DefaultUserStateComputations.scala [new file with mode: 0644]
src/main/scala/gr/grnet/aquarium/user/UserDataSnapshot.scala
src/main/scala/gr/grnet/aquarium/user/UserStateComputations.scala
src/main/scala/gr/grnet/aquarium/util/ContextualLogger.scala [new file with mode: 0644]

index fb10767..f2ae96b 100644 (file)
@@ -263,7 +263,8 @@ object ResourceEvent {
   type ResourceIdType = String
   type FullResourceType = (ResourceType, ResourceIdType)
   type FullResourceTypeMap = Map[FullResourceType, ResourceEvent]
-  
+  type FullMutableResourceTypeMap = scala.collection.mutable.Map[FullResourceType, ResourceEvent]
+
   def fromJson(json: String): ResourceEvent = {
     JsonHelpers.jsonToObject[ResourceEvent](json)
   }
index d12f2d2..26c99f1 100644 (file)
@@ -45,7 +45,6 @@ import java.util.Date
 import collection.mutable.ConcurrentMap
 import gr.grnet.aquarium.logic.events.{WalletEntry, ResourceEvent, UserEvent, PolicyEntry}
 import java.util.concurrent.ConcurrentHashMap
-import gr.grnet.aquarium.util.date.DateCalculator
 
 /**
  * An implementation of various stores that persists data in memory
@@ -69,6 +68,18 @@ class MemStore extends UserStateStore
   def configure(props: Props) = {
   }
 
+  override def toString = {
+    val map = Map(
+      "UserState"     -> userStateByUserId.size,
+      "ResourceEvent" -> resourceEventsById.size,
+      "UserEvent"     -> userEventById.size,
+      "PolicyEntry"   -> policyById.size,
+      "WalletEntry"   -> walletEntriesById.size
+    )
+
+    "MemStore(%s)" format map
+  }
+
   //+ StoreProvider
   def userStateStore = this
 
diff --git a/src/main/scala/gr/grnet/aquarium/user/DefaultUserStateComputations.scala b/src/main/scala/gr/grnet/aquarium/user/DefaultUserStateComputations.scala
new file mode 100644 (file)
index 0000000..1445405
--- /dev/null
@@ -0,0 +1,43 @@
+/*
+ * Copyright 2012 GRNET S.A. All rights reserved.
+ *
+ * Redistribution and use in source and binary forms, with or
+ * without modification, are permitted provided that the following
+ * conditions are met:
+ *
+ *   1. Redistributions of source code must retain the above
+ *      copyright notice, this list of conditions and the following
+ *      disclaimer.
+ *
+ *   2. Redistributions in binary form must reproduce the above
+ *      copyright notice, this list of conditions and the following
+ *      disclaimer in the documentation and/or other materials
+ *      provided with the distribution.
+ *
+ * THIS SOFTWARE IS PROVIDED BY GRNET S.A. ``AS IS'' AND ANY EXPRESS
+ * OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
+ * WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
+ * PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL GRNET S.A OR
+ * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+ * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+ * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
+ * USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED
+ * AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
+ * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN
+ * ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
+ * POSSIBILITY OF SUCH DAMAGE.
+ *
+ * The views and conclusions contained in the software and
+ * documentation are those of the authors and should not be
+ * interpreted as representing official policies, either expressed
+ * or implied, of GRNET S.A.
+ */
+
+package gr.grnet.aquarium.user
+
+/**
+ * Default implementation for [[gr.grnet.aquarium.user.UserStateComputations]].
+ *
+ * @author Christos KK Loverdos <loverdos@gmail.com>
+ */
+object DefaultUserStateComputations extends UserStateComputations
\ No newline at end of file
index 301c97d..bfc53ba 100644 (file)
@@ -41,6 +41,8 @@ import java.util.Date
 import logic.accounting.dsl.DSLAgreement
 import com.ckkloverdos.maybe.{Failed, NoVal, Maybe, Just}
 import logic.events.ResourceEvent
+import logic.events.ResourceEvent.FullResourceTypeMap
+import logic.events.ResourceEvent.FullMutableResourceTypeMap
 
 /**
  * Snapshot of data that are user-related.
@@ -229,12 +231,45 @@ class DataSnapshotException(msg: String) extends Exception(msg)
 case class ActiveStateSnapshot(isActive: Boolean, snapshotTime: Long) extends DataSnapshot
 
 /**
- * Keeps the latest resource event per resource instance
+ * Keeps the latest resource event per resource instance.
  *
  * @param resourceEventsMap
  * @param snapshotTime
  *
  * @author Christos KK Loverdos <loverdos@gmail.com>
  */
-case class LatestResourceEventsSnapshot(resourceEventsMap: ResourceEvent.FullResourceTypeMap,
-                                        snapshotTime: Long) extends DataSnapshot
\ No newline at end of file
+case class LatestResourceEventsSnapshot(resourceEventsMap: FullResourceTypeMap,
+                                        snapshotTime: Long) extends DataSnapshot {
+
+  /**
+   * The gateway to playing with mutable state.
+   *
+   * @return A fresh instance of [[gr.grnet.aquarium.user.LatestResourceEventsWorker]].
+   */
+  def toMutableWorker =
+    LatestResourceEventsWorker(scala.collection.mutable.Map(resourceEventsMap.toSeq: _*))
+}
+
+/**
+ * This is the mutable cousin of [[gr.grnet.aquarium.user.LatestResourceEventsSnapshot]].
+ *
+ * @param resourceEventsMap
+ */
+case class LatestResourceEventsWorker(resourceEventsMap: FullMutableResourceTypeMap) {
+
+  /**
+   * The gateway to immutable state.
+   *
+   * @param snapshotTime The relevant snapshot time.
+   * @return A fresh instance of [[gr.grnet.aquarium.user.LatestResourceEventsSnapshot]].
+   */
+  def toImmutableSnapshot(snapshotTime: Long) = LatestResourceEventsSnapshot(resourceEventsMap.toMap, snapshotTime)
+
+  def updateResourceEvent(resource: String, instanceId: String, resourceEvent: ResourceEvent): Unit = {
+    resourceEventsMap((resource, instanceId)) = resourceEvent
+  }
+  
+  def findResourceEvent(resource: String, instanceId: String): Option[ResourceEvent] = {
+    resourceEventsMap.get((resource, instanceId))
+  }
+}
\ No newline at end of file
index 2c209e4..c619bde 100644 (file)
@@ -41,9 +41,9 @@ import com.ckkloverdos.maybe.{Failed, NoVal, Just, Maybe}
 import gr.grnet.aquarium.logic.accounting.Accounting
 import gr.grnet.aquarium.util.date.DateCalculator
 import gr.grnet.aquarium.logic.accounting.dsl.{DSLResourcesMap, DSLCostPolicy, DSLPolicy}
-import gr.grnet.aquarium.util.Loggable
 import gr.grnet.aquarium.logic.events.ResourceEvent
 import gr.grnet.aquarium.store.{PolicyStore, UserStateStore, ResourceEventStore}
+import gr.grnet.aquarium.util.{ContextualLogger, Loggable}
 
 /**
  *
@@ -99,22 +99,18 @@ class UserStateComputations extends Loggable {
                                        zeroUserState: UserState, 
                                        defaultPolicy: DSLPolicy,
                                        defaultResourcesMap: DSLResourcesMap,
-                                       accounting: Accounting): Maybe[UserState] = {
+                                       accounting: Accounting,
+                                       contextualLogger: Maybe[ContextualLogger] = NoVal): Maybe[UserState] = {
 
-    def D(fmt: String, args: Any*) = {
-      logger.debug("[%s, %s-%02d] %s".format(userId, yearOfBillingMonth, billingMonth, fmt.format(args:_*)))
-    }
-
-    def E(fmt: String, args: Any*) = {
-      logger.error("[%s, %s-%02d] %s".format(userId, yearOfBillingMonth, billingMonth, fmt.format(args:_*)))
-    }
-
-    def W(fmt: String, args: Any*) = {
-      logger.error("[%s, %s-%02d] %s".format(userId, yearOfBillingMonth, billingMonth, fmt.format(args:_*)))
-    }
+    val clog = ContextualLogger.fromOther(
+      contextualLogger,
+      logger,
+      "findUserStateAtEndOfBillingMonth(%s-%02d)", yearOfBillingMonth, billingMonth)
+//    val clog = new ContextualLogger(logger, "findUserStateAtEndOfBillingMonth(%s-%02d)", yearOfBillingMonth, billingMonth)
+    clog.begin()
 
     def doCompute: Maybe[UserState] = {
-      D("Computing full month billing")
+      clog.debug("Computing full month billing")
       doFullMonthlyBilling(
         userId,
         yearOfBillingMonth,
@@ -127,11 +123,10 @@ class UserStateComputations extends Loggable {
         zeroUserState,
         defaultPolicy,
         defaultResourcesMap,
-        accounting)
+        accounting,
+        Just(clog))
     }
 
-    D("+findUserStateAtEndOfBillingMonth()")
-
     val billingMonthStartDateCalc = new DateCalculator(yearOfBillingMonth, billingMonth)
     val userCreationDateCalc = new DateCalculator(userCreationMillis)
     val billingMonthStartMillis = billingMonthStartDateCalc.toMillis
@@ -139,40 +134,32 @@ class UserStateComputations extends Loggable {
 
     if(billingMonthStopMillis < userCreationMillis) {
       // If the user did not exist for this billing month, piece of cake
-      D("User did not exist before %s. Returning %s", userCreationDateCalc, zeroUserState)
-      D("-findUserStateAtEndOfBillingMonth()")
-      Just(zeroUserState)
+      clog.debug("User did not exist before %s. Returning %s", userCreationDateCalc, zeroUserState)
+      clog.endWith(Just(zeroUserState))
     } else {
       resourceEventStore.countOutOfSyncEventsForBillingPeriod(userId, billingMonthStartMillis, billingMonthStopMillis) match {
         case Just(outOfSyncEventCount) ⇒
           // Have out of sync, so must recompute
-          D("Found %s out of sync events, will have to (re)compute user state", outOfSyncEventCount)
-          val retval = doCompute
-          D("-findUserStateAtEndOfBillingMonth()")
-          retval
+          clog.debug("Found %s out of sync events, will have to (re)compute user state", outOfSyncEventCount)
+          clog.endWith(doCompute)
         case NoVal ⇒
           // No out of sync events, ask DB cache
           userStateStore.findLatestUserStateForEndOfBillingMonth(userId, yearOfBillingMonth, billingMonth) match {
             case just @ Just(userState) ⇒
               // Found from cache
-              D("Found from cache: %s", userState)
-              D("-findUserStateAtEndOfBillingMonth()")
-              just
+              clog.debug("Found from cache: %s", userState)
+              clog.endWith(just)
             case NoVal ⇒
               // otherwise compute
-              D("No user state found from cache, will have to (re)compute")
-              val retval = doCompute
-              D("-findUserStateAtEndOfBillingMonth()")
-              retval
+              clog.debug("No user state found from cache, will have to (re)compute")
+              clog.endWith(doCompute)
             case failed @ Failed(_, _) ⇒
-              W("Failure while quering cache for user state: %s", failed)
-              D("-findUserStateAtEndOfBillingMonth()")
-              failed
+              clog.warn("Failure while quering cache for user state: %s", failed)
+              clog.endWith(failed)
           }
         case failed @ Failed(_, _) ⇒
-          W("Failure while querying for out of sync events: %s", failed)
-          D("-findUserStateAtEndOfBillingMonth()")
-          failed
+          clog.warn("Failure while querying for out of sync events: %s", failed)
+          clog.endWith(failed)
       }
     }
   }
@@ -188,26 +175,22 @@ class UserStateComputations extends Loggable {
                            zeroUserState: UserState,
                            defaultPolicy: DSLPolicy,
                            defaultResourcesMap: DSLResourcesMap,
-                           accounting: Accounting): Maybe[UserState] = Maybe {
-    def D(fmt: String, args: Any*) = {
-      logger.debug("[%s, %s-%02d] %s".format(userId, yearOfBillingMonth, billingMonth, fmt.format(args:_*)))
-    }
+                           accounting: Accounting,
+                           contextualLogger: Maybe[ContextualLogger] = NoVal): Maybe[UserState] = Maybe {
 
-    def E(fmt: String, args: Any*) = {
-      logger.error("[%s, %s-%02d] %s".format(userId, yearOfBillingMonth, billingMonth, fmt.format(args:_*)))
-    }
-
-    def W(fmt: String, args: Any*) = {
-      logger.error("[%s, %s-%02d] %s".format(userId, yearOfBillingMonth, billingMonth, fmt.format(args:_*)))
-    }
-
-    D("+doFullMonthlyBilling()")
 
     val billingMonthStartDateCalc = new DateCalculator(yearOfBillingMonth, billingMonth)
+    val billingMonthEndDateCalc   = billingMonthStartDateCalc.copy.goEndOfThisMonth
     val previousBillingMonthCalc = billingMonthStartDateCalc.copy.goPreviousMonth
     val previousBillingMonth = previousBillingMonthCalc.getMonthOfYear
     val yearOfPreviousBillingMonth = previousBillingMonthCalc.getYear
 
+    val clog = ContextualLogger.fromOther(
+      contextualLogger,
+      logger,
+      "doFullMonthlyBilling(%s, %s)", billingMonthStartDateCalc.toYYYYMMDD, billingMonthEndDateCalc.toYYYYMMDD)
+    clog.begin()
+
     val previousBillingMonthUserStateM = findUserStateAtEndOfBillingMonth(
       userId,
       yearOfPreviousBillingMonth,
@@ -220,19 +203,25 @@ class UserStateComputations extends Loggable {
       zeroUserState,
       defaultPolicy,
       defaultResourcesMap,
-      accounting
+      accounting,
+      Just(clog)
     )
     
     previousBillingMonthUserStateM match {
       case NoVal ⇒
-        NoVal // not really...
+        NoVal // not really... (must throw an exception here probably...)
       case failed @ Failed(_, _) ⇒
         failed
       case Just(startingUserState) ⇒
         // This is the real deal
 
+        // This is a collection of all the latest resource events.
+        // We want these in order to correlate incoming resource events with their previous (in `occurredMillis` time)
+        // ones.
+        // Will be updated on processing the next resource event.
+        val previousResourceEvents = startingUserState.latestResourceEvents.toMutableWorker
+        clog.debug("previousResourceEvents = %s", previousResourceEvents)
 
-        val billingMonthEndDateCalc   = billingMonthStartDateCalc.copy.goEndOfThisMonth
         val billingMonthStartMillis = billingMonthStartDateCalc.toMillis
         val billingMonthEndMillis  = billingMonthEndDateCalc.toMillis
 
@@ -243,9 +232,12 @@ class UserStateComputations extends Loggable {
           userId,
           billingMonthStartMillis,
           billingMonthEndMillis)
+
+        clog.debug("resourceEventStore = %s".format(resourceEventStore))
+        clog.debug("Found %s resource events", allResourceEventsForMonth.size)
     }
 
-    D("-doFullMonthlyBilling()")
+    clog.end()
     null
   }
 
@@ -285,5 +277,3 @@ class UserStateComputations extends Loggable {
     previousRCEventsMap(newRCEvent.fullResourceInfo) = newRCEvent
   }
 }
-
-object DefaultUserStateComputations extends UserStateComputations
\ No newline at end of file
diff --git a/src/main/scala/gr/grnet/aquarium/util/ContextualLogger.scala b/src/main/scala/gr/grnet/aquarium/util/ContextualLogger.scala
new file mode 100644 (file)
index 0000000..cf2c1ce
--- /dev/null
@@ -0,0 +1,151 @@
+/*
+ * Copyright 2011 GRNET S.A. All rights reserved.
+ *
+ * Redistribution and use in source and binary forms, with or
+ * without modification, are permitted provided that the following
+ * conditions are met:
+ *
+ *   1. Redistributions of source code must retain the above
+ *      copyright notice, this list of conditions and the following
+ *      disclaimer.
+ *
+ *   2. Redistributions in binary form must reproduce the above
+ *      copyright notice, this list of conditions and the following
+ *      disclaimer in the documentation and/or other materials
+ *      provided with the distribution.
+ *
+ * THIS SOFTWARE IS PROVIDED BY GRNET S.A. ``AS IS'' AND ANY EXPRESS
+ * OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED
+ * WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR
+ * PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL GRNET S.A OR
+ * CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+ * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+ * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF
+ * USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED
+ * AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
+ * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN
+ * ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
+ * POSSIBILITY OF SUCH DAMAGE.
+ *
+ * The views and conclusions contained in the software and
+ * documentation are those of the authors and should not be
+ * interpreted as representing official policies, either expressed
+ * or implied, of GRNET S.A.
+ */
+
+package gr.grnet.aquarium.util
+
+import org.slf4j.Logger
+import com.ckkloverdos.maybe.{Just, Maybe}
+
+/**
+ * A logger that keeps track of working context and indentation level.
+ *
+ * @author Christos KK Loverdos <loverdos@gmail.com>
+ */
+final class ContextualLogger(val logger: Logger, fmt: String, args: Any*) {
+  val ctx = ContextualLogger.fixCtx(fmt.format(args:_*))
+
+  private[this] var _nesting = 0
+
+  private def nestMsg(fmt: String, args: Any*) = {
+    val msg = fmt.format(args: _*)
+    _nesting match {
+      case 0 ⇒
+        msg
+      case n ⇒
+        val buffer = new java.lang.StringBuilder(n + msg.size)
+        var _i = 0
+        while(_i < n) {
+          buffer.append(' ')
+          _i = _i + 1
+        }
+        buffer.append(msg)
+        buffer.toString
+    }
+  }
+
+  def nesting = _nesting
+
+  def indentAs(other: ContextualLogger): this.type = {
+    _nesting = other.nesting
+    this
+  }
+
+  def indent(): this.type   = {
+    _nesting = _nesting + 1
+    this
+  }
+
+  def unindent(): this.type = {
+    _nesting = _nesting - 1
+    this
+  }
+
+  @inline
+  def debug(fmt: String, args: Any*): Unit = {
+    if(logger.isDebugEnabled) {
+      val msg = ctx + " " + nestMsg(fmt, args:_*)
+      logger.debug(msg)
+    }
+  }
+
+  @inline
+  def warn(fmt: String, args: Any*): Unit = {
+    if(logger.isWarnEnabled) {
+      val msg = ctx + " " + nestMsg(fmt, args:_*)
+      logger.debug(msg)
+    }
+  }
+
+  @inline
+  def begin(): Unit = {
+    debug("BEGIN")
+    indent()
+  }
+
+  @inline
+  def end(): Unit = {
+    unindent()
+    debug("END")
+  }
+
+  @inline
+  def endWith[A](f: A): A = {
+    val retval = f
+    end()
+    retval
+  }
+}
+
+object ContextualLogger {
+  final val MaxCtxLength = 45
+  
+  def fixCtx(ctx: String): String = {
+    val ctxLen = ctx.length()
+    if(ctxLen == MaxCtxLength) {
+      ctx
+    } else if(ctxLen > MaxCtxLength) {
+      ctx.substring(0, MaxCtxLength)
+    } else {
+      val buffer = new java.lang.StringBuilder(MaxCtxLength)
+      val prefixLen = MaxCtxLength - ctxLen
+      var _i = 0
+      while(_i < prefixLen) {
+        buffer.append(' ')
+        _i = _i + 1
+      }
+      buffer.append(ctx)
+      buffer.toString
+    }
+  }
+  
+  def fromOther(clogM: Maybe[ContextualLogger], logger: Logger,  fmt: String, args: Any*): ContextualLogger = {
+    clogM match {
+      case Just(clog) ⇒
+        new ContextualLogger(clog.logger, fmt, args:_*).indentAs(clog)
+      case _ ⇒
+        new ContextualLogger(logger, fmt, args:_*)
+    }
+  }
+}