diff --git a/http-verbs-common/src/main/scala/uk/gov/hmrc/http/Retries.scala b/http-verbs-common/src/main/scala/uk/gov/hmrc/http/Retries.scala index ac40ad37..40ae2e17 100644 --- a/http-verbs-common/src/main/scala/uk/gov/hmrc/http/Retries.scala +++ b/http-verbs-common/src/main/scala/uk/gov/hmrc/http/Retries.scala @@ -36,16 +36,21 @@ trait Retries { private val logger = LoggerFactory.getLogger("application") def retry[A](verb: String, url: String)(block: => Future[A])(implicit ec: ExecutionContext): Future[A] = { - def loop(remainingIntervals: Seq[FiniteDuration])(mdcData: Map[String, String])(block: => Future[A]): Future[A] = + def loop(remainingIntervals: Seq[FiniteDuration]): Future[A] = { // scheduling will loose MDC data. Here we explicitly ensure it is available on block. - Mdc.withMdc(block, mdcData) + block .recoverWith { case ex @ `sslEngineClosedMatcher`() if remainingIntervals.nonEmpty => val delay = remainingIntervals.head logger.warn(s"Retrying $verb $url in $delay due to '${ex.getMessage}' error") - after(delay, actorSystem.scheduler)(loop(remainingIntervals.tail)(mdcData)(block)) + val mdcData = Mdc.mdcData + after(delay, actorSystem.scheduler){ + Mdc.putMdc(mdcData) + loop(remainingIntervals.tail) + } } - loop(intervals)(Mdc.mdcData)(block) + } + loop(intervals) } private[http] lazy val intervals: Seq[FiniteDuration] = diff --git a/http-verbs-common/src/main/scala/uk/gov/hmrc/play/http/logging/Mdc.scala b/http-verbs-common/src/main/scala/uk/gov/hmrc/play/http/logging/Mdc.scala index 52265f25..0f08e8d4 100644 --- a/http-verbs-common/src/main/scala/uk/gov/hmrc/play/http/logging/Mdc.scala +++ b/http-verbs-common/src/main/scala/uk/gov/hmrc/play/http/logging/Mdc.scala @@ -30,17 +30,16 @@ object Mdc { block.map { a => putMdc(mdcData) a - }.recover { + }.recoverWith { case t => putMdc(mdcData) - throw t + Future.failed(t) } - private def putMdc(mdc: Map[String, String]): Unit = { + def putMdc(mdc: Map[String, String]): Unit = mdc.foreach { case (k, v) => MDC.put(k, v) } - } /** Restores MDC data to the continuation of a block, which may be discarding MDC data (e.g. uses a different execution context) */ diff --git a/http-verbs-common/src/main/scala/uk/gov/hmrc/play/http/logging/MdcLoggingExecutionContext.scala b/http-verbs-common/src/main/scala/uk/gov/hmrc/play/http/logging/MdcLoggingExecutionContext.scala index d92141e6..63c6d6fe 100644 --- a/http-verbs-common/src/main/scala/uk/gov/hmrc/play/http/logging/MdcLoggingExecutionContext.scala +++ b/http-verbs-common/src/main/scala/uk/gov/hmrc/play/http/logging/MdcLoggingExecutionContext.scala @@ -20,6 +20,7 @@ import org.slf4j.MDC import scala.concurrent.ExecutionContext +@deprecated("MdcLoggingExecutionContext no longer required, please inject Play's default EC instead", "15.6.0") class MdcLoggingExecutionContext(wrapped: ExecutionContext, mdcData: Map[String, String]) extends ExecutionContext { diff --git a/http-verbs-common/src/test/scala/uk/gov/hmrc/http/RetriesSpec.scala b/http-verbs-common/src/test/scala/uk/gov/hmrc/http/RetriesSpec.scala index f908a68d..a6e9bc5c 100644 --- a/http-verbs-common/src/test/scala/uk/gov/hmrc/http/RetriesSpec.scala +++ b/http-verbs-common/src/test/scala/uk/gov/hmrc/http/RetriesSpec.scala @@ -17,6 +17,7 @@ package uk.gov.hmrc.http import java.time.Instant +import java.util.concurrent.Executors import akka.actor.ActorSystem import com.typesafe.config.{Config, ConfigFactory} @@ -29,6 +30,7 @@ import org.slf4j.MDC import play.api.libs.json.{JsValue, Json, Writes} import uk.gov.hmrc.http.HttpReads.Implicits._ import uk.gov.hmrc.http.hooks.{HttpHook, HttpHooks} +import uk.gov.hmrc.play.http.logging.Mdc import scala.collection.JavaConverters._ import scala.concurrent.duration._ @@ -181,26 +183,28 @@ class RetriesSpec extends AnyWordSpecLike with Matchers with MockitoSugar with S } val mdcData = Map("key1" -> "value1") - mdcData.foreach { case (k, v) => MDC.put("key1", "value1") } - val mdcEc = new uk.gov.hmrc.play.http.logging.MdcLoggingExecutionContext(implicitly[ExecutionContext], mdcData) + + implicit val mdcEc = ExecutionContext.fromExecutor(new uk.gov.hmrc.play.http.logging.MDCPropagatingExecutorService(Executors.newFixedThreadPool(2))) val expectedResponse = HttpResponse(404, "") val resultF = - retries.retry("GET", "url") { - // assert mdc available to block execution - Option(MDC.getCopyOfContextMap).map(_.asScala.toMap).getOrElse(Map.empty) shouldBe mdcData - - retries.failFewTimesAndThenSucceed( - success = Future.successful(expectedResponse), - exception = new SSLException("SSLEngine closed already") - ) - }(mdcEc) - .map { res => + for { + _ <- Future.successful(Mdc.putMdc(mdcData)) + res <- retries.retry("GET", "url") { + // assert mdc available to block execution + Option(MDC.getCopyOfContextMap).map(_.asScala.toMap).getOrElse(Map.empty) shouldBe mdcData + + retries.failFewTimesAndThenSucceed( + success = Future.successful(expectedResponse), + exception = new SSLException("SSLEngine closed already") + ) + } + } yield { // assert mdc available to continuation Option(MDC.getCopyOfContextMap).map(_.asScala.toMap).getOrElse(Map.empty) shouldBe mdcData res - }(mdcEc) + } whenReady(resultF) { response => response shouldBe expectedResponse @@ -372,14 +376,15 @@ class RetriesSpec extends AnyWordSpecLike with Matchers with MockitoSugar with S trait SucceedNthCall { var failureCounter: Int = 0 - val maxFailures: Int = Random.nextInt(3) - def failFewTimesAndThenSucceed[A, B](success: Future[A], exception: Exception): Future[A] = + val maxFailures: Int = 1 + Random.nextInt(2) + def failFewTimesAndThenSucceed[A, B](success: Future[A], exception: Exception): Future[A] = { + println(s"failFewTimesAndThenSucceed = $failureCounter, $maxFailures") if (failureCounter < maxFailures) { failureCounter += 1 Future.failed(exception) - } else { + } else success - } + } } trait TestHttpPost extends HttpPost { diff --git a/http-verbs-common/src/test/scala/uk/gov/hmrc/play/http/logging/MdcLoggingExecutionContextSpec.scala b/http-verbs-common/src/test/scala/uk/gov/hmrc/play/http/logging/MdcLoggingExecutionContextSpec.scala index c89106ab..e5d5f6e7 100644 --- a/http-verbs-common/src/test/scala/uk/gov/hmrc/play/http/logging/MdcLoggingExecutionContextSpec.scala +++ b/http-verbs-common/src/test/scala/uk/gov/hmrc/play/http/logging/MdcLoggingExecutionContextSpec.scala @@ -18,6 +18,7 @@ package uk.gov.hmrc.play.http.logging import java.util.concurrent.{CountDownLatch, Executors} +import com.github.ghik.silencer.silent import ch.qos.logback.classic.spi.ILoggingEvent import ch.qos.logback.classic.{Level, Logger => LogbackLogger} import ch.qos.logback.core.AppenderBase @@ -33,6 +34,7 @@ import scala.concurrent.duration._ import scala.concurrent.{Await, ExecutionContext, Future} import scala.reflect._ +@silent("deprecated") class MdcLoggingExecutionContextSpec extends AnyWordSpecLike with Matchers diff --git a/http-verbs-common/src/test/scala/uk/gov/hmrc/http/logging/MdcSpec.scala b/http-verbs-common/src/test/scala/uk/gov/hmrc/play/http/logging/MdcSpec.scala similarity index 81% rename from http-verbs-common/src/test/scala/uk/gov/hmrc/http/logging/MdcSpec.scala rename to http-verbs-common/src/test/scala/uk/gov/hmrc/play/http/logging/MdcSpec.scala index e178ba44..993643d1 100644 --- a/http-verbs-common/src/test/scala/uk/gov/hmrc/http/logging/MdcSpec.scala +++ b/http-verbs-common/src/test/scala/uk/gov/hmrc/play/http/logging/MdcSpec.scala @@ -14,22 +14,24 @@ * limitations under the License. */ -package uk.gov.hmrc.http.logging +package uk.gov.hmrc.play.http.logging import akka.dispatch.ExecutorServiceDelegate import org.scalatest.BeforeAndAfter -import org.scalatest.concurrent.{IntegrationPatience, ScalaFutures} +import org.scalatest.concurrent.ScalaFutures import org.scalatest.matchers.should.Matchers import org.scalatest.wordspec.AnyWordSpecLike -import org.scalatestplus.mockito.MockitoSugar import org.slf4j.MDC -import uk.gov.hmrc.play.http.logging.Mdc import java.util.concurrent.{ExecutorService, Executors} import scala.concurrent.duration.DurationInt import scala.concurrent.{ExecutionContext, Future} -class MdcSpec extends AnyWordSpecLike with Matchers with MockitoSugar with ScalaFutures with BeforeAndAfter with IntegrationPatience { +class MdcSpec + extends AnyWordSpecLike + with Matchers + with ScalaFutures + with BeforeAndAfter { before { MDC.clear() @@ -58,9 +60,9 @@ class MdcSpec extends AnyWordSpecLike with Matchers with MockitoSugar with Scala implicit val mdcEc: ExecutionContext = mdcPropagatingExecutionContext() (for { - _ <- Future.successful(org.slf4j.MDC.put("k", "v")) - _ <- Mdc.preservingMdc(runActionWhichLosesMdc()) - } yield + _ <- Future.successful(org.slf4j.MDC.put("k", "v")) + _ <- Mdc.preservingMdc(runActionWhichLosesMdc()) + } yield Option(MDC.get("k")) ).futureValue shouldBe Some("v") } @@ -72,16 +74,15 @@ class MdcSpec extends AnyWordSpecLike with Matchers with MockitoSugar with Scala _ <- Future.successful(org.slf4j.MDC.put("k", "v")) _ <- Mdc.preservingMdc(runActionWhichLosesMdc(fail = true)) } yield () - ) - .recover { case _ => + ).recover { case _ => Option(MDC.get("k")) }.futureValue shouldBe Some("v") } } private def runActionWhichLosesMdc(fail: Boolean = false): Future[Any] = { - val as = akka.actor.ActorSystem("different-as") - akka.pattern.after(1.second, as.scheduler)(Future(())(as.dispatcher))(as.dispatcher) + val as = akka.actor.ActorSystem("as") + akka.pattern.after(10.millis, as.scheduler)(Future(())(as.dispatcher))(as.dispatcher) .map(a => if (fail) sys.error("expected test exception") else a)(as.dispatcher) } @@ -105,17 +106,16 @@ class MDCPropagatingExecutorService(val executor: ExecutorService) extends Execu try { command.run() } finally { + // this means any Mdc updates on the ec will not be propagated once it steps out setMDC(oldMdcData) } } }) } - private def setMDC(context: java.util.Map[String, String]): Unit = { - if (context == null) { + private def setMDC(context: java.util.Map[String, String]): Unit = + if (context == null) MDC.clear() - } else { + else MDC.setContextMap(context) - } - } }