Log sent/receive message log level check #24774

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.")

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)
 

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)
 

akka-remote/src/test/scala/akka/remote/MessageLoggingSpec.scala

@@ -0,0 +1,72 @@
+/*
+ * Copyright (C) 2018 Lightbend Inc. <https://www.lightbend.com>
+ */
+
+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)
+  }
+}
+