You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@openwhisk.apache.org by GitBox <gi...@apache.org> on 2018/01/24 17:41:12 UTC
[GitHub] rabbah closed pull request #2960: Reduce the number of logs on info level
rabbah closed pull request #2960: Reduce the number of logs on info level
URL: https://github.com/apache/incubator-openwhisk/pull/2960
This is a PR merged from a forked repository.
As GitHub hides the original diff on merge, it is displayed below for
the sake of provenance:
As this is a foreign pull request (from a fork), the diff is supplied
below (as it won't show otherwise due to GitHub magic):
diff --git a/common/scala/src/main/scala/whisk/common/Scheduler.scala b/common/scala/src/main/scala/whisk/common/Scheduler.scala
index c4bceeda96..28d150260e 100644
--- a/common/scala/src/main/scala/whisk/common/Scheduler.scala
+++ b/common/scala/src/main/scala/whisk/common/Scheduler.scala
@@ -61,7 +61,7 @@ object Scheduler {
}
}
override def postStop() = {
- logging.info(this, s"$name shutdown")
+ logging.debug(this, s"$name shutdown")
lastSchedule.foreach(_.cancel())
}
diff --git a/common/scala/src/main/scala/whisk/common/TransactionId.scala b/common/scala/src/main/scala/whisk/common/TransactionId.scala
index bdf9255521..72dde1e05f 100644
--- a/common/scala/src/main/scala/whisk/common/TransactionId.scala
+++ b/common/scala/src/main/scala/whisk/common/TransactionId.scala
@@ -24,7 +24,7 @@ import java.util.concurrent.atomic.AtomicInteger
import scala.math.BigDecimal.int2bigDecimal
import scala.util.Try
-import akka.event.Logging.{InfoLevel, WarningLevel}
+import akka.event.Logging.{DebugLevel, InfoLevel, WarningLevel}
import akka.event.Logging.LogLevel
import spray.json._
@@ -53,11 +53,12 @@ case class TransactionId private (meta: TransactionMetadata) extends AnyVal {
* @param message An additional message that is written into the log, together with the other information.
* @param logLevel The Loglevel, the message should have. Default is <code>InfoLevel</code>.
*/
- def mark(from: AnyRef, marker: LogMarkerToken, message: String = "", logLevel: LogLevel = InfoLevel)(
+ def mark(from: AnyRef, marker: LogMarkerToken, message: String = "", logLevel: LogLevel = DebugLevel)(
implicit logging: Logging) = {
if (TransactionId.metricsLog) {
- logging.emit(logLevel, this, from, createMessageWithMarker(message, LogMarker(marker, deltaToStart)))
+ // marker received with a debug level will be emitted on info level
+ logging.emit(InfoLevel, this, from, createMessageWithMarker(message, LogMarker(marker, deltaToStart)))
} else if (message.nonEmpty) {
logging.emit(logLevel, this, from, message)
}
@@ -79,11 +80,12 @@ case class TransactionId private (meta: TransactionMetadata) extends AnyVal {
*
* @return startMarker that has to be passed to the finished or failed method to calculate the time difference.
*/
- def started(from: AnyRef, marker: LogMarkerToken, message: String = "", logLevel: LogLevel = InfoLevel)(
+ def started(from: AnyRef, marker: LogMarkerToken, message: String = "", logLevel: LogLevel = DebugLevel)(
implicit logging: Logging): StartMarker = {
if (TransactionId.metricsLog) {
- logging.emit(logLevel, this, from, createMessageWithMarker(message, LogMarker(marker, deltaToStart)))
+ // marker received with a debug level will be emitted on info level
+ logging.emit(InfoLevel, this, from, createMessageWithMarker(message, LogMarker(marker, deltaToStart)))
} else if (message.nonEmpty) {
logging.emit(logLevel, this, from, message)
}
@@ -107,7 +109,7 @@ case class TransactionId private (meta: TransactionMetadata) extends AnyVal {
def finished(from: AnyRef,
startMarker: StartMarker,
message: String = "",
- logLevel: LogLevel = InfoLevel,
+ logLevel: LogLevel = DebugLevel,
endTime: Instant = Instant.now(Clock.systemUTC))(implicit logging: Logging) = {
val endMarker =
@@ -116,7 +118,7 @@ case class TransactionId private (meta: TransactionMetadata) extends AnyVal {
if (TransactionId.metricsLog) {
logging.emit(
- logLevel,
+ InfoLevel,
this,
from,
createMessageWithMarker(message, LogMarker(endMarker, deltaToStart, Some(deltaToEnd))))
diff --git a/common/scala/src/main/scala/whisk/core/connector/MessageConsumer.scala b/common/scala/src/main/scala/whisk/core/connector/MessageConsumer.scala
index 51977677ab..2dd8ba34b0 100644
--- a/common/scala/src/main/scala/whisk/core/connector/MessageConsumer.scala
+++ b/common/scala/src/main/scala/whisk/core/connector/MessageConsumer.scala
@@ -212,7 +212,7 @@ class MessageFeed(description: String,
val (topic, partition, offset, bytes) = outstandingMessages.head
outstandingMessages = outstandingMessages.tail
- if (logHandoff) logging.info(this, s"processing $topic[$partition][$offset] ($occupancy/$handlerCapacity)")
+ if (logHandoff) logging.debug(this, s"processing $topic[$partition][$offset] ($occupancy/$handlerCapacity)")
handler(bytes)
handlerCapacity -= 1
diff --git a/common/scala/src/main/scala/whisk/core/containerpool/Container.scala b/common/scala/src/main/scala/whisk/core/containerpool/Container.scala
index f3ebcf3758..49c692b086 100644
--- a/common/scala/src/main/scala/whisk/core/containerpool/Container.scala
+++ b/common/scala/src/main/scala/whisk/core/containerpool/Container.scala
@@ -40,6 +40,7 @@ import whisk.core.entity.ActivationResponse.ContainerResponse
import whisk.core.entity.ByteSize
import whisk.core.entity.size._
import whisk.http.Messages
+import akka.event.Logging.InfoLevel
/**
* An OpenWhisk biased container abstraction. This is **not only** an abstraction
@@ -79,7 +80,11 @@ trait Container {
/** Initializes code in the container. */
def initialize(initializer: JsObject, timeout: FiniteDuration)(implicit transid: TransactionId): Future[Interval] = {
- val start = transid.started(this, LoggingMarkers.INVOKER_ACTIVATION_INIT, s"sending initialization to $id $addr")
+ val start = transid.started(
+ this,
+ LoggingMarkers.INVOKER_ACTIVATION_INIT,
+ s"sending initialization to $id $addr",
+ logLevel = InfoLevel)
val body = JsObject("value" -> initializer)
callContainer("/init", body, timeout, retry = true)
@@ -89,7 +94,8 @@ trait Container {
this,
start.copy(start = r.interval.start),
s"initialization result: ${r.toBriefString}",
- endTime = r.interval.end)
+ endTime = r.interval.end,
+ logLevel = InfoLevel)
case Failure(t) =>
transid.failed(this, start, s"initializiation failed with $t")
}
@@ -115,7 +121,11 @@ trait Container {
implicit transid: TransactionId): Future[(Interval, ActivationResponse)] = {
val actionName = environment.fields.get("action_name").map(_.convertTo[String]).getOrElse("")
val start =
- transid.started(this, LoggingMarkers.INVOKER_ACTIVATION_RUN, s"sending arguments to $actionName at $id $addr")
+ transid.started(
+ this,
+ LoggingMarkers.INVOKER_ACTIVATION_RUN,
+ s"sending arguments to $actionName at $id $addr",
+ logLevel = InfoLevel)
val parameterWrapper = JsObject("value" -> parameters)
val body = JsObject(parameterWrapper.fields ++ environment.fields)
@@ -126,7 +136,8 @@ trait Container {
this,
start.copy(start = r.interval.start),
s"running result: ${r.toBriefString}",
- endTime = r.interval.end)
+ endTime = r.interval.end,
+ logLevel = InfoLevel)
case Failure(t) =>
transid.failed(this, start, s"run failed with $t")
}
diff --git a/common/scala/src/main/scala/whisk/core/database/MultipleReadersSingleWriterCache.scala b/common/scala/src/main/scala/whisk/core/database/MultipleReadersSingleWriterCache.scala
index 58663550fa..41751808a8 100644
--- a/common/scala/src/main/scala/whisk/core/database/MultipleReadersSingleWriterCache.scala
+++ b/common/scala/src/main/scala/whisk/core/database/MultipleReadersSingleWriterCache.scala
@@ -315,7 +315,7 @@ trait MultipleReadersSingleWriterCache[W, Winfo] {
*
*/
private def makeNoteOfCacheHit(key: CacheKey)(implicit transid: TransactionId, logger: Logging) = {
- transid.mark(this, LoggingMarkers.DATABASE_CACHE_HIT, s"[GET] serving from cache: $key")(logger)
+ transid.started(this, LoggingMarkers.DATABASE_CACHE_HIT, s"[GET] serving from cache: $key")(logger)
}
/**
@@ -323,7 +323,7 @@ trait MultipleReadersSingleWriterCache[W, Winfo] {
*
*/
private def makeNoteOfCacheMiss(key: CacheKey)(implicit transid: TransactionId, logger: Logging) = {
- transid.mark(this, LoggingMarkers.DATABASE_CACHE_MISS, s"[GET] serving from datastore: $key")(logger)
+ transid.started(this, LoggingMarkers.DATABASE_CACHE_MISS, s"[GET] serving from datastore: $key")(logger)
}
/**
diff --git a/core/controller/src/main/scala/whisk/core/controller/Actions.scala b/core/controller/src/main/scala/whisk/core/controller/Actions.scala
index d0a43c9f3e..1e26a6684c 100644
--- a/core/controller/src/main/scala/whisk/core/controller/Actions.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/Actions.scala
@@ -250,10 +250,10 @@ trait WhiskActionsApi extends WhiskCollectionAPI with PostActionActivation with
complete(InternalServerError, response)
}
case Failure(t: RecordTooLargeException) =>
- logging.info(this, s"[POST] action payload was too large")
+ logging.debug(this, s"[POST] action payload was too large")
terminate(RequestEntityTooLarge)
case Failure(RejectRequest(code, message)) =>
- logging.info(this, s"[POST] action rejected with code $code: $message")
+ logging.debug(this, s"[POST] action rejected with code $code: $message")
terminate(code, message)
case Failure(t: Throwable) =>
logging.error(this, s"[POST] action activation failed: ${t.getMessage}")
@@ -389,7 +389,7 @@ trait WhiskActionsApi extends WhiskCollectionAPI with PostActionActivation with
implicit transid: TransactionId) = {
exec match {
case Some(seq: SequenceExec) =>
- logging.info(this, "checking if sequence components are accessible")
+ logging.debug(this, "checking if sequence components are accessible")
entitlementProvider.check(user, right, referencedEntities(seq), noThrottle = true)
case _ => Future.successful(true)
}
@@ -516,10 +516,10 @@ trait WhiskActionsApi extends WhiskCollectionAPI with PostActionActivation with
// resolved namespace
getEntity(WhiskPackage, entityStore, pkgName.toDocId, Some { (wp: WhiskPackage) =>
val pkgns = wp.binding map { b =>
- logging.info(this, s"list actions in package binding '${wp.name}' -> '$b'")
+ logging.debug(this, s"list actions in package binding '${wp.name}' -> '$b'")
b.namespace.addPath(b.name)
} getOrElse {
- logging.info(this, s"list actions in package '${wp.name}'")
+ logging.debug(this, s"list actions in package '${wp.name}'")
pkgName.path.addPath(wp.name)
}
// list actions in resolved namespace
@@ -541,7 +541,7 @@ trait WhiskActionsApi extends WhiskCollectionAPI with PostActionActivation with
wp.binding map {
case b: Binding =>
val docid = b.fullyQualifiedName.toDocId
- logging.info(this, s"fetching package '$docid' for reference")
+ logging.debug(this, s"fetching package '$docid' for reference")
// already checked that subject is authorized for package and binding;
// this fetch is redundant but should hit the cache to ameliorate cost
getEntity(WhiskPackage, entityStore, docid, Some {
@@ -554,7 +554,7 @@ trait WhiskActionsApi extends WhiskCollectionAPI with PostActionActivation with
val ns = wp.namespace.addPath(wp.name) // the package namespace
val resource = Resource(ns, collection, Some { action.asString }, Some { params })
val right = collection.determineRight(method, resource.entity)
- logging.info(this, s"merged package parameters and rebased action to '$ns")
+ logging.debug(this, s"merged package parameters and rebased action to '$ns")
dispatchOp(user, right, resource)
}
}
diff --git a/core/controller/src/main/scala/whisk/core/controller/ApiUtils.scala b/core/controller/src/main/scala/whisk/core/controller/ApiUtils.scala
index 0f5b16c002..ea74d72f12 100644
--- a/core/controller/src/main/scala/whisk/core/controller/ApiUtils.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/ApiUtils.scala
@@ -97,7 +97,7 @@ trait ReadOps extends Directives {
protected def listEntities(list: Future[List[JsValue]])(implicit transid: TransactionId) = {
onComplete(list) {
case Success(entities) =>
- logging.info(this, s"[LIST] entity success")
+ logging.debug(this, s"[LIST] entity success")
complete(OK, entities)
case Failure(t: Throwable) =>
logging.error(this, s"[LIST] entity failed: ${t.getMessage}")
@@ -146,16 +146,16 @@ trait ReadOps extends Directives {
ma: Manifest[A]) = {
onComplete(factory.get(datastore, docid)) {
case Success(entity) =>
- logging.info(this, s"[GET] entity success")
+ logging.debug(this, s"[GET] entity success")
postProcess map { _(entity) } getOrElse complete(OK, entity)
case Failure(t: NoDocumentException) =>
- logging.info(this, s"[GET] entity does not exist")
+ logging.debug(this, s"[GET] entity does not exist")
terminate(NotFound)
case Failure(t: DocumentTypeMismatchException) =>
- logging.info(this, s"[GET] entity conformance check failed: ${t.getMessage}")
+ logging.debug(this, s"[GET] entity conformance check failed: ${t.getMessage}")
terminate(Conflict, conformanceMessage)
case Failure(t: ArtifactStoreException) =>
- logging.info(this, s"[GET] entity unreadable")
+ logging.debug(this, s"[GET] entity unreadable")
terminate(InternalServerError, t.getMessage)
case Failure(t: Throwable) =>
logging.error(this, s"[GET] entity failed: ${t.getMessage}")
@@ -183,16 +183,16 @@ trait ReadOps extends Directives {
project: A => Future[JsObject])(implicit transid: TransactionId, format: RootJsonFormat[A], ma: Manifest[A]) = {
onComplete(factory.get(datastore, docid)) {
case Success(entity) =>
- logging.info(this, s"[PROJECT] entity success")
+ logging.debug(this, s"[PROJECT] entity success")
complete(OK, project(entity))
case Failure(t: NoDocumentException) =>
- logging.info(this, s"[PROJECT] entity does not exist")
+ logging.debug(this, s"[PROJECT] entity does not exist")
terminate(NotFound)
case Failure(t: DocumentTypeMismatchException) =>
- logging.info(this, s"[PROJECT] entity conformance check failed: ${t.getMessage}")
+ logging.debug(this, s"[PROJECT] entity conformance check failed: ${t.getMessage}")
terminate(Conflict, conformanceMessage)
case Failure(t: ArtifactStoreException) =>
- logging.info(this, s"[PROJECT] entity unreadable")
+ logging.debug(this, s"[PROJECT] entity unreadable")
terminate(InternalServerError, t.getMessage)
case Failure(t: Throwable) =>
logging.error(this, s"[PROJECT] entity failed: ${t.getMessage}")
@@ -256,41 +256,41 @@ trait WriteOps extends Directives {
onComplete(factory.get(datastore, docid) flatMap { doc =>
if (overwrite) {
- logging.info(this, s"[PUT] entity exists, will try to update '$doc'")
+ logging.debug(this, s"[PUT] entity exists, will try to update '$doc'")
update(doc)
} else if (treatExistsAsConflict) {
- logging.info(this, s"[PUT] entity exists, but overwrite is not enabled, aborting")
+ logging.debug(this, s"[PUT] entity exists, but overwrite is not enabled, aborting")
Future failed RejectRequest(Conflict, "resource already exists")
} else {
Future failed IdentityPut(doc)
}
} recoverWith {
case _: NoDocumentException =>
- logging.info(this, s"[PUT] entity does not exist, will try to create it")
+ logging.debug(this, s"[PUT] entity does not exist, will try to create it")
create()
} flatMap { a =>
- logging.info(this, s"[PUT] entity created/updated, writing back to datastore")
+ logging.debug(this, s"[PUT] entity created/updated, writing back to datastore")
factory.put(datastore, a) map { _ =>
a
}
}) {
case Success(entity) =>
- logging.info(this, s"[PUT] entity success")
+ logging.debug(this, s"[PUT] entity success")
postProcess map { _(entity) } getOrElse complete(OK, entity)
case Failure(IdentityPut(a)) =>
- logging.info(this, s"[PUT] entity exists, not overwritten")
+ logging.debug(this, s"[PUT] entity exists, not overwritten")
complete(OK, a)
case Failure(t: DocumentConflictException) =>
- logging.info(this, s"[PUT] entity conflict: ${t.getMessage}")
+ logging.debug(this, s"[PUT] entity conflict: ${t.getMessage}")
terminate(Conflict, conflictMessage)
case Failure(RejectRequest(code, message)) =>
- logging.info(this, s"[PUT] entity rejected with code $code: $message")
+ logging.debug(this, s"[PUT] entity rejected with code $code: $message")
terminate(code, message)
case Failure(t: DocumentTypeMismatchException) =>
- logging.info(this, s"[PUT] entity conformance check failed: ${t.getMessage}")
+ logging.debug(this, s"[PUT] entity conformance check failed: ${t.getMessage}")
terminate(Conflict, conformanceMessage)
case Failure(t: ArtifactStoreException) =>
- logging.info(this, s"[PUT] entity unreadable")
+ logging.debug(this, s"[PUT] entity unreadable")
terminate(InternalServerError, t.getMessage)
case Failure(t: Throwable) =>
logging.error(this, s"[PUT] entity failed: ${t.getMessage}")
@@ -333,22 +333,22 @@ trait WriteOps extends Directives {
}
}) {
case Success(entity) =>
- logging.info(this, s"[DEL] entity success")
+ logging.debug(this, s"[DEL] entity success")
postProcess map { _(entity) } getOrElse complete(OK, entity)
case Failure(t: NoDocumentException) =>
- logging.info(this, s"[DEL] entity does not exist")
+ logging.debug(this, s"[DEL] entity does not exist")
terminate(NotFound)
case Failure(t: DocumentConflictException) =>
- logging.info(this, s"[DEL] entity conflict: ${t.getMessage}")
+ logging.debug(this, s"[DEL] entity conflict: ${t.getMessage}")
terminate(Conflict, conflictMessage)
case Failure(RejectRequest(code, message)) =>
- logging.info(this, s"[DEL] entity rejected with code $code: $message")
+ logging.debug(this, s"[DEL] entity rejected with code $code: $message")
terminate(code, message)
case Failure(t: DocumentTypeMismatchException) =>
- logging.info(this, s"[DEL] entity conformance check failed: ${t.getMessage}")
+ logging.debug(this, s"[DEL] entity conformance check failed: ${t.getMessage}")
terminate(Conflict, conformanceMessage)
case Failure(t: ArtifactStoreException) =>
- logging.info(this, s"[DEL] entity unreadable")
+ logging.error(this, s"[DEL] entity unreadable")
terminate(InternalServerError, t.getMessage)
case Failure(t: Throwable) =>
logging.error(this, s"[DEL] entity failed: ${t.getMessage}")
diff --git a/core/controller/src/main/scala/whisk/core/controller/Authenticate.scala b/core/controller/src/main/scala/whisk/core/controller/Authenticate.scala
index cf8899fa64..70ea3efaf2 100644
--- a/core/controller/src/main/scala/whisk/core/controller/Authenticate.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/Authenticate.scala
@@ -62,22 +62,22 @@ trait Authenticate {
logging.info(this, s"authenticate: ${authkey.uuid}")
val future = Identity.get(authStore, authkey) map { result =>
if (authkey == result.authkey) {
- logging.info(this, s"authentication valid")
+ logging.debug(this, s"authentication valid")
Some(result)
} else {
- logging.info(this, s"authentication not valid")
+ logging.debug(this, s"authentication not valid")
None
}
} recover {
case _: NoDocumentException | _: IllegalArgumentException =>
- logging.info(this, s"authentication not valid")
+ logging.debug(this, s"authentication not valid")
None
}
future onFailure { case t => logging.error(this, s"authentication error: $t") }
future
}.toOption
} getOrElse {
- credentials.foreach(_ => logging.info(this, s"credentials are malformed"))
+ credentials.foreach(_ => logging.debug(this, s"credentials are malformed"))
Future.successful(None)
}
}
diff --git a/core/controller/src/main/scala/whisk/core/controller/Controller.scala b/core/controller/src/main/scala/whisk/core/controller/Controller.scala
index 53408c3438..2ccbf2f642 100644
--- a/core/controller/src/main/scala/whisk/core/controller/Controller.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/Controller.scala
@@ -29,11 +29,8 @@ import akka.http.scaladsl.model.Uri
import akka.http.scaladsl.server.Route
import akka.stream.ActorMaterializer
import spray.json._
-
import spray.json.DefaultJsonProtocol._
-
import kamon.Kamon
-
import whisk.common.AkkaLogging
import whisk.common.Logging
import whisk.common.LoggingMarkers
@@ -51,6 +48,7 @@ import whisk.http.BasicHttpService
import whisk.http.BasicRasService
import whisk.spi.SpiLoader
import whisk.core.containerpool.logging.LogStoreProvider
+import akka.event.Logging.InfoLevel
/**
* The Controller is the service that provides the REST API for OpenWhisk.
@@ -88,7 +86,8 @@ class Controller(val instance: InstanceId,
TransactionId.controller.mark(
this,
LoggingMarkers.CONTROLLER_STARTUP(instance.toInt),
- s"starting controller instance ${instance.toInt}")
+ s"starting controller instance ${instance.toInt}",
+ logLevel = InfoLevel)
/**
* A Route in Akka is technically a function taking a RequestContext as a parameter.
diff --git a/core/controller/src/main/scala/whisk/core/controller/Packages.scala b/core/controller/src/main/scala/whisk/core/controller/Packages.scala
index 6a646c043f..ef52f274fc 100644
--- a/core/controller/src/main/scala/whisk/core/controller/Packages.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/Packages.scala
@@ -75,9 +75,8 @@ trait WhiskPackagesApi extends WhiskCollectionAPI with ReferencedEntities {
if (!RESERVED_NAMES.contains(entityName.name.asString)) {
entity(as[WhiskPackagePut]) { content =>
val request = content.resolve(entityName.namespace)
-
request.binding.map { b =>
- logging.info(this, "checking if package is accessible")
+ logging.debug(this, "checking if package is accessible")
}
val referencedentities = referencedEntities(request)
@@ -266,7 +265,7 @@ trait WhiskPackagesApi extends WhiskCollectionAPI with ReferencedEntities {
private def rewriteEntitlementFailure(failure: Throwable)(
implicit transid: TransactionId): RequestContext => Future[RouteResult] = {
- logging.info(this, s"rewriting failure $failure")
+ logging.debug(this, s"rewriting failure $failure")
failure match {
case RejectRequest(NotFound, _) => terminate(BadRequest, Messages.bindingDoesNotExist)
case RejectRequest(Conflict, _) => terminate(Conflict, Messages.requestedBindingIsNotValid)
@@ -297,13 +296,13 @@ trait WhiskPackagesApi extends WhiskCollectionAPI with ReferencedEntities {
wp.binding map {
case b: Binding =>
val docid = b.fullyQualifiedName.toDocId
- logging.info(this, s"fetching package '$docid' for reference")
+ logging.debug(this, s"fetching package '$docid' for reference")
getEntity(WhiskPackage, entityStore, docid, Some {
mergePackageWithBinding(Some { wp }) _
})
} getOrElse {
val pkg = ref map { _ inherit wp.parameters } getOrElse wp
- logging.info(this, s"fetching package actions in '${wp.fullPath}'")
+ logging.debug(this, s"fetching package actions in '${wp.fullPath}'")
val actions = WhiskAction.listCollectionInNamespace(entityStore, wp.fullPath, skip = 0, limit = 0) flatMap {
case Left(list) =>
Future.successful {
@@ -320,7 +319,7 @@ trait WhiskPackagesApi extends WhiskCollectionAPI with ReferencedEntities {
onComplete(actions) {
case Success(p) =>
- logging.info(this, s"[GET] entity success")
+ logging.debug(this, s"[GET] entity success")
complete(OK, p)
case Failure(t) =>
logging.error(this, s"[GET] failed: ${t.getMessage}")
diff --git a/core/controller/src/main/scala/whisk/core/controller/Rules.scala b/core/controller/src/main/scala/whisk/core/controller/Rules.scala
index 9561d3713c..3031222c7b 100644
--- a/core/controller/src/main/scala/whisk/core/controller/Rules.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/Rules.scala
@@ -123,17 +123,17 @@ trait WhiskRulesApi extends WhiskCollectionAPI with ReferencedEntities {
} flatMap {
oldStatus =>
if (requestedState != oldStatus) {
- logging.info(this, s"[POST] rule state change initiated: ${oldStatus} -> $requestedState")
+ logging.debug(this, s"[POST] rule state change initiated: ${oldStatus} -> $requestedState")
Future successful requestedState
} else {
- logging.info(
+ logging.debug(
this,
s"[POST] rule state will not be changed, the requested state is the same as the old state: ${oldStatus} -> $requestedState")
Future failed { IgnoredRuleActivation(requestedState == oldStatus) }
}
} flatMap {
case (newStatus) =>
- logging.info(this, s"[POST] attempting to set rule state to: ${newStatus}")
+ logging.debug(this, s"[POST] attempting to set rule state to: ${newStatus}")
WhiskTrigger.get(entityStore, rule.trigger.toDocId) flatMap { trigger =>
val newTrigger = trigger.removeRule(ruleName)
val triggerLink = ReducedRule(rule.action, newStatus)
@@ -147,13 +147,13 @@ trait WhiskRulesApi extends WhiskCollectionAPI with ReferencedEntities {
case Failure(t) =>
t match {
case _: DocumentConflictException =>
- logging.info(this, s"[POST] rule update conflict")
+ logging.debug(this, s"[POST] rule update conflict")
terminate(Conflict, conflictMessage)
case IgnoredRuleActivation(ok) =>
- logging.info(this, s"[POST] rule update ignored")
+ logging.debug(this, s"[POST] rule update ignored")
if (ok) complete(OK) else terminate(Conflict)
case _: NoDocumentException =>
- logging.info(this, s"[POST] the trigger attached to the rule doesn't exist")
+ logging.debug(this, s"[POST] the trigger attached to the rule doesn't exist")
terminate(NotFound, "Only rules with existing triggers can be activated")
case _: DeserializationException =>
logging.error(this, s"[POST] rule update failed: ${t.getMessage}")
@@ -272,7 +272,7 @@ trait WhiskRulesApi extends WhiskCollectionAPI with ReferencedEntities {
content.annotations getOrElse Parameters())
val triggerLink = ReducedRule(actionName, Status.ACTIVE)
- logging.info(this, s"about to put ${trigger.addRule(ruleName, triggerLink)}")
+ logging.debug(this, s"about to put ${trigger.addRule(ruleName, triggerLink)}")
WhiskTrigger.put(entityStore, trigger.addRule(ruleName, triggerLink)) map { _ =>
rule
}
diff --git a/core/controller/src/main/scala/whisk/core/controller/Triggers.scala b/core/controller/src/main/scala/whisk/core/controller/Triggers.scala
index 3893f57a4f..044d5a25fb 100644
--- a/core/controller/src/main/scala/whisk/core/controller/Triggers.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/Triggers.scala
@@ -122,7 +122,7 @@ trait WhiskTriggersApi extends WhiskCollectionAPI {
version = trigger.version,
duration = None)
- logging.info(this, s"[POST] trigger activated, writing activation record to datastore: $triggerActivationId")
+ logging.debug(this, s"[POST] trigger activated, writing activation record to datastore: $triggerActivationId")
WhiskActivation.put(activationStore, triggerActivation) recover {
case t =>
logging.error(this, s"[POST] storing trigger activation $triggerActivationId failed: ${t.getMessage}")
@@ -178,7 +178,7 @@ trait WhiskTriggersApi extends WhiskCollectionAPI {
}
case NotFound =>
response.discardEntityBytes()
- logging.info(this, s"${rule.action} failed, action not found")
+ logging.debug(this, s"${rule.action} failed, action not found")
case _ =>
Unmarshal(response.entity).to[String].map { error =>
logging.warn(this, s"${rule.action} failed due to $error")
diff --git a/core/controller/src/main/scala/whisk/core/controller/WebActions.scala b/core/controller/src/main/scala/whisk/core/controller/WebActions.scala
index 8cfb1e935e..2642366a51 100644
--- a/core/controller/src/main/scala/whisk/core/controller/WebActions.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/WebActions.scala
@@ -658,7 +658,7 @@ trait WhiskWebActionsApi extends Directives with ValidateRequestSize with PostAc
case Success(Left(activationId)) =>
// blocking invoke which got queued instead
// this should not happen, instead it should be a blocking invoke timeout
- logging.info(this, "activation waiting period expired")
+ logging.debug(this, "activation waiting period expired")
terminate(Accepted, Messages.responseNotReady)
case Failure(t: RejectRequest) => terminate(t.code, t.message)
@@ -680,10 +680,10 @@ trait WhiskWebActionsApi extends Directives with ValidateRequestSize with PostAc
// if the package lookup fails or the package doesn't conform to expected invariants,
// fail the request with BadRequest so as not to leak information about the existence
// of packages that are otherwise private
- logging.info(this, s"package which does not exist")
+ logging.debug(this, s"package which does not exist")
Future.failed(RejectRequest(NotFound))
case _: NoSuchElementException =>
- logging.warn(this, s"'$pkg' is a binding")
+ logging.debug(this, s"'$pkg' is a binding")
Future.failed(RejectRequest(NotFound))
}
}
@@ -725,13 +725,13 @@ trait WhiskWebActionsApi extends Directives with ValidateRequestSize with PostAc
if ((isExported && requiresAuthenticatedUser && authenticated) ||
(isExported && !requiresAuthenticatedUser)) {
- logging.info(this, s"${action.fullyQualifiedName(true)} is exported")
+ logging.debug(this, s"${action.fullyQualifiedName(true)} is exported")
Future.successful(action)
} else if (!isExported) {
- logging.info(this, s"${action.fullyQualifiedName(true)} not exported")
+ logging.debug(this, s"${action.fullyQualifiedName(true)} not exported")
Future.failed(RejectRequest(NotFound))
} else {
- logging.info(this, s"${action.fullyQualifiedName(true)} requires authentication")
+ logging.debug(this, s"${action.fullyQualifiedName(true)} requires authentication")
Future.failed(RejectRequest(Unauthorized))
}
}
diff --git a/core/controller/src/main/scala/whisk/core/controller/actions/PrimitiveActions.scala b/core/controller/src/main/scala/whisk/core/controller/actions/PrimitiveActions.scala
index bf24cbe79d..9302f4c9a9 100644
--- a/core/controller/src/main/scala/whisk/core/controller/actions/PrimitiveActions.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/actions/PrimitiveActions.scala
@@ -22,7 +22,6 @@ import scala.concurrent.Future
import scala.concurrent.Promise
import scala.concurrent.duration._
import scala.util.Failure
-
import akka.actor.Actor
import akka.actor.ActorRef
import akka.actor.ActorSystem
@@ -40,6 +39,7 @@ import whisk.core.entity._
import whisk.core.entity.types.ActivationStore
import whisk.core.entity.types.EntityStore
import whisk.utils.ExecutionContextFactory.FutureExtensions
+import akka.event.Logging.InfoLevel
protected[actions] trait PrimitiveActions {
/** The core collections require backend services to be injected in this trait. */
@@ -114,7 +114,8 @@ protected[actions] trait PrimitiveActions {
this,
waitForResponse
.map(_ => LoggingMarkers.CONTROLLER_ACTIVATION_BLOCKING)
- .getOrElse(LoggingMarkers.CONTROLLER_ACTIVATION))
+ .getOrElse(LoggingMarkers.CONTROLLER_ACTIVATION),
+ logLevel = InfoLevel)
val startLoadbalancer =
transid.started(this, LoggingMarkers.CONTROLLER_LOADBALANCER, s"action activation id: ${message.activationId}")
val postedFuture = loadBalancer.publish(action, message)
@@ -163,7 +164,7 @@ protected[actions] trait PrimitiveActions {
WhiskActivation.get(activationStore, docid)
})
- logging.info(this, s"action activation will block for result upto $totalWaitTime")
+ logging.debug(this, s"action activation will block for result upto $totalWaitTime")
activeAckResponse map {
case result @ Right(_) =>
@@ -277,7 +278,7 @@ protected[actions] object ActivationFinisher {
}
override def postStop() = {
- logging.info(this, "finisher shutdown")
+ logging.debug(this, "finisher shutdown")
preemptiveMsgs.foreach(_.cancel())
preemptiveMsgs = Vector.empty
context.stop(poller)
diff --git a/core/controller/src/main/scala/whisk/core/controller/actions/SequenceActions.scala b/core/controller/src/main/scala/whisk/core/controller/actions/SequenceActions.scala
index 90b2c2a000..6232c0eb88 100644
--- a/core/controller/src/main/scala/whisk/core/controller/actions/SequenceActions.scala
+++ b/core/controller/src/main/scala/whisk/core/controller/actions/SequenceActions.scala
@@ -123,7 +123,7 @@ protected[actions] trait SequenceActions {
if (topmost) { // need to deal with blocking and closing connection
waitForOutermostResponse
.map { timeout =>
- logging.info(this, s"invoke sequence blocking topmost!")
+ logging.debug(this, s"invoke sequence blocking topmost!")
futureSeqResult.withAlternativeAfterTimeout(
timeout,
Future.successful(Left(seqActivationId), atomicActionsCount))
@@ -174,9 +174,9 @@ protected[actions] trait SequenceActions {
* Stores sequence activation to database.
*/
private def storeSequenceActivation(activation: WhiskActivation)(implicit transid: TransactionId): Unit = {
- logging.info(this, s"recording activation '${activation.activationId}'")
+ logging.debug(this, s"recording activation '${activation.activationId}'")
WhiskActivation.put(activationStore, activation)(transid, notifier = None) onComplete {
- case Success(id) => logging.info(this, s"recorded activation")
+ case Success(id) => logging.debug(this, s"recorded activation")
case Failure(t) =>
logging.error(
this,
diff --git a/core/controller/src/main/scala/whisk/core/entitlement/ActivationThrottler.scala b/core/controller/src/main/scala/whisk/core/entitlement/ActivationThrottler.scala
index 6256af2a5b..1a787e5b55 100644
--- a/core/controller/src/main/scala/whisk/core/entitlement/ActivationThrottler.scala
+++ b/core/controller/src/main/scala/whisk/core/entitlement/ActivationThrottler.scala
@@ -48,7 +48,7 @@ class ActivationThrottler(loadBalancer: LoadBalancer, defaultConcurrencyLimit: I
def check(user: Identity)(implicit tid: TransactionId): Future[RateLimit] = {
loadBalancer.activeActivationsFor(user.uuid).map { concurrentActivations =>
val concurrencyLimit = user.limits.concurrentInvocations.getOrElse(defaultConcurrencyLimit)
- logging.info(
+ logging.debug(
this,
s"namespace = ${user.uuid.asString}, concurrent activations = $concurrentActivations, below limit = $concurrencyLimit")
ConcurrentRateLimit(concurrentActivations, concurrencyLimit)
@@ -60,10 +60,12 @@ class ActivationThrottler(loadBalancer: LoadBalancer, defaultConcurrencyLimit: I
*/
def isOverloaded()(implicit tid: TransactionId): Future[Boolean] = {
loadBalancer.totalActiveActivations.map { concurrentActivations =>
- logging.info(
- this,
- s"concurrent activations in system = $concurrentActivations, below limit = $systemOverloadLimit")
- concurrentActivations > systemOverloadLimit
+ val overloaded = concurrentActivations > systemOverloadLimit
+ if (overloaded)
+ logging.info(
+ this,
+ s"concurrent activations in system = $concurrentActivations, below limit = $systemOverloadLimit")
+ overloaded
}
}
}
diff --git a/core/controller/src/main/scala/whisk/core/entitlement/Entitlement.scala b/core/controller/src/main/scala/whisk/core/entitlement/Entitlement.scala
index 734fa09025..9f97d719ef 100644
--- a/core/controller/src/main/scala/whisk/core/entitlement/Entitlement.scala
+++ b/core/controller/src/main/scala/whisk/core/entitlement/Entitlement.scala
@@ -160,10 +160,10 @@ protected[core] abstract class EntitlementProvider(config: WhiskConfig, loadBala
*/
protected[core] def checkThrottles(user: Identity)(implicit transid: TransactionId): Future[Unit] = {
- logging.info(this, s"checking user '${user.subject}' has not exceeded activation quota")
+ logging.debug(this, s"checking user '${user.subject}' has not exceeded activation quota")
checkSystemOverload(ACTIVATE)
- .flatMap(_ => checkThrottleOverload(Future.successful(invokeRateThrottler.check(user))))
- .flatMap(_ => checkThrottleOverload(concurrentInvokeThrottler.check(user)))
+ .flatMap(_ => checkThrottleOverload(Future.successful(invokeRateThrottler.check(user)), user))
+ .flatMap(_ => checkThrottleOverload(concurrentInvokeThrottler.check(user), user))
}
/**
@@ -218,7 +218,7 @@ protected[core] abstract class EntitlementProvider(config: WhiskConfig, loadBala
val entitlementCheck: Future[Unit] = if (user.rights.contains(right)) {
if (resources.nonEmpty) {
- logging.info(this, s"checking user '$subject' has privilege '$right' for '${resources.mkString(", ")}'")
+ logging.debug(this, s"checking user '$subject' has privilege '$right' for '${resources.mkString(", ")}'")
val throttleCheck =
if (noThrottle) Future.successful(())
else
@@ -234,7 +234,7 @@ protected[core] abstract class EntitlementProvider(config: WhiskConfig, loadBala
})
} else Future.successful(())
} else if (right != REJECT) {
- logging.info(
+ logging.debug(
this,
s"supplied authkey for user '$subject' does not have privilege '$right' for '${resources.mkString(", ")}'")
Future.failed(unauthorizedOn(resources))
@@ -244,9 +244,9 @@ protected[core] abstract class EntitlementProvider(config: WhiskConfig, loadBala
entitlementCheck andThen {
case Success(rs) =>
- logging.info(this, "authorized")
+ logging.debug(this, "authorized")
case Failure(r: RejectRequest) =>
- logging.info(this, s"not authorized: $r")
+ logging.debug(this, s"not authorized: $r")
case Failure(t) =>
logging.error(this, s"failed while checking entitlement: ${t.getMessage}")
}
@@ -269,7 +269,7 @@ protected[core] abstract class EntitlementProvider(config: WhiskConfig, loadBala
resource.collection.implicitRights(user, defaultNamespaces, right, resource) flatMap {
case true => Future.successful(resource -> true)
case false =>
- logging.info(this, "checking explicit grants")
+ logging.debug(this, "checking explicit grants")
entitled(user.subject, right, resource).flatMap(b => Future.successful(resource -> b))
}
}
@@ -307,9 +307,9 @@ protected[core] abstract class EntitlementProvider(config: WhiskConfig, loadBala
implicit transid: TransactionId): Future[Unit] = {
if (right == ACTIVATE) {
if (resources.exists(_.collection.path == Collection.ACTIONS)) {
- checkThrottleOverload(Future.successful(invokeRateThrottler.check(user)))
+ checkThrottleOverload(Future.successful(invokeRateThrottler.check(user)), user)
} else if (resources.exists(_.collection.path == Collection.TRIGGERS)) {
- checkThrottleOverload(Future.successful(triggerRateThrottler.check(user)))
+ checkThrottleOverload(Future.successful(triggerRateThrottler.check(user)), user)
} else Future.successful(())
} else Future.successful(())
}
@@ -328,15 +328,17 @@ protected[core] abstract class EntitlementProvider(config: WhiskConfig, loadBala
private def checkConcurrentUserThrottle(user: Identity, right: Privilege, resources: Set[Resource])(
implicit transid: TransactionId): Future[Unit] = {
if (right == ACTIVATE && resources.exists(_.collection.path == Collection.ACTIONS)) {
- checkThrottleOverload(concurrentInvokeThrottler.check(user))
+ checkThrottleOverload(concurrentInvokeThrottler.check(user), user)
} else Future.successful(())
}
- private def checkThrottleOverload(throttle: Future[RateLimit])(implicit transid: TransactionId): Future[Unit] = {
+ private def checkThrottleOverload(throttle: Future[RateLimit], user: Identity)(
+ implicit transid: TransactionId): Future[Unit] = {
throttle.flatMap { limit =>
if (limit.ok) {
Future.successful(())
} else {
+ logging.info(this, s"'${user.namespace}' has exceeded its throttle limit, ${limit.errorMsg}")
Future.failed(RejectRequest(TooManyRequests, limit.errorMsg))
}
}
diff --git a/core/controller/src/main/scala/whisk/core/entitlement/LocalEntitlement.scala b/core/controller/src/main/scala/whisk/core/entitlement/LocalEntitlement.scala
index a912899c38..e9155f7219 100644
--- a/core/controller/src/main/scala/whisk/core/entitlement/LocalEntitlement.scala
+++ b/core/controller/src/main/scala/whisk/core/entitlement/LocalEntitlement.scala
@@ -49,7 +49,7 @@ protected[core] class LocalEntitlementProvider(private val config: WhiskConfig,
synchronized {
val key = (subject, resource.id)
matrix.put(key, matrix.get(key) map { _ + right } getOrElse Set(right))
- logging.info(this, s"granted user '$subject' privilege '$right' for '$resource'")
+ logging.debug(this, s"granted user '$subject' privilege '$right' for '$resource'")
true
}
}
@@ -60,7 +60,7 @@ protected[core] class LocalEntitlementProvider(private val config: WhiskConfig,
synchronized {
val key = (subject, resource.id)
val newrights = matrix.get(key) map { _ - right } map { matrix.put(key, _) }
- logging.info(this, s"revoked user '$subject' privilege '$right' for '$resource'")
+ logging.debug(this, s"revoked user '$subject' privilege '$right' for '$resource'")
true
}
}
diff --git a/core/controller/src/main/scala/whisk/core/entitlement/PackageCollection.scala b/core/controller/src/main/scala/whisk/core/entitlement/PackageCollection.scala
index 9d1078038c..30ff6be3cb 100644
--- a/core/controller/src/main/scala/whisk/core/entitlement/PackageCollection.scala
+++ b/core/controller/src/main/scala/whisk/core/entitlement/PackageCollection.scala
@@ -90,22 +90,22 @@ class PackageCollection(entityStore: EntityStore)(implicit logging: Logging) ext
WhiskPackage.get(entityStore, doc) flatMap {
case wp if wp.binding.isEmpty =>
val allowed = wp.publish || isOwner
- logging.info(this, s"entitlement check on package, '$right' allowed?: $allowed")
+ logging.debug(this, s"entitlement check on package, '$right' allowed?: $allowed")
Future.successful(allowed)
case wp =>
if (isOwner) {
val binding = wp.binding.get
val pkgOwner = namespaces.contains(binding.namespace.asString)
val pkgDocid = binding.docid
- logging.info(this, s"checking subject has privilege '$right' for bound package '$pkgDocid'")
+ logging.debug(this, s"checking subject has privilege '$right' for bound package '$pkgDocid'")
checkPackageReadPermission(namespaces, pkgOwner, pkgDocid)
} else {
- logging.info(this, s"entitlement check on package binding, '$right' allowed?: false")
+ logging.debug(this, s"entitlement check on package binding, '$right' allowed?: false")
Future.successful(false)
}
} recoverWith {
case t: NoDocumentException =>
- logging.info(this, s"the package does not exist (owner? $isOwner)")
+ logging.debug(this, s"the package does not exist (owner? $isOwner)")
// if owner, reject with not found, otherwise fail the future to reject with
// unauthorized (this prevents information leaks about packages in other namespaces)
if (isOwner) {
@@ -114,7 +114,7 @@ class PackageCollection(entityStore: EntityStore)(implicit logging: Logging) ext
Future.successful(false)
}
case t: DocumentTypeMismatchException =>
- logging.info(this, s"the requested binding is not a package (owner? $isOwner)")
+ logging.debug(this, s"the requested binding is not a package (owner? $isOwner)")
// if owner, reject with not found, otherwise fail the future to reject with
// unauthorized (this prevents information leaks about packages in other namespaces)
if (isOwner) {
diff --git a/core/controller/src/main/scala/whisk/core/entitlement/RateThrottler.scala b/core/controller/src/main/scala/whisk/core/entitlement/RateThrottler.scala
index ef2cf22ae4..fd0b56a836 100644
--- a/core/controller/src/main/scala/whisk/core/entitlement/RateThrottler.scala
+++ b/core/controller/src/main/scala/whisk/core/entitlement/RateThrottler.scala
@@ -33,7 +33,7 @@ import java.util.concurrent.atomic.AtomicInteger
class RateThrottler(description: String, defaultMaxPerMinute: Int, overrideMaxPerMinute: Identity => Option[Int])(
implicit logging: Logging) {
- logging.info(this, s"$description: defaultMaxPerMinute = $defaultMaxPerMinute")(TransactionId.controller)
+ logging.debug(this, s"$description: defaultMaxPerMinute = $defaultMaxPerMinute")(TransactionId.controller)
/**
* Maintains map of subject namespace to operations rates.
diff --git a/core/controller/src/main/scala/whisk/core/loadBalancer/ContainerPoolBalancer.scala b/core/controller/src/main/scala/whisk/core/loadBalancer/ContainerPoolBalancer.scala
index ffd831d079..f2614e0ca2 100644
--- a/core/controller/src/main/scala/whisk/core/loadBalancer/ContainerPoolBalancer.scala
+++ b/core/controller/src/main/scala/whisk/core/loadBalancer/ContainerPoolBalancer.scala
@@ -34,6 +34,7 @@ import whisk.core.entity._
import whisk.core.entity.types.EntityStore
import whisk.core.{ConfigKeys, WhiskConfig}
import whisk.spi.SpiLoader
+import akka.event.Logging.InfoLevel
import scala.annotation.tailrec
import scala.concurrent.duration._
@@ -202,11 +203,16 @@ class ContainerPoolBalancer(config: WhiskConfig, instance: InstanceId)(implicit
val start = transid.started(
this,
LoggingMarkers.CONTROLLER_KAFKA,
- s"posting topic '$topic' with activation id '${msg.activationId}'")
+ s"posting topic '$topic' with activation id '${msg.activationId}'",
+ logLevel = InfoLevel)
producer.send(topic, msg).andThen {
case Success(status) =>
- transid.finished(this, start, s"posted to ${status.topic()}[${status.partition()}][${status.offset()}]")
+ transid.finished(
+ this,
+ start,
+ s"posted to ${status.topic()}[${status.partition()}][${status.offset()}]",
+ logLevel = InfoLevel)
case Failure(e) => transid.failed(this, start, s"error on posting to topic $topic")
}
}
diff --git a/core/invoker/src/main/scala/whisk/core/containerpool/ContainerProxy.scala b/core/invoker/src/main/scala/whisk/core/containerpool/ContainerProxy.scala
index 23d0965107..805c2a1b0c 100644
--- a/core/invoker/src/main/scala/whisk/core/containerpool/ContainerProxy.scala
+++ b/core/invoker/src/main/scala/whisk/core/containerpool/ContainerProxy.scala
@@ -37,6 +37,7 @@ import whisk.core.entity._
import whisk.core.entity.size._
import whisk.core.entity.ExecManifest.ImageName
import whisk.http.Messages
+import akka.event.Logging.InfoLevel
// States
sealed trait ContainerState
@@ -379,7 +380,7 @@ class ContainerProxy(
// Adds logs to the raw activation.
val activationWithLogs: Future[Either[ActivationLogReadingError, WhiskActivation]] = activation
.flatMap { activation =>
- val start = tid.started(this, LoggingMarkers.INVOKER_COLLECT_LOGS)
+ val start = tid.started(this, LoggingMarkers.INVOKER_COLLECT_LOGS, logLevel = InfoLevel)
collectLogs(tid, job.msg.user, activation, container, job.action)
.andThen {
case Success(_) => tid.finished(this, start)
diff --git a/core/invoker/src/main/scala/whisk/core/containerpool/docker/DockerClient.scala b/core/invoker/src/main/scala/whisk/core/containerpool/docker/DockerClient.scala
index ca527d953b..a663cf8d82 100644
--- a/core/invoker/src/main/scala/whisk/core/containerpool/docker/DockerClient.scala
+++ b/core/invoker/src/main/scala/whisk/core/containerpool/docker/DockerClient.scala
@@ -31,7 +31,7 @@ import scala.concurrent.Future
import scala.util.Failure
import scala.util.Success
import scala.util.Try
-import akka.event.Logging.ErrorLevel
+import akka.event.Logging.{ErrorLevel, InfoLevel}
import pureconfig.loadConfigOrThrow
import whisk.common.Logging
import whisk.common.LoggingMarkers
@@ -180,7 +180,8 @@ class DockerClient(dockerHost: Option[String] = None,
val start = transid.started(
this,
LoggingMarkers.INVOKER_DOCKER_CMD(args.head),
- s"running ${cmd.mkString(" ")} (timeout: $timeout)")
+ s"running ${cmd.mkString(" ")} (timeout: $timeout)",
+ logLevel = InfoLevel)
executeProcess(cmd, timeout).andThen {
case Success(_) => transid.finished(this, start)
case Failure(t) => transid.failed(this, start, t.getMessage, ErrorLevel)
diff --git a/core/invoker/src/main/scala/whisk/core/containerpool/docker/RuncClient.scala b/core/invoker/src/main/scala/whisk/core/containerpool/docker/RuncClient.scala
index 9f95ec3a8e..a44a8aa904 100644
--- a/core/invoker/src/main/scala/whisk/core/containerpool/docker/RuncClient.scala
+++ b/core/invoker/src/main/scala/whisk/core/containerpool/docker/RuncClient.scala
@@ -28,8 +28,8 @@ import scala.util.Success
import whisk.common.LoggingMarkers
import whisk.common.Logging
import whisk.core.ConfigKeys
-import akka.event.Logging.ErrorLevel
import pureconfig.loadConfigOrThrow
+import akka.event.Logging.{ErrorLevel, InfoLevel}
import whisk.core.containerpool.ContainerId
import scala.concurrent.duration.Duration
@@ -68,9 +68,10 @@ class RuncClient(timeouts: RuncClientTimeouts = loadConfigOrThrow[RuncClientTime
val start = transid.started(
this,
LoggingMarkers.INVOKER_RUNC_CMD(args.head),
- s"running ${cmd.mkString(" ")} (timeout: $timeout)")
+ s"running ${cmd.mkString(" ")} (timeout: $timeout)",
+ logLevel = InfoLevel)
executeProcess(cmd, timeout).andThen {
- case Success(_) => transid.finished(this, start)
+ case Success(_) => transid.finished(this, start, logLevel = InfoLevel)
case Failure(t) => transid.failed(this, start, t.getMessage, ErrorLevel)
}
}
diff --git a/core/invoker/src/main/scala/whisk/core/invoker/InvokerReactive.scala b/core/invoker/src/main/scala/whisk/core/invoker/InvokerReactive.scala
index 4efda9d17f..0c9cdb4504 100644
--- a/core/invoker/src/main/scala/whisk/core/invoker/InvokerReactive.scala
+++ b/core/invoker/src/main/scala/whisk/core/invoker/InvokerReactive.scala
@@ -49,6 +49,7 @@ import whisk.core.entity._
import whisk.core.entity.size._
import whisk.http.Messages
import whisk.spi.SpiLoader
+import akka.event.Logging.InfoLevel
class InvokerReactive(config: WhiskConfig, instance: InstanceId, producer: MessageProducer)(
implicit actorSystem: ActorSystem,
@@ -129,9 +130,9 @@ class InvokerReactive(config: WhiskConfig, instance: InstanceId, producer: Messa
/** Stores an activation in the database. */
val store = (tid: TransactionId, activation: WhiskActivation) => {
implicit val transid = tid
- logging.info(this, "recording the activation result to the data store")
+ logging.debug(this, "recording the activation result to the data store")
WhiskActivation.put(activationStore, activation)(tid, notifier = None).andThen {
- case Success(id) => logging.info(this, s"recorded activation")
+ case Success(id) => logging.debug(this, s"recorded activation")
case Failure(t) => logging.error(this, s"failed to record activation")
}
}
@@ -164,13 +165,13 @@ class InvokerReactive(config: WhiskConfig, instance: InstanceId, producer: Messa
.flatMap { msg =>
implicit val transid = msg.transid
- val start = transid.started(this, LoggingMarkers.INVOKER_ACTIVATION)
+ val start = transid.started(this, LoggingMarkers.INVOKER_ACTIVATION, logLevel = InfoLevel)
val namespace = msg.action.path
val name = msg.action.name
val actionid = FullyQualifiedEntityName(namespace, name).toDocId.asDocInfo(msg.revision)
val subject = msg.user.subject
- logging.info(this, s"${actionid.id} $subject ${msg.activationId}")
+ logging.debug(this, s"${actionid.id} $subject ${msg.activationId}")
// caching is enabled since actions have revision id and an updated
// action will not hit in the cache due to change in the revision id;
diff --git a/common/scala/src/main/scala/whisk/common/SimpleExec.scala b/tests/src/test/scala/common/SimpleExec.scala
similarity index 89%
rename from common/scala/src/main/scala/whisk/common/SimpleExec.scala
rename to tests/src/test/scala/common/SimpleExec.scala
index abe520c4f3..34f9e9adcc 100644
--- a/common/scala/src/main/scala/whisk/common/SimpleExec.scala
+++ b/tests/src/test/scala/common/SimpleExec.scala
@@ -15,10 +15,11 @@
* limitations under the License.
*/
-package whisk.common
+package common
-import scala.sys.process.ProcessLogger
-import scala.sys.process.stringSeqToProcess
+import whisk.common.{Logging, TransactionId}
+
+import scala.sys.process.{stringSeqToProcess, ProcessLogger}
/**
* Utility to exec processes
@@ -46,7 +47,7 @@ object SimpleExec {
errs.append("\n")
})
- logging.info(this, s"Done running command: ${cmd.mkString(" ")}")
+ logging.debug(this, s"Done running command: ${cmd.mkString(" ")}")
def noLastNewLine(sb: StringBuilder) = {
if (sb.isEmpty) "" else sb.substring(0, sb.size - 1)
diff --git a/tests/src/test/scala/whisk/core/cli/test/WskWebActionsTests.scala b/tests/src/test/scala/whisk/core/cli/test/WskWebActionsTests.scala
index 6009f1578d..b003e8d422 100644
--- a/tests/src/test/scala/whisk/core/cli/test/WskWebActionsTests.scala
+++ b/tests/src/test/scala/whisk/core/cli/test/WskWebActionsTests.scala
@@ -22,25 +22,22 @@ import java.util.Base64
import scala.util.Failure
import scala.util.Try
-
import org.junit.runner.RunWith
import org.scalatest.BeforeAndAfterAll
import org.scalatest.junit.JUnitRunner
-
import com.jayway.restassured.RestAssured
import com.jayway.restassured.response.Header
-
import common.TestHelpers
import common.TestUtils
import common.WhiskProperties
import common.BaseWsk
import common.WskProps
import common.WskTestHelpers
+import common.SimpleExec
import spray.json._
import spray.json.DefaultJsonProtocol._
import system.rest.RestUtil
import whisk.common.PrintStreamLogging
-import whisk.common.SimpleExec
import whisk.common.TransactionId
import whisk.core.entity.Subject
diff --git a/tests/src/test/scala/whisk/core/controller/test/ControllerTestCommon.scala b/tests/src/test/scala/whisk/core/controller/test/ControllerTestCommon.scala
index 7344ba7849..ffedc81d80 100644
--- a/tests/src/test/scala/whisk/core/controller/test/ControllerTestCommon.scala
+++ b/tests/src/test/scala/whisk/core/controller/test/ControllerTestCommon.scala
@@ -96,35 +96,35 @@ protected trait ControllerTestCommon
def deleteAction(doc: DocId)(implicit transid: TransactionId) = {
Await.result(WhiskAction.get(entityStore, doc) flatMap { doc =>
- logging.info(this, s"deleting ${doc.docinfo}")
+ logging.debug(this, s"deleting ${doc.docinfo}")
WhiskAction.del(entityStore, doc.docinfo)
}, dbOpTimeout)
}
def deleteActivation(doc: DocId)(implicit transid: TransactionId) = {
Await.result(WhiskActivation.get(activationStore, doc) flatMap { doc =>
- logging.info(this, s"deleting ${doc.docinfo}")
+ logging.debug(this, s"deleting ${doc.docinfo}")
WhiskActivation.del(activationStore, doc.docinfo)
}, dbOpTimeout)
}
def deleteTrigger(doc: DocId)(implicit transid: TransactionId) = {
Await.result(WhiskTrigger.get(entityStore, doc) flatMap { doc =>
- logging.info(this, s"deleting ${doc.docinfo}")
+ logging.debug(this, s"deleting ${doc.docinfo}")
WhiskAction.del(entityStore, doc.docinfo)
}, dbOpTimeout)
}
def deleteRule(doc: DocId)(implicit transid: TransactionId) = {
Await.result(WhiskRule.get(entityStore, doc) flatMap { doc =>
- logging.info(this, s"deleting ${doc.docinfo}")
+ logging.debug(this, s"deleting ${doc.docinfo}")
WhiskRule.del(entityStore, doc.docinfo)
}, dbOpTimeout)
}
def deletePackage(doc: DocId)(implicit transid: TransactionId) = {
Await.result(WhiskPackage.get(entityStore, doc) flatMap { doc =>
- logging.info(this, s"deleting ${doc.docinfo}")
+ logging.debug(this, s"deleting ${doc.docinfo}")
WhiskPackage.del(entityStore, doc.docinfo)
}, dbOpTimeout)
}
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
With regards,
Apache Git Services