Skip to content
Open
Show file tree
Hide file tree
Changes from 5 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions apps/scan/src/main/openapi/scan.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -4060,6 +4060,9 @@ components:
update_id:
description: |
The ID of the transaction update associated with this verdict.

Verdicts are deduplicated by update_id. Only the first verdict ingested for a given update_id is stored and returned, while a subsequent verdict with the same update_id is rejected.
This can happen for example if a sequencer client retries a successful submission. In that case, the retry is rejected as a duplicate, and the events endpoint will only show the successful verdict but not the rejected duplicates.
type: string
migration_id:
description: |
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,7 @@ import com.digitalasset.base.error.utils.ErrorDetails
import com.digitalasset.canton.data.CantonTimestamp
import com.digitalasset.canton.discard.Implicits.DiscardOps
import com.digitalasset.canton.lifecycle.{AsyncOrSyncCloseable, SyncCloseable}
import com.digitalasset.canton.logging.NamedLoggerFactory
import com.digitalasset.canton.logging.{NamedLoggerFactory, TracedLogger}
import com.digitalasset.canton.mediator.admin.v30
import com.digitalasset.canton.sequencing.traffic.TrafficControlErrors
import com.digitalasset.canton.time.Clock
Expand Down Expand Up @@ -64,6 +64,40 @@ object ScanVerdictIngestionService {
.filter(_ >= start)
.filterNot(summaryTimes.contains)
}

/** Groups a batch of verdicts by update id and returns only the update ids that
* appear more than once within the batch.
*/
def findDuplicateUpdateIds(batch: Seq[v30.Verdict]): Map[String, Seq[(v30.Verdict, Int)]] =
batch.zipWithIndex.groupBy(_._1.updateId).filter(_._2.size > 1)

/** True if any verdict in the duplicate groups has an accepted result. */
def duplicatesContainAccept(duplicates: Map[String, Seq[(v30.Verdict, Int)]]): Boolean =
duplicates.values.flatten.exists { case (v, _) =>
v.verdict == v30.VerdictResult.VERDICT_RESULT_ACCEPTED

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks off. We should only warn if we see an accept after seeing another verdict for the same update id.

Seeing a reject after an accept is fine and should not trigger a warning (and thus a production alert).

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Got it. I renamed this duplicatesContainSubsequentAccept, tweaked the logic, and updated the tests accordingly.

}

/** Finds and logs when duplicate verdicts exist in a batch.
* Logs at WARN level when any duplicate is an accept, otherwise at INFO level.
*/
def logDuplicateUpdateIds(batch: Seq[v30.Verdict], logger: TracedLogger)(implicit
tc: TraceContext
): Unit = {
val duplicates = findDuplicateUpdateIds(batch)
if (duplicates.nonEmpty) {
val message = s"Received multiple verdicts with the same update id in the same batch. " +
s"Batch: ${batch.size} verdicts with record times ${batch.map(_.getRecordTime).map(CantonTimestamp.tryFromProtoTimestamp).mkString("[", ",", "]")}. " +
s"Duplicate verdicts: ${duplicates.values.flatten
.map { case (verdict, index) =>
s"${index} => ${verdict}"
}
.mkString("[\n", ",\n", "\n]")}"

if (duplicatesContainAccept(duplicates))
logger.warn(s"$message Duplicate verdicts contains an accept.")
else logger.info(message)
}
}
}

class ScanVerdictIngestionService(
Expand Down Expand Up @@ -387,22 +421,7 @@ class ScanVerdictIngestionService(
.batch(math.max(1, config.mediatorVerdictIngestion.batchSize.toLong), Vector(_))(_ :+ _)
// TODO(DACH-NY/cn-test-failures#8281): Remove once we have figured out why we're getting duplicate data.
.map(batch => {
val duplicates = batch.zipWithIndex
.groupBy(_._1.updateId)
.filter(_._2.size > 1)

if (duplicates.nonEmpty) {
logger.info(
s"Received multiple verdicts with the same update id in the same batch. " +
s"Batch: ${batch.size} verdicts with record times ${batch.map(_.getRecordTime).map(CantonTimestamp.tryFromProtoTimestamp).mkString("[", ",", "]")}. " +
s"Duplicate verdicts: ${duplicates.values.flatten
.map { case (verdict, index) =>
s"${index} => ${verdict}"
}
.mkString("[\n", ",\n", "\n]")}"
)
}

ScanVerdictIngestionService.logDuplicateUpdateIds(batch, logger)
batch
})

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -421,10 +421,22 @@ class DbScanVerdictStore(

for {
alreadyExisting <- checkExist.map(_.toSet)
nonExisting = items.filter(item => !alreadyExisting.contains(item._1.updateId))
_ = logger.info(
s"Already ingested verdicts: $alreadyExisting. Non-existing: ${nonExisting.map(_._1.updateId)}."
)
(dropped, nonExisting) = items.partition(item => alreadyExisting.contains(item._1.updateId))
droppedAccepts =
dropped.filter(_._1.verdictResult == DbScanVerdictStore.VerdictResultDbValue.Accepted)
nonExistingMessage = s"Non-existing: ${nonExisting.map(_._1.updateId)}."
_ =
if (droppedAccepts.nonEmpty)
logger.warn(
s"Dropping duplicate accepted verdicts: ${droppedAccepts.map(_._1.updateId)}. " +
s"All dropped verdicts: ${dropped.map(_._1.updateId)}. $nonExistingMessage"
)
else if (dropped.nonEmpty)
logger.info(
s"Dropping duplicate verdicts: ${dropped.map(_._1.updateId)}. $nonExistingMessage"
)
else
logger.info(s"Already ingested verdicts: $alreadyExisting. $nonExistingMessage")
rowIdMap <-
if (nonExisting.nonEmpty) {
DBIO
Expand Down
Original file line number Diff line number Diff line change
@@ -1,13 +1,24 @@
package org.lfdecentralizedtrust.splice.scan.automation

import com.digitalasset.canton.BaseTest
import com.digitalasset.canton.data.CantonTimestamp
import org.scalatest.matchers.should.Matchers
import com.digitalasset.canton.logging.SuppressionRule
import com.digitalasset.canton.mediator.admin.v30
import org.scalatest.wordspec.AnyWordSpec
import org.slf4j.event.Level.INFO

class ScanVerdictIngestionServiceTest extends AnyWordSpec with Matchers {
class ScanVerdictIngestionServiceTest extends AnyWordSpec with BaseTest {

private def ts(micros: Long) = CantonTimestamp.ofEpochMicro(micros)

private def mkVerdict(updateId: String, accepted: Boolean): v30.Verdict =
v30.Verdict.defaultInstance.copy(
updateId = updateId,
verdict =
if (accepted) v30.VerdictResult.VERDICT_RESULT_ACCEPTED
else v30.VerdictResult.VERDICT_RESULT_REJECTED,
)

"findMissingTrafficSummaries" should {

"return empty when ingestion hasn't started" in {
Expand Down Expand Up @@ -50,4 +61,79 @@ class ScanVerdictIngestionServiceTest extends AnyWordSpec with Matchers {
) shouldBe empty
}
}

"findDuplicateUpdateIds" should {

"return empty when all update ids are distinct" in {
ScanVerdictIngestionService.findDuplicateUpdateIds(
Seq(mkVerdict("a", true), mkVerdict("b", false))
) shouldBe empty
}

"return only the update ids that appear more than once" in {
val result = ScanVerdictIngestionService.findDuplicateUpdateIds(
Seq(mkVerdict("a", true), mkVerdict("b", false), mkVerdict("a", false))
)
result.keySet shouldBe Set("a")
result("a").map(_._2) shouldBe Seq(0, 2)
}
}

"duplicatesContainAccept" should {

"return false when no duplicate is an accept" in {
val duplicates = ScanVerdictIngestionService.findDuplicateUpdateIds(
Seq(mkVerdict("a", false), mkVerdict("a", false))
)
ScanVerdictIngestionService.duplicatesContainAccept(duplicates) shouldBe false
}

"return true when a duplicate group contains an accept" in {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This tests accept-after-reject. Add the same test for reject-after-accept.

val duplicates = ScanVerdictIngestionService.findDuplicateUpdateIds(
Seq(mkVerdict("a", false), mkVerdict("a", true))
)
ScanVerdictIngestionService.duplicatesContainAccept(duplicates) shouldBe true
}

"ignore an accept that is not part of a duplicate group" in {
// "a" is accepted but unique; only "b" is duplicated (both rejected).
val duplicates = ScanVerdictIngestionService.findDuplicateUpdateIds(
Seq(mkVerdict("a", true), mkVerdict("b", false), mkVerdict("b", false))
)
ScanVerdictIngestionService.duplicatesContainAccept(duplicates) shouldBe false
}
}

"logDuplicateUpdateIds" should {

"not log when there are no duplicates" in {
loggerFactory.assertLogsSeq(SuppressionRule.LevelAndAbove(INFO))(
ScanVerdictIngestionService.logDuplicateUpdateIds(
Seq(mkVerdict("a", true), mkVerdict("b", true)),
logger,
),
_ shouldBe empty,
)
}

"log at info level when no duplicate is an accept" in {
loggerFactory.assertLogs(SuppressionRule.LevelAndAbove(INFO))(
ScanVerdictIngestionService.logDuplicateUpdateIds(
Seq(mkVerdict("a", false), mkVerdict("a", false)),
logger,
),
_.infoMessage should include("Duplicate verdicts:"),
)
}

"log at warning level when a duplicate is an accept" in {
loggerFactory.assertLogs(
ScanVerdictIngestionService.logDuplicateUpdateIds(
Seq(mkVerdict("a", true), mkVerdict("a", false)),

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As noted above, this particular order should not warn.

logger,
),
_.warningMessage should endWith("Duplicate verdicts contains an accept."),
)
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -412,6 +412,101 @@ class DbAppActivityRecordStoreTest
countAfter shouldBe 0L
}
}

"drop a rejected verdict that's a duplicate of a prior accept" in {

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Here we already have the behavior that reject-after-accept does not warn.

val updateId = "update-dupe-reject-after-accept"
val ts1 = CantonTimestamp.now()
val ts2 = ts1.plusSeconds(1L)
for {
(appStore, verdictStore) <- newStores()
accepted = mkVerdict(
verdictStore,
updateId,
ts1,
DbScanVerdictStore.VerdictResultDbValue.Accepted,
)
rejected = mkVerdict(
verdictStore,
updateId,
ts2,
DbScanVerdictStore.VerdictResultDbValue.Rejected,
)
// First batch with the accepted verdict and its activity record
_ <- verdictStore.insertVerdictsWithAppActivityRecords(
NonEmptyList.of(accepted -> noViews),
Seq(ts1 -> mkRecord(0L, 10L, Seq("app1::provider"), Seq(100L))),
hasTrafficSummaries = true,
firstActiveRoundO = Some(10L),
lastArchivedRoundO = Some(9L),
)
countAfterBatch1 <- countRecords()
// A later batch with a rejection for the same update_id
_ <- verdictStore.insertVerdictsWithAppActivityRecords(
NonEmptyList.of(rejected -> noViews),
Seq(ts2 -> mkRecord(0L, 11L, Seq("app2::provider"), Seq(200L))),
hasTrafficSummaries = true,
firstActiveRoundO = Some(11L),
lastArchivedRoundO = Some(10L),
)
v <- verdictStore.getVerdictByUpdateId(updateId)
countAfterBatch2 <- countRecords()
} yield {
v shouldBe defined
v.value.verdictResult shouldBe DbScanVerdictStore.VerdictResultDbValue.Accepted
v.value.recordTime shouldBe ts1
// The rejection's activity record was dropped along with the verdict
countAfterBatch2 shouldBe countAfterBatch1
}
}

"drop and warn of an accepted verdict that's a duplicate of a prior rejection" in {
val updateId = "update-dupe-accept-after-reject"
val ts1 = CantonTimestamp.now()
val ts2 = ts1.plusSeconds(1L)
for {
(appStore, verdictStore) <- newStores()
rejected = mkVerdict(
verdictStore,
updateId,
ts1,
DbScanVerdictStore.VerdictResultDbValue.Rejected,
)
accepted = mkVerdict(
verdictStore,
updateId,
ts2,
DbScanVerdictStore.VerdictResultDbValue.Accepted,
)
// First batch with the rejection and its activity record
_ <- verdictStore.insertVerdictsWithAppActivityRecords(
NonEmptyList.of(rejected -> noViews),
Seq(ts1 -> mkRecord(0L, 10L, Seq("app1::provider"), Seq(100L))),
hasTrafficSummaries = true,
firstActiveRoundO = Some(10L),
lastArchivedRoundO = Some(9L),
)
countAfterBatch1 <- countRecords()
// A later batch with an accept for the same update_id
_ <- loggerFactory.assertLogs(
verdictStore.insertVerdictsWithAppActivityRecords(
NonEmptyList.of(accepted -> noViews),
Seq(ts2 -> mkRecord(0L, 11L, Seq("app2::provider"), Seq(200L))),
hasTrafficSummaries = true,
firstActiveRoundO = Some(11L),
lastArchivedRoundO = Some(10L),
),
_.warningMessage should startWith("Dropping duplicate accepted verdicts"),
)
v <- verdictStore.getVerdictByUpdateId(updateId)
countAfterBatch2 <- countRecords()
} yield {
v shouldBe defined
v.value.verdictResult shouldBe DbScanVerdictStore.VerdictResultDbValue.Rejected
v.value.recordTime shouldBe ts1
// The accept's activity record was dropped along with the verdict
countAfterBatch2 shouldBe countAfterBatch1
}
}
}

"earliestRoundWithCompleteAppActivity" should {
Expand Down Expand Up @@ -1200,6 +1295,7 @@ class DbAppActivityRecordStoreTest
verdictStore: DbScanVerdictStore,
updateId: String,
recordTs: CantonTimestamp,
verdictResult: Short = DbScanVerdictStore.VerdictResultDbValue.Accepted,
): verdictStore.VerdictT =
new verdictStore.VerdictT(
rowId = 0L,
Expand All @@ -1208,7 +1304,7 @@ class DbAppActivityRecordStoreTest
recordTime = recordTs,
finalizationTime = recordTs,
submittingParticipantUid = "participant1",
verdictResult = DbScanVerdictStore.VerdictResultDbValue.Accepted,
verdictResult = verdictResult,
mediatorGroup = 0,
updateId = updateId,
submittingParties = Seq.empty,
Expand Down