From c8f16845f29611fee93958094a88c6b1b55730df Mon Sep 17 00:00:00 2001 From: Christopher Batey Date: Tue, 27 Mar 2018 11:20:20 +0100 Subject: [PATCH] Log sent/receive message log level check #24774 --- .../src/main/scala/akka/remote/Endpoint.scala | 15 ++-- .../scala/akka/remote/artery/Codecs.scala | 3 +- .../remote/artery/MessageDispatcher.scala | 6 +- .../akka/remote/MessageLoggingSpec.scala | 72 +++++++++++++++++++ 4 files changed, 85 insertions(+), 11 deletions(-) create mode 100644 akka-remote/src/test/scala/akka/remote/MessageLoggingSpec.scala diff --git a/akka-remote/src/main/scala/akka/remote/Endpoint.scala b/akka-remote/src/main/scala/akka/remote/Endpoint.scala index 002873606c..4418256c61 100644 --- a/akka-remote/src/main/scala/akka/remote/Endpoint.scala +++ b/akka-remote/src/main/scala/akka/remote/Endpoint.scala @@ -67,19 +67,22 @@ private[remote] class DefaultMessageDispatcher( val sender: ActorRef = senderOption.getOrElse(system.deadLetters) val originalReceiver = recipient.path - def msgLog = s"RemoteMessage: [$payload] to [$recipient]<+[$originalReceiver] from [$sender()]" + def logMessageReceived(messageType: String): Unit = { + if (LogReceive && log.isDebugEnabled) + log.debug(s"received $messageType RemoteMessage: [{}] to [{}]<+[{}] from [{}]", payload, recipient, originalReceiver, sender) + } recipient match { case `remoteDaemon` ⇒ if (UntrustedMode) log.debug(LogMarker.Security, "dropping daemon message in untrusted mode") else { - if (LogReceive) log.debug("received daemon message {}", msgLog) + logMessageReceived("daemon message") remoteDaemon ! payload } case l @ (_: LocalRef | _: RepointableRef) if l.isLocal ⇒ - if (LogReceive) log.debug("received local message {}", msgLog) + logMessageReceived("local message") payload match { case sel: ActorSelectionMessage ⇒ if (UntrustedMode && (!TrustedSelectionPaths.contains(sel.elements.mkString("/", "/", "")) || @@ -99,7 +102,7 @@ private[remote] class DefaultMessageDispatcher( } case r @ (_: RemoteRef | _: RepointableRef) if !r.isLocal && !UntrustedMode ⇒ - if (LogReceive) log.debug("received remote-destined message {}", msgLog) + logMessageReceived("remote-destined message") if (provider.transport.addresses(recipientAddress)) // if it was originally addressed to us but is in fact remote from our point of view (i.e. remote-deployed) r.!(payload)(sender) @@ -778,7 +781,7 @@ private[remote] class EndpointWriter( def writeSend(s: Send): Boolean = try { handle match { case Some(h) ⇒ - if (provider.remoteSettings.LogSend) { + if (provider.remoteSettings.LogSend && log.isDebugEnabled) { def msgLog = s"RemoteMessage: [${s.message}] to [${s.recipient}]<+[${s.recipient.path}] from [${s.senderOption.getOrElse(extendedSystem.deadLetters)}]" log.debug("sending message {}", msgLog) } @@ -896,7 +899,7 @@ private[remote] class EndpointWriter( private def serializeMessage(msg: Any): SerializedMessage = handle match { case Some(h) ⇒ Serialization.currentTransportInformation.withValue(Serialization.Information(h.localAddress, extendedSystem)) { - (MessageSerializer.serialize(extendedSystem, msg.asInstanceOf[AnyRef])) + MessageSerializer.serialize(extendedSystem, msg.asInstanceOf[AnyRef]) } case None ⇒ throw new EndpointException("Internal error: No handle was present during serialization of outbound message.") diff --git a/akka-remote/src/main/scala/akka/remote/artery/Codecs.scala b/akka-remote/src/main/scala/akka/remote/artery/Codecs.scala index 5eeca91f12..ef27b3eee7 100644 --- a/akka-remote/src/main/scala/akka/remote/artery/Codecs.scala +++ b/akka-remote/src/main/scala/akka/remote/artery/Codecs.scala @@ -139,8 +139,7 @@ private[remote] class Encoder( if (debugLogSendEnabled) log.debug( "sending remote message [{}] to [{}] from [{}]", - Logging.messageClassName(outboundEnvelope.message), - outboundEnvelope.recipient.getOrElse(""), outboundEnvelope.sender.getOrElse("")) + outboundEnvelope.message, outboundEnvelope.recipient.getOrElse(""), outboundEnvelope.sender.getOrElse("")) push(out, envelope) diff --git a/akka-remote/src/main/scala/akka/remote/artery/MessageDispatcher.scala b/akka-remote/src/main/scala/akka/remote/artery/MessageDispatcher.scala index dd36382fec..2b73ebdc9e 100644 --- a/akka-remote/src/main/scala/akka/remote/artery/MessageDispatcher.scala +++ b/akka-remote/src/main/scala/akka/remote/artery/MessageDispatcher.scala @@ -54,14 +54,14 @@ private[remote] class MessageDispatcher( } else { if (LogReceive && debugLogEnabled) log.debug( "received daemon message [{}] from [{}]", - messageClassName(message), senderOption.getOrElse(originAddress.getOrElse(""))) + message, senderOption.getOrElse(originAddress.getOrElse(""))) remoteDaemon ! message } case l @ (_: LocalRef | _: RepointableRef) if l.isLocal ⇒ if (LogReceive && debugLogEnabled) log.debug( "received message [{}] to [{}] from [{}]", - messageClassName(message), recipient, senderOption.getOrElse("")) + message, recipient, senderOption.getOrElse("")) message match { case sel: ActorSelectionMessage ⇒ if (UntrustedMode && (!TrustedSelectionPaths.contains(sel.elements.mkString("/", "/", "")) || @@ -86,7 +86,7 @@ private[remote] class MessageDispatcher( case r @ (_: RemoteRef | _: RepointableRef) if !r.isLocal && !UntrustedMode ⇒ if (LogReceive && debugLogEnabled) log.debug( "received remote-destined message [{}] to [{}] from [{}]", - messageClassName(message), recipient, senderOption.getOrElse(originAddress.getOrElse(""))) + message, recipient, senderOption.getOrElse(originAddress.getOrElse(""))) // if it was originally addressed to us but is in fact remote from our point of view (i.e. remote-deployed) r.!(message)(sender) diff --git a/akka-remote/src/test/scala/akka/remote/MessageLoggingSpec.scala b/akka-remote/src/test/scala/akka/remote/MessageLoggingSpec.scala new file mode 100644 index 0000000000..14a4cde03f --- /dev/null +++ b/akka-remote/src/test/scala/akka/remote/MessageLoggingSpec.scala @@ -0,0 +1,72 @@ +/* + * Copyright (C) 2018 Lightbend Inc. + */ + +package akka.remote + +import akka.actor.{ Actor, ActorIdentity, ActorSystem, ExtendedActorSystem, Identify, Props, RootActorPath } +import akka.testkit.{ AkkaSpec, ImplicitSender, TestKit } +import com.typesafe.config.{ Config, ConfigFactory } +import MessageLoggingSpec._ + +object MessageLoggingSpec { + def config(artery: Boolean) = ConfigFactory.parseString( + s""" + akka.loglevel = info // debug makes this test fail intentionally + akka.actor.provider = remote + akka.remote { + log-received-messages = on + log-sent-messages = on + + netty.tcp { + hostname = localhost + port = 0 + } + + artery { + enabled = $artery + transport = aeron-udp + canonical.hostname = localhost + canonical.port = 0 + log-received-messages = on + log-sent-messages = on + } + } + """.stripMargin) + + case class BadMsg(msg: String) { + override def toString = throw new RuntimeException("Don't log me") + + } + + class BadActor extends Actor { + override def receive = { + case _ ⇒ + sender() ! BadMsg("hah") + } + } +} + +class ArteryMessageLoggingSpec extends MessageLoggingSpec(config(true)) +class ClassicMessageLoggingSpec extends MessageLoggingSpec(config(false)) + +abstract class MessageLoggingSpec(config: Config) extends AkkaSpec(config) with ImplicitSender { + + val remoteSystem = ActorSystem("remote-sys", config) + val remoteAddress = remoteSystem.asInstanceOf[ExtendedActorSystem].provider.getDefaultAddress + "Message logging" must { + "not be on if debug logging not enabled" in { + remoteSystem.actorOf(Props[BadActor], "bad") + val as = system.actorSelection(RootActorPath(remoteAddress) / "user" / "bad") + as ! Identify("bad") + val ref = expectMsgType[ActorIdentity].ref.get + ref ! "hello" + expectMsgType[BadMsg] + } + } + + override protected def afterTermination(): Unit = { + TestKit.shutdownActorSystem(remoteSystem) + } +} +