Add unit tests for ErrorCode [DPP-799] (#13236)

changelog_begin
changelog_end
This commit is contained in:
pbatko-da 2022-03-14 12:38:23 +01:00 committed by GitHub
parent a8c0984d9b
commit 92e3e9e2df
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
13 changed files with 538 additions and 201 deletions

View File

@ -135,7 +135,7 @@ We use following error details:
- A mandatory ``com.google.rpc.RequestInfo`` containing (not-truncated) correlation id
(or ``0`` if correlation id is not available).
- An optional ``com.google.rpc.RetryInfo`` containing retry interval in seconds.
- An optional ``com.google.rpc.RetryInfo`` containing retry interval with milliseconds resolution.
- An optional ``com.google.rpc.ResourceInfo`` containing information about the resource the failure is based on.
Any request that fails due to some well-defined resource issues (such as contract, contract-key, package, party, template, domain, etc..) will contain these.
@ -165,11 +165,11 @@ This example shows how a user can extract the relevant error information.
DummmyServer.serviceEndpointDummy()
} catch {
case e: StatusRuntimeException =>
// Converting to a status object.
val status = io.grpc.protobuf.StatusProto.fromThrowable(e)
// Extracting error code id.
// Extracting gRPC status code.
assert(status.getCode == io.grpc.Status.Code.ABORTED.value())
assert(status.getCode == 10)
// Extracting error message, both
@ -204,7 +204,8 @@ This example shows how a user can extract the relevant error information.
rawDetails.collectFirst {
case any if any.is(classOf[RetryInfo]) =>
val v = any.unpack(classOf[RetryInfo])
assert(v.getRetryDelay.getSeconds == 123)
assert(v.getRetryDelay.getSeconds == 123, v.getRetryDelay.getSeconds)
assert(v.getRetryDelay.getNanos == 456 * 1000 * 1000, v.getRetryDelay.getNanos)
}.isDefined
}

View File

@ -94,6 +94,7 @@ da_scala_test_suite(
":error-test-utils",
"//ledger/test-common",
"//libs-scala/contextualized-logging",
"//libs-scala/logging-entries",
"@maven//:ch_qos_logback_logback_classic",
"@maven//:ch_qos_logback_logback_core",
"@maven//:com_google_api_grpc_proto_google_common_protos",

View File

@ -5,6 +5,7 @@ package com.daml.error
import com.daml.error.ErrorCode.{ValidMetadataKeyRegex, truncateResourceForTransport}
import com.daml.error.definitions.DamlError
import com.daml.error.utils.ErrorDetails
import com.google.rpc.Status
import io.grpc.Status.Code
import io.grpc.StatusRuntimeException
@ -14,6 +15,7 @@ import org.slf4j.event.Level
import scala.annotation.StaticAnnotation
import scala.util.control.NoStackTrace
import scala.util.matching.Regex
import scala.jdk.CollectionConverters._
/** Error Code Definition
*
@ -50,91 +52,72 @@ abstract class ErrorCode(val id: String, val category: ErrorCategory)(implicit
implicit val code: ErrorCode = this
/** The error code string, uniquely identifiable by the error id, error category and correlation id.
/** The machine readable error code string, uniquely identifiable by the error id, error category and correlation id.
* e.g. NO_DOMAINS_CONNECTED(2,ABC234)
*/
def codeStr(correlationId: Option[String]): String =
s"$id(${category.asInt},${correlationId.getOrElse("0").take(8)})"
/** Render the cause including codestring and error name */
/** @return message including error category id, error code id, correlation id and cause
*/
def toMsg(cause: => String, correlationId: Option[String]): String =
s"${codeStr(correlationId)}: ${ErrorCode.truncateCause(cause)}"
def asGrpcStatus(err: BaseError)(implicit
loggingContext: ContextualizedErrorLogger
): Status = {
val ErrorCode.StatusInfo(codeGrpc, message, contextMap, correlationId) =
getStatusInfo(err)
def asGrpcStatus(err: BaseError)(implicit loggingContext: ContextualizedErrorLogger): Status = {
val statusInfo = getStatusInfo(err)(loggingContext)
// Provide error id and context via ErrorInfo
val maybeErrInfo =
if (!code.category.securitySensitive) {
val errInfoBld = com.google.rpc.ErrorInfo.newBuilder()
contextMap.foreach { case (k, v) => errInfoBld.putMetadata(k, v) }
errInfoBld.setReason(id)
val definiteAnswerKey = com.daml.ledger.grpc.GrpcStatuses.DefiniteAnswerKey
err.definiteAnswerO.foreach { definiteAnswer =>
errInfoBld.putMetadata(definiteAnswerKey, definiteAnswer.toString)
}
Some(com.google.protobuf.Any.pack(errInfoBld.build()))
} else None
val errorInfo =
if (code.category.securitySensitive) {
None
} else {
val errorInfo = ErrorDetails.ErrorInfoDetail(
errorCodeId = id,
metadata = statusInfo.contextMap ++
err.definiteAnswerO.fold(Map.empty[String, String])(value =>
Map(com.daml.ledger.grpc.GrpcStatuses.DefiniteAnswerKey -> value.toString)
),
)
Some(errorInfo)
}
// Build retry info
val retryInfo = err.retryable.map { ri =>
val millis = ri.duration.toMillis % 1000
val seconds = (ri.duration.toMillis - millis) / 1000
val dt = com.google.protobuf.Duration
.newBuilder()
.setNanos(millis.toInt * 1000000)
.setSeconds(seconds)
.build()
com.google.protobuf.Any.pack(
com.google.rpc.RetryInfo
.newBuilder()
.setRetryDelay(dt)
.build()
val retryInfo = err.retryable.map(r =>
ErrorDetails.RetryInfoDetail(
duration = r.duration
)
)
// Build request info
val requestInfo = statusInfo.correlationId.map { correlationId =>
ErrorDetails.RequestInfoDetail(
correlationId = correlationId
)
}
// Build request info based on correlation id
val requestInfo = correlationId.map { ci =>
com.google.protobuf.Any.pack(com.google.rpc.RequestInfo.newBuilder().setRequestId(ci).build())
}
// Build (truncated) resource infos
val resourceInfo =
// Build resource infos
val resourceInfos =
if (code.category.securitySensitive) Seq()
else
truncateResourceForTransport(err.resources).map { case (rs, item) =>
com.google.protobuf.Any
.pack(
com.google.rpc.ResourceInfo
.newBuilder()
.setResourceType(rs.asString)
.setResourceName(item)
.build()
truncateResourceForTransport(err.resources)
.map { case (resourceType, resourceValue) =>
ErrorDetails.ResourceInfoDetail(
typ = resourceType.asString,
name = resourceValue,
)
}
}
val allDetails: Seq[ErrorDetails.ErrorDetail] =
errorInfo.toList ++ retryInfo.toList ++ requestInfo.toList ++ resourceInfos
// Build status
val statusBuilder = com.google.rpc.Status
val status = com.google.rpc.Status
.newBuilder()
.setCode(codeGrpc.value())
.setMessage(message)
(maybeErrInfo.toList ++ retryInfo.toList ++ requestInfo.toList ++ resourceInfo)
.foldLeft(statusBuilder) { case (acc, item) =>
acc.addDetails(item)
}
statusBuilder.build()
.setCode(statusInfo.grpcStatusCode.value())
.setMessage(statusInfo.message)
.addAllDetails(allDetails.map(_.toRpcAny).asJava)
.build()
status
}
def asGrpcError(err: BaseError)(implicit
loggingContext: ContextualizedErrorLogger
): StatusRuntimeException = {
val status = asGrpcStatus(err)
val status = asGrpcStatus(err)(loggingContext)
// Builder methods for metadata are not exposed, so going route via creating an exception
val e = StatusProto.toStatusRuntimeException(status)
// Stripping stacktrace
@ -145,10 +128,10 @@ abstract class ErrorCode(val id: String, val category: ErrorCategory)(implicit
}
}
/** log level of the error code
/** Log level of the error code
*
* Generally, the log level is defined by the error category. In rare cases, it might be overridden
* by the error code.
* Generally, the log level is defined by the error category.
* In rare cases, it might be overridden by the error code.
*/
def logLevel: Level = category.logLevel
@ -164,21 +147,26 @@ abstract class ErrorCode(val id: String, val category: ErrorCategory)(implicit
s"${BaseError.SecuritySensitiveMessageOnApiPrefix} ${correlationId.getOrElse("<no-correlation-id>")}"
else
code.toMsg(err.cause, loggingContext.correlationId)
val codeGrpc = category.grpcCode
val grpcStatusCode = category.grpcCode
.getOrElse {
loggingContext.warn(s"Passing non-grpc error via grpc $id ")
Code.INTERNAL
}
val contextMap = getTruncatedContext(err) + ("category" -> category.asInt.toString)
ErrorCode.StatusInfo(codeGrpc, message, contextMap, correlationId)
ErrorCode.StatusInfo(
grpcStatusCode = grpcStatusCode,
message = message,
contextMap = contextMap,
correlationId = correlationId,
)
}
private[error] def getTruncatedContext(
err: BaseError
private def getTruncatedContext(
error: BaseError
)(implicit loggingContext: ContextualizedErrorLogger): Map[String, String] = {
val raw =
(err.context ++ loggingContext.properties).toSeq.filter(_._2.nonEmpty).sortBy(_._2.length)
val raw: Seq[(String, String)] =
(error.context ++ loggingContext.properties).toSeq.filter(_._2.nonEmpty).sortBy(_._2.length)
val maxPerEntry = ErrorCode.MaxContentBytes / Math.max(1, raw.size)
// truncate smart, starting with the smallest value strings such that likely only truncate the largest args
raw
@ -193,7 +181,7 @@ abstract class ErrorCode(val id: String, val category: ErrorCategory)(implicit
} else {
// keep track of "free space" such that we can keep larger values around
val newFree = free + maxPerEntry - adjustedKey.length - truncatedValue.length
(map + (k -> truncatedValue), newFree)
(map + (adjustedKey -> truncatedValue), newFree)
}
}
._1
@ -216,7 +204,7 @@ abstract class ErrorCode(val id: String, val category: ErrorCategory)(implicit
object ErrorCode {
private val ValidMetadataKeyRegex: Regex = "[^(a-zA-Z0-9-_)]".r
private val MaxContentBytes = 2000
private[error] val MaxContentBytes = 2000
private[error] val MaxCauseLogLength = 512
class ApiException(status: io.grpc.Status, metadata: io.grpc.Metadata)
@ -229,7 +217,7 @@ object ErrorCode {
extends ApiException(status, metadata)
case class StatusInfo(
codeGrpc: io.grpc.Status.Code,
grpcStatusCode: io.grpc.Status.Code,
message: String,
contextMap: Map[String, String],
correlationId: Option[String],

View File

@ -2,6 +2,7 @@
// SPDX-License-Identifier: Apache-2.0
package com.daml.error.samples
import scala.concurrent.duration._
import com.daml.error.definitions.{DamlError}
@ -17,8 +18,6 @@ object DummmyServer {
}
import com.daml.logging.{ContextualizedLogger, LoggingContext}
import scala.concurrent.duration.Duration
object ErrorCodeFoo
extends ErrorCode(id = "MY_ERROR_CODE_ID", ErrorCategory.ContentionOnSharedResources)(
ErrorClass.root()
@ -37,7 +36,7 @@ object DummmyServer {
)
override def retryable: Option[ErrorCategoryRetry] = Some(
ErrorCategoryRetry("me", Duration("123 s"))
ErrorCategoryRetry("me", 123.second + 456.milliseconds)
)
override def context: Map[String, String] = Map("foo" -> "bar")
@ -71,7 +70,8 @@ object SampleClientSide {
// Converting to a status object.
val status = io.grpc.protobuf.StatusProto.fromThrowable(e)
// Extracting error code id.
// Extracting gRPC status code.
assert(status.getCode == io.grpc.Status.Code.ABORTED.value())
assert(status.getCode == 10)
// Extracting error message, both
@ -106,7 +106,8 @@ object SampleClientSide {
rawDetails.collectFirst {
case any if any.is(classOf[RetryInfo]) =>
val v = any.unpack(classOf[RetryInfo])
assert(v.getRetryDelay.getSeconds == 123)
assert(v.getRetryDelay.getSeconds == 123, v.getRetryDelay.getSeconds)
assert(v.getRetryDelay.getNanos == 456 * 1000 * 1000, v.getRetryDelay.getNanos)
}.isDefined
}

View File

@ -14,35 +14,83 @@ import scala.concurrent.duration._
object ErrorDetails {
sealed trait ErrorDetail extends Product with Serializable
sealed trait ErrorDetail extends Product with Serializable {
type T <: com.google.protobuf.Message
def toRpc: T
def toRpcAny: com.google.protobuf.Any = com.google.protobuf.Any.pack(toRpc)
}
final case class ResourceInfoDetail(name: String, typ: String) extends ErrorDetail
final case class ResourceInfoDetail(name: String, typ: String) extends ErrorDetail {
type T = ResourceInfo
def toRpc: ResourceInfo = {
ResourceInfo.newBuilder().setResourceType(typ).setResourceName(name).build()
}
}
final case class ErrorInfoDetail(errorCodeId: String, metadata: Map[String, String])
extends ErrorDetail
final case class RetryInfoDetail(duration: Duration) extends ErrorDetail
final case class RequestInfoDetail(requestId: String) extends ErrorDetail
extends ErrorDetail {
type T = ErrorInfo
def toRpc: ErrorInfo = {
ErrorInfo
.newBuilder()
.setReason(errorCodeId)
.putAllMetadata(metadata.asJava)
.build()
}
}
final case class RetryInfoDetail(duration: Duration) extends ErrorDetail {
type T = RetryInfo
def toRpc: RetryInfo = {
val millis = duration.toMillis
val fullSeconds = millis / 1000
val remainderMillis = millis % 1000
// Ensuring that we do not exceed max allowed value of nanos as documented in [[com.google.protobuf.Duration.Builder.setNanos]]
val remainderNanos = Math.min(remainderMillis * 1000 * 1000, 999999999).toInt
val protoDuration = com.google.protobuf.Duration
.newBuilder()
.setNanos(remainderNanos)
.setSeconds(fullSeconds)
.build()
RetryInfo
.newBuilder()
.setRetryDelay(protoDuration)
.build()
}
}
final case class RequestInfoDetail(correlationId: String) extends ErrorDetail {
type T = RequestInfo
def toRpc: RequestInfo = {
RequestInfo
.newBuilder()
.setRequestId(correlationId)
.setServingData("")
.build()
}
}
def from(status: com.google.rpc.Status): Seq[ErrorDetail] = {
from(status.getDetailsList.asScala.toSeq)
}
def from(e: StatusRuntimeException): Seq[ErrorDetail] =
from(StatusProto.fromThrowable(e).getDetailsList.asScala.toSeq)
from(StatusProto.fromThrowable(e))
def from(anys: Seq[protobuf.Any]): Seq[ErrorDetail] = anys.toList.map {
case any if any.is(classOf[ResourceInfo]) =>
val v = any.unpack(classOf[ResourceInfo])
ResourceInfoDetail(v.getResourceType, v.getResourceName)
ResourceInfoDetail(typ = v.getResourceType, name = v.getResourceName)
case any if any.is(classOf[ErrorInfo]) =>
val v = any.unpack(classOf[ErrorInfo])
ErrorInfoDetail(v.getReason, v.getMetadataMap.asScala.toMap)
ErrorInfoDetail(errorCodeId = v.getReason, metadata = v.getMetadataMap.asScala.toMap)
case any if any.is(classOf[RetryInfo]) =>
val v = any.unpack(classOf[RetryInfo])
val delay = v.getRetryDelay
val duration = (delay.getSeconds.seconds + delay.getNanos.nanos).toCoarsest
RetryInfoDetail(duration)
RetryInfoDetail(duration = duration)
case any if any.is(classOf[RequestInfo]) =>
val v = any.unpack(classOf[RequestInfo])
RequestInfoDetail(v.getRequestId)
RequestInfoDetail(correlationId = v.getRequestId)
case any => throw new IllegalStateException(s"Could not unpack value of: |$any|")
}

View File

@ -12,14 +12,14 @@ import com.daml.scalautil.Statement
import io.grpc.Status.Code
import io.grpc.StatusRuntimeException
import io.grpc.protobuf.StatusProto
import org.scalatest.{Assertion, OptionValues}
import org.scalatest.{AppendedClues, Assertion, OptionValues}
import org.scalatest.matchers.should.Matchers
import scala.jdk.CollectionConverters._
import scala.reflect.ClassTag
import org.scalatest.Checkpoints.Checkpoint
trait ErrorsAssertions extends Matchers with OptionValues {
trait ErrorsAssertions extends Matchers with OptionValues with AppendedClues {
private val logger = ContextualizedLogger.get(getClass)
private val loggingContext = LoggingContext.ForTesting
@ -46,6 +46,28 @@ trait ErrorsAssertions extends Matchers with OptionValues {
succeed
}
def assertStatus(
actual: com.google.rpc.Status,
expected: com.google.rpc.Status,
): Assertion = {
val actualDetails = ErrorDetails.from(actual)
val expectedDetails = ErrorDetails.from(expected)
val actualDescription = Option(actual.getMessage)
val expectedDescription = Option(expected.getMessage)
val actualStatusCode = actual.getCode
val expectedStatusCode = expected.getCode
val cp = new Checkpoint
cp { Statement.discard { actualDescription shouldBe expectedDescription } }
cp {
Statement.discard {
actualStatusCode shouldBe expectedStatusCode withClue (s", expecting status code: '${expectedStatusCode}''")
}
}
cp { Statement.discard { actualDetails should contain theSameElementsAs expectedDetails } }
cp.reportAll()
succeed
}
def assertError(
actual: StatusRuntimeException,
expectedF: ContextualizedErrorLogger => StatusRuntimeException,
@ -66,7 +88,7 @@ trait ErrorsAssertions extends Matchers with OptionValues {
val expectedDetails = expectedStatus.getDetailsList.asScala.toSeq
assertError(
actual = actual,
expectedCode = expected.getStatus.getCode,
expectedStatusCode = expected.getStatus.getCode,
expectedMessage = expectedStatus.getMessage,
expectedDetails = ErrorDetails.from(expectedDetails),
)
@ -74,14 +96,14 @@ trait ErrorsAssertions extends Matchers with OptionValues {
def assertError(
actual: StatusRuntimeException,
expectedCode: Code,
expectedStatusCode: Code,
expectedMessage: String,
expectedDetails: Seq[ErrorDetails.ErrorDetail],
): Unit = {
val actualStatus = StatusProto.fromThrowable(actual)
val actualDetails = actualStatus.getDetailsList.asScala.toSeq
val cp = new Checkpoint
cp { Statement.discard { actual.getStatus.getCode shouldBe expectedCode } }
cp { Statement.discard { actual.getStatus.getCode shouldBe expectedStatusCode } }
cp { Statement.discard { actualStatus.getMessage shouldBe expectedMessage } }
cp {
Statement.discard {
@ -110,7 +132,7 @@ trait ErrorAssertionsWithLogCollectorAssertions
): Unit = {
assertError(
actual = actual,
expectedCode = expectedCode,
expectedStatusCode = expectedCode,
expectedMessage = expectedMessage,
expectedDetails = expectedDetails,
)

View File

@ -4,19 +4,21 @@
package com.daml.error
import ch.qos.logback.classic.Level
import com.daml.error.ErrorCategory.TransientServerFailure
import com.daml.error.utils.ErrorDetails
import com.daml.error.utils.testpackage.SeriousError
import com.daml.error.utils.testpackage.subpackage.MildErrorsParent.MildErrors.NotSoSeriousError
import com.daml.platform.testing.LogCollector.ExpectedLogEntry
import com.daml.logging.LoggingContext
import com.daml.platform.testing.{LogCollector, LogCollectorAssertions}
import io.grpc.StatusRuntimeException
import com.google.rpc.Status
import io.grpc.Status.Code
import org.scalatest.BeforeAndAfter
import org.scalatest.flatspec.AnyFlatSpec
import org.scalatest.freespec.AnyFreeSpec
import org.scalatest.matchers.should.Matchers
import scala.concurrent.duration._
import scala.jdk.CollectionConverters._
class ErrorCodeSpec
extends AnyFlatSpec
extends AnyFreeSpec
with Matchers
with BeforeAndAfter
with LogCollectorAssertions
@ -26,116 +28,352 @@ class ErrorCodeSpec
(correlationId: Option[String]) =>
DamlContextualizedErrorLogger.forTesting(getClass, correlationId)
private val className = classOf[ErrorCode].getSimpleName
before {
LogCollector.clear[this.type]
}
s"$className.logWithContext" should "log the error message with the correct markers" in {
val error = SeriousError.Error(
"the error argument",
context = Map("extra-context-key" -> "extra-context-value"),
)
object FooErrorCodeSecuritySensitive
extends ErrorCode(
"FOO_ERROR_CODE_SECURITY_SENSITIVE",
ErrorCategory.SystemInternalAssumptionViolated,
)(ErrorClass.root())
error.logWithContext()(contextualizedErrorLoggerF(Some("1234567890")))
object FooErrorCode
extends ErrorCode("FOO_ERROR_CODE", ErrorCategory.InvalidIndependentOfSystemState)(
ErrorClass.root()
)
val actualLogs = LogCollector
.readAsEntries[this.type, this.type]
actualLogs.size shouldBe 1
assertLogEntry(
actualLogs.head,
expectedLogLevel = Level.ERROR,
expectedMsg = "BLUE_SCREEN(4,12345678): the error argument",
expectedMarkerRegex = Some(
"\\{err-context: \"\\{extra-context-key=extra-context-value, location=ErrorCodeSpec.scala:\\d+\\}\"\\}"
),
)
}
classOf[ErrorCode].getSimpleName - {
s"$className.logWithContext" should s"truncate the cause size if larger than ${ErrorCode.MaxCauseLogLength}" in {
val veryLongCause = "o" * (ErrorCode.MaxCauseLogLength * 2)
val error =
SeriousError.Error(veryLongCause, context = Map("extra-context-key" -> "extra-context-value"))
"meet test preconditions" in {
FooErrorCodeSecuritySensitive.category.securitySensitive shouldBe true
FooErrorCode.category.securitySensitive shouldBe false
FooErrorCodeSecuritySensitive.category.grpcCode shouldBe Some(Code.INTERNAL)
FooErrorCode.category.grpcCode shouldBe Some(Code.INVALID_ARGUMENT)
}
error.logWithContext()(contextualizedErrorLoggerF(None))
"create correct message" in {
FooErrorCode.toMsg(
cause = "cause123",
correlationId = Some("123correlationId"),
) shouldBe "FOO_ERROR_CODE(8,123corre): cause123"
FooErrorCode.toMsg(
cause = "cause123",
correlationId = None,
) shouldBe "FOO_ERROR_CODE(8,0): cause123"
FooErrorCode.toMsg(
cause = "x" * ErrorCode.MaxCauseLogLength * 2,
correlationId = Some("123correlationId"),
) shouldBe s"FOO_ERROR_CODE(8,123corre): ${"x" * ErrorCode.MaxCauseLogLength}..."
FooErrorCodeSecuritySensitive.toMsg(
cause = "cause123",
correlationId = Some("123correlationId"),
) shouldBe "FOO_ERROR_CODE_SECURITY_SENSITIVE(4,123corre): cause123"
}
val expectedErrorLog = "BLUE_SCREEN(4,0): " + ("o" * ErrorCode.MaxCauseLogLength + "...")
val actualLogs = LogCollector.read[this.type, this.type]
actualLogs shouldBe Seq(Level.ERROR -> expectedErrorLog)
}
"create a minimal grpc status and exception" in {
class FooErrorMinimal(override val code: ErrorCode) extends BaseError {
override val cause: String = "cause123"
}
val errorLoggerSmall = DamlContextualizedErrorLogger.forClass(
clazz = getClass,
correlationId = None,
loggingContext = LoggingContext.empty,
)
val testedErrorCode = FooErrorCode
case class TestedError() extends FooErrorMinimal(testedErrorCode)
val details = Seq(
ErrorDetails
.ErrorInfoDetail(
testedErrorCode.id,
Map("category" -> testedErrorCode.category.asInt.toString),
)
)
val expected = Status
.newBuilder()
.setMessage("FOO_ERROR_CODE(8,0): cause123")
.setCode(Code.INVALID_ARGUMENT.value())
.addAllDetails(details.map(_.toRpcAny).asJava)
.build()
val testedError = TestedError()
s"$className.asGrpcErrorFromContext" should "output a GRPC error with correct status, message and metadata" in {
val contextMetadata = Map("some key" -> "some value", "another key" -> "another value")
val error = NotSoSeriousError.Error("some error cause", contextMetadata)
val correlationId = "12345678"
assertStatus(
actual = testedErrorCode.asGrpcStatus(testedError)(errorLoggerSmall),
expected = expected,
)
assertError(
actual = testedErrorCode.asGrpcError(testedError)(errorLoggerSmall),
expectedStatusCode = testedErrorCode.category.grpcCode.get,
expectedMessage = "FOO_ERROR_CODE(8,0): cause123",
expectedDetails = details,
)
}
val actual: StatusRuntimeException =
error.asGrpcErrorFromContext(contextualizedErrorLoggerF(Some(correlationId)))
"create a big grpc status and exception" - {
class FooErrorBig(override val code: ErrorCode) extends BaseError {
override val cause: String = "cause123"
assertError(
actual,
expectedCode = NotSoSeriousError.category.grpcCode.get,
expectedMessage = "TEST_ROUTINE_FAILURE_PLEASE_IGNORE(1,12345678): Some obscure cause",
expectedDetails = Seq(
ErrorDetails.ErrorInfoDetail(
NotSoSeriousError.id,
Map("category" -> "1") ++ contextMetadata ++ Map("definite_answer" -> "true"),
override def retryable: Option[ErrorCategoryRetry] = Some(
ErrorCategoryRetry(who = "unused", duration = 123.seconds + 456.milliseconds)
)
override def resources: Seq[(ErrorResource, String)] =
super.resources ++
Seq[(ErrorResource, String)](
ErrorResource.CommandId -> "commandId1",
ErrorResource.CommandId -> "commandId2",
ErrorResource.Party -> "party1",
)
override def context: Map[String, String] =
super.context ++ Map(
"contextKey1" -> "contextValue1",
"kkk????" -> "keyWithInvalidCharacters",
)
override def definiteAnswerO: Option[Boolean] = Some(false)
}
val errorLoggerBig = DamlContextualizedErrorLogger.forClass(
clazz = getClass,
correlationId = Some("123correlationId"),
loggingContext = LoggingContext(
"loggingEntryKey" -> "loggingEntryValue"
),
ErrorDetails.RetryInfoDetail(TransientServerFailure.retryable.get.duration),
ErrorDetails.RequestInfoDetail(correlationId),
ErrorDetails.ResourceInfoDetail(error.resources.head._1.asString, error.resources.head._2),
),
)
}
)
val requestInfo = ErrorDetails.RequestInfoDetail("123correlationId")
val retryInfo = ErrorDetails.RetryInfoDetail(123.seconds + 456.milliseconds)
s"$className.asGrpcErrorFromContext" should "not propagate security sensitive information in gRPC statuses (with correlation id)" in {
val error =
SeriousError.Error("some cause", Map("some sensitive key" -> "some sensitive value"))
val correlationId = "12345678"
val contextualizedErrorLogger = contextualizedErrorLoggerF(Some(correlationId))
def getDetails(tested: ErrorCode) = Seq(
ErrorDetails
.ErrorInfoDetail(
tested.id,
Map(
"category" -> tested.category.asInt.toString,
"definite_answer" -> "false",
"loggingEntryKey" -> "'loggingEntryValue'",
"contextKey1" -> "contextValue1",
"kkk" -> "keyWithInvalidCharacters",
),
),
requestInfo,
retryInfo,
ErrorDetails.ResourceInfoDetail(name = "commandId1", typ = "COMMAND_ID"),
ErrorDetails.ResourceInfoDetail(name = "commandId2", typ = "COMMAND_ID"),
ErrorDetails.ResourceInfoDetail(name = "party1", typ = "PARTY"),
)
val actual: StatusRuntimeException = error.asGrpcErrorFromContext(contextualizedErrorLogger)
error.logWithContext(Map.empty)(contextualizedErrorLogger)
"not security sensitive" in {
val testedErrorCode = FooErrorCode
val details = getDetails(testedErrorCode)
case class TestedError() extends FooErrorBig(testedErrorCode)
assertError[this.type, this.type](
actual,
expectedCode = io.grpc.Status.Code.INTERNAL,
expectedMessage =
s"An error occurred. Please contact the operator and inquire about the request $correlationId",
expectedDetails = Seq(ErrorDetails.RequestInfoDetail(correlationId)),
expectedLogEntry = ExpectedLogEntry(
Level.ERROR,
s"BLUE_SCREEN(4,$correlationId): some cause",
Some(
"\\{err-context: \"\\{location=ErrorCodeSpec.scala:\\d+, some sensitive key=some sensitive value\\}\"\\}"
val expectedStatus = Status
.newBuilder()
.setMessage("FOO_ERROR_CODE(8,123corre): cause123")
.setCode(testedErrorCode.category.grpcCode.get.value())
.addAllDetails(details.map(_.toRpcAny).asJava)
.build()
val testedError = TestedError()
testedError.logWithContext(Map.empty)(errorLoggerBig)
assertSingleLogEntry(
actual = LogCollector.readAsEntries[this.type, this.type],
expectedLogLevel = Level.INFO,
expectedMsg = "FOO_ERROR_CODE(8,123corre): cause123",
expectedMarkerAsString =
"""{loggingEntryKey: "loggingEntryValue", err-context: "{contextKey1=contextValue1, kkk????=keyWithInvalidCharacters, location=ErrorCodeSpec.scala:<line-number>}"}""",
)
assertStatus(
actual = testedErrorCode.asGrpcStatus(testedError)(errorLoggerBig),
expected = expectedStatus,
)
assertStatus(
actual = testedError.asGrpcStatusFromContext(errorLoggerBig),
expected = expectedStatus,
)
assertError(
actual = testedErrorCode.asGrpcError(testedError)(errorLoggerBig),
expectedStatusCode = testedErrorCode.category.grpcCode.get,
expectedMessage = "FOO_ERROR_CODE(8,123corre): cause123",
expectedDetails = details,
)
assertError(
actual = testedError.asGrpcErrorFromContext(errorLoggerBig),
expectedStatusCode = testedErrorCode.category.grpcCode.get,
expectedMessage = "FOO_ERROR_CODE(8,123corre): cause123",
expectedDetails = details,
)
}
"security sensitive" in {
val testedErrorCode = FooErrorCodeSecuritySensitive
case class FooError() extends FooErrorBig(testedErrorCode)
val expectedStatus = Status
.newBuilder()
.setMessage(
"An error occurred. Please contact the operator and inquire about the request 123correlationId"
)
.setCode(testedErrorCode.category.grpcCode.get.value())
.addDetails(requestInfo.toRpcAny)
.addDetails(retryInfo.toRpcAny)
.build()
val testedError = FooError()
testedError.logWithContext(Map.empty)(errorLoggerBig)
assertSingleLogEntry(
actual = LogCollector.readAsEntries[this.type, this.type],
expectedLogLevel = Level.ERROR,
expectedMsg = "FOO_ERROR_CODE_SECURITY_SENSITIVE(4,123corre): cause123",
expectedMarkerAsString =
"""{loggingEntryKey: "loggingEntryValue", err-context: "{contextKey1=contextValue1, kkk????=keyWithInvalidCharacters, location=ErrorCodeSpec.scala:<line-number>}"}""",
)
assertStatus(
actual = testedErrorCode.asGrpcStatus(testedError)(errorLoggerBig),
expected = expectedStatus,
)
assertStatus(
actual = testedError.asGrpcStatusFromContext(errorLoggerBig),
expected = expectedStatus,
)
assertError(
actual = testedErrorCode.asGrpcError(testedError)(errorLoggerBig),
expectedStatusCode = testedErrorCode.category.grpcCode.get,
expectedMessage =
"An error occurred. Please contact the operator and inquire about the request 123correlationId",
expectedDetails = Seq(requestInfo, retryInfo),
)
assertError(
actual = testedError.asGrpcErrorFromContext(errorLoggerBig),
expectedStatusCode = testedErrorCode.category.grpcCode.get,
expectedMessage =
"An error occurred. Please contact the operator and inquire about the request 123correlationId",
expectedDetails = Seq(requestInfo, retryInfo),
)
}
}
"create a grpc status and exception for input exceeding details size limits" in {
class FooErrorBig(override val code: ErrorCode) extends BaseError {
override val cause: String = "cause123"
override def retryable: Option[ErrorCategoryRetry] = Some(
ErrorCategoryRetry(who = "unused", duration = 123.seconds + 456.milliseconds)
)
override def resources: Seq[(ErrorResource, String)] =
super.resources ++
Seq[(ErrorResource, String)](
ErrorResource.CommandId -> "commandId1",
ErrorResource.CommandId -> "commandId2",
ErrorResource.Party -> "party1",
ErrorResource.Party -> ("x" * ErrorCode.MaxContentBytes),
)
override def definiteAnswerO: Option[Boolean] = Some(false)
}
val errorLoggerOversized = DamlContextualizedErrorLogger.forClass(
clazz = getClass,
correlationId = Some("123correlationId"),
loggingContext = LoggingContext(
"loggingEntryKey" -> "loggingEntryValue",
"loggingEntryValueTooBig" -> ("x" * ErrorCode.MaxContentBytes),
("x" * ErrorCode.MaxContentBytes) -> "loggingEntryKeyTooBig",
),
),
)
}
)
val requestInfo = ErrorDetails.RequestInfoDetail("123correlationId")
val retryInfo = ErrorDetails.RetryInfoDetail(123.seconds + 456.milliseconds)
s"$className.asGrpcErrorFromContext" should "not propagate security sensitive information in gRPC statuses (without correlation id)" in {
val error =
SeriousError.Error("some cause", Map("some sensitive key" -> "some sensitive value"))
val contextualizedErrorLogger = contextualizedErrorLoggerF(None)
val testedErrorCode = FooErrorCode
case class TestedError() extends FooErrorBig(FooErrorCode)
val testedError = TestedError()
val actual: StatusRuntimeException = error.asGrpcErrorFromContext(contextualizedErrorLogger)
error.logWithContext(Map.empty)(contextualizedErrorLogger)
val expectedDetails = Seq(
ErrorDetails
.ErrorInfoDetail(
testedErrorCode.id,
Map(
"category" -> testedErrorCode.category.asInt.toString,
"definite_answer" -> "false",
"loggingEntryKey" -> "'loggingEntryValue'",
"loggingEntryValueTooBig" -> ("'" + "x" * 1854 + "..."),
("xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx") -> "'loggingEntryKeyTooBig'",
),
),
requestInfo,
retryInfo,
ErrorDetails.ResourceInfoDetail(name = "commandId1", typ = "COMMAND_ID"),
ErrorDetails.ResourceInfoDetail(name = "commandId2", typ = "COMMAND_ID"),
ErrorDetails.ResourceInfoDetail(name = "party1", typ = "PARTY"),
)
val expectedMessage = "FOO_ERROR_CODE(8,123corre): cause123"
val expectedStatus = Status
.newBuilder()
.setMessage(expectedMessage)
.setCode(testedErrorCode.category.grpcCode.get.value())
.addAllDetails(expectedDetails.map(_.toRpcAny).asJava)
.build()
assertError[this.type, this.type](
actual,
expectedCode = io.grpc.Status.Code.INTERNAL,
expectedMessage =
s"An error occurred. Please contact the operator and inquire about the request <no-correlation-id>",
expectedDetails = Seq(),
expectedLogEntry = ExpectedLogEntry(
Level.ERROR,
"BLUE_SCREEN(4,0): some cause",
Some(
"\\{err-context: \"\\{location=ErrorCodeSpec.scala:\\d+, some sensitive key=some sensitive value\\}\"\\}"
assertStatus(
actual = testedErrorCode.asGrpcStatus(testedError)(errorLoggerOversized),
expected = expectedStatus,
)
assertStatus(
actual = testedError.asGrpcStatusFromContext(errorLoggerOversized),
expected = expectedStatus,
)
assertError(
actual = testedErrorCode.asGrpcError(testedError)(errorLoggerOversized),
expectedStatusCode = testedErrorCode.category.grpcCode.get,
expectedMessage = expectedMessage,
expectedDetails = expectedDetails,
)
assertError(
actual = testedError.asGrpcErrorFromContext(errorLoggerOversized),
expectedStatusCode = testedErrorCode.category.grpcCode.get,
expectedMessage = expectedMessage,
expectedDetails = expectedDetails,
)
}
"log the error message with the correct markers" in {
val error = SeriousError.Error(
"the error argument",
context = Map("extra-context-key" -> "extra-context-value"),
)
val errorLogger = DamlContextualizedErrorLogger.forTesting(getClass, Some("1234567890"))
error.logWithContext()(errorLogger)
val actualLogs = LogCollector
.readAsEntries[this.type, this.type]
actualLogs.size shouldBe 1
assertLogEntry(
actualLogs.head,
expectedLogLevel = Level.ERROR,
expectedMsg = "BLUE_SCREEN(4,12345678): the error argument",
expectedMarkerRegex = Some(
"\\{err-context: \"\\{extra-context-key=extra-context-value, location=ErrorCodeSpec.scala:\\d+\\}\"\\}"
),
),
)
)
}
s"truncate the cause size if larger than ${ErrorCode.MaxCauseLogLength}" in {
val veryLongCause = "o" * (ErrorCode.MaxCauseLogLength * 2)
val error =
SeriousError.Error(
veryLongCause,
context = Map("extra-context-key" -> "extra-context-value"),
)
error.logWithContext()(contextualizedErrorLoggerF(None))
val expectedErrorLog = "BLUE_SCREEN(4,0): " + ("o" * ErrorCode.MaxCauseLogLength + "...")
val actualLogs = LogCollector.read[this.type, this.type]
actualLogs shouldBe Seq(Level.ERROR -> expectedErrorLog)
}
}
}

View File

@ -6,10 +6,13 @@ package com.daml.error.utils
import com.daml.error.ErrorCategory.BackgroundProcessDegradationWarning
import com.daml.error.definitions.LedgerApiErrors
import com.daml.error.{DamlContextualizedErrorLogger, ErrorClass, ErrorCode}
import com.google.protobuf
import io.grpc.{Status, StatusRuntimeException}
import org.scalatest.flatspec.AnyFlatSpec
import org.scalatest.matchers.should.Matchers
import scala.concurrent.duration._
class ErrorDetailsSpec extends AnyFlatSpec with Matchers {
private val errorLogger = DamlContextualizedErrorLogger.forTesting(getClass)
@ -51,4 +54,16 @@ class ErrorDetailsSpec extends AnyFlatSpec with Matchers {
NonGrpcErrorCode,
) shouldBe false
}
it should "should preserve details when going through grpc Any" in {
val details = Seq(
ErrorDetails
.ErrorInfoDetail(errorCodeId = "errorCodeId1", metadata = Map("a" -> "b", "c" -> "d")),
ErrorDetails.ResourceInfoDetail(name = "name1", typ = "type1"),
ErrorDetails.RequestInfoDetail(correlationId = "correlationId1"),
ErrorDetails.RetryInfoDetail(1.seconds + 2.milliseconds),
)
val anys: Seq[protobuf.Any] = details.map(_.toRpcAny)
ErrorDetails.from(anys) shouldBe details
}
}

View File

@ -256,7 +256,7 @@ class ErrorFactoriesSpec
Map("category" -> "11", "definite_answer" -> "false"),
),
expectedCorrelationIdRequestInfo,
ErrorDetails.ResourceInfoDetail("PACKAGE", "packageId123"),
ErrorDetails.ResourceInfoDetail(typ = "PACKAGE", name = "packageId123"),
),
logEntry = ExpectedLogEntry(
Level.INFO,
@ -314,7 +314,7 @@ class ErrorFactoriesSpec
Map("category" -> "11", "definite_answer" -> "false"),
),
expectedCorrelationIdRequestInfo,
ErrorDetails.ResourceInfoDetail("TRANSACTION_ID", "tId"),
ErrorDetails.ResourceInfoDetail(typ = "TRANSACTION_ID", name = "tId"),
),
logEntry = ExpectedLogEntry(
Level.INFO,

View File

@ -200,7 +200,7 @@ final class ErrorInterceptorSpec
private def assertSecuritySanitizedError(actual: StatusRuntimeException): Assertion = {
assertError(
actual,
expectedCode = Status.Code.INTERNAL,
expectedStatusCode = Status.Code.INTERNAL,
expectedMessage =
"An error occurred. Please contact the operator and inquire about the request <no-correlation-id>",
expectedDetails = Seq(),
@ -214,7 +214,7 @@ final class ErrorInterceptorSpec
): Assertion = {
assertError(
actual,
expectedCode = FooMissingErrorCode.category.grpcCode.get,
expectedStatusCode = FooMissingErrorCode.category.grpcCode.get,
expectedMessage = s"FOO_MISSING_ERROR_CODE(11,0): Foo is missing: $expectedMsg",
expectedDetails =
Seq(ErrorDetails.ErrorInfoDetail("FOO_MISSING_ERROR_CODE", Map("category" -> "11"))),

View File

@ -106,7 +106,7 @@ final class OngoingStreamAuthIT
case sre: StatusRuntimeException =>
assertError(
actual = sre,
expectedCode = Status.Code.ABORTED,
expectedStatusCode = Status.Code.ABORTED,
expectedMessage =
"STALE_STREAM_AUTHORIZATION(2,0): Stale stream authorization. Retry quickly.",
expectedDetails = List(

View File

@ -9,6 +9,7 @@ import ch.qos.logback.core.AppenderBase
import com.daml.platform.testing.LogCollector.Entry
import com.daml.scalautil.Statement
import org.scalatest.Checkpoints.Checkpoint
import org.scalatest.{AppendedClues, OptionValues}
import org.scalatest.matchers.should.Matchers
import org.slf4j.Marker
@ -72,7 +73,26 @@ final class LogCollector extends AppenderBase[ILoggingEvent] {
}
}
trait LogCollectorAssertions { self: Matchers =>
trait LogCollectorAssertions extends OptionValues with AppendedClues { self: Matchers =>
/** @param expectedMarkerAsString use "<line-number>" where a line number would've been expected
*/
def assertSingleLogEntry(
actual: Seq[LogCollector.Entry],
expectedLogLevel: Level,
expectedMsg: String,
expectedMarkerAsString: String,
): Unit = {
actual should have size 1 withClue ("expected exactly one log entry")
val actualEntry = actual.head
val actualMarker =
actualEntry.marker.value.toString.replaceAll("\\.scala:\\d+", ".scala:<line-number>")
val cp = new Checkpoint
cp { Statement.discard { actualEntry.level shouldBe expectedLogLevel } }
cp { Statement.discard { actualEntry.msg shouldBe expectedMsg } }
cp { Statement.discard { actualMarker shouldBe expectedMarkerAsString } }
cp.reportAll()
}
def assertLogEntry(
actual: LogCollector.Entry,

View File

@ -13,6 +13,9 @@ object LoggingContext {
val empty: LoggingContext = new LoggingContext(LoggingEntries.empty)
def apply(entry: LoggingEntry, entries: LoggingEntry*): LoggingContext =
new LoggingContext(LoggingEntries(entry +: entries: _*))
private[logging] def newLoggingContext[A](entries: LoggingEntries)(f: LoggingContext => A): A =
f(new LoggingContext(entries))