diff --git a/obp-api/src/main/scala/code/accountaccessrequest/AccountAccessRequest.scala b/obp-api/src/main/scala/code/accountaccessrequest/AccountAccessRequest.scala index 397587363b..2bc25655ec 100644 --- a/obp-api/src/main/scala/code/accountaccessrequest/AccountAccessRequest.scala +++ b/obp-api/src/main/scala/code/accountaccessrequest/AccountAccessRequest.scala @@ -90,13 +90,12 @@ object MappedAccountAccessRequestProvider extends AccountAccessRequestProvider { checkerComment: String ): Box[AccountAccessRequestTrait] = { AccountAccessRequest.find(By(AccountAccessRequest.AccountAccessRequestId, accountAccessRequestId)).flatMap { request => - tryo { - request - .Status(status) - .CheckerUserId(checkerUserId) - .CheckerComment(checkerComment) - .saveMe() - } + // Atomic guarded transition: an access request is actioned once, from INITIATED. The loser of a + // concurrent approve/decline gets 0 rows -> Failure, instead of silently overwriting the decision. + val rows = code.bankconnectors.DoobieBusinessStatusQueries.conditionalAccountAccessRequestStatus( + request.id.get, AccountAccessRequestStatus.INITIATED.toString, status, checkerUserId, checkerComment) + if (rows == 1) AccountAccessRequest.find(By(AccountAccessRequest.AccountAccessRequestId, accountAccessRequestId)) + else net.liftweb.common.Failure("Account access request is no longer INITIATED; it was already actioned.") } } } diff --git a/obp-api/src/main/scala/code/accountapplication/MappedAccountApplication.scala b/obp-api/src/main/scala/code/accountapplication/MappedAccountApplication.scala index 9040013306..be4008278a 100644 --- a/obp-api/src/main/scala/code/accountapplication/MappedAccountApplication.scala +++ b/obp-api/src/main/scala/code/accountapplication/MappedAccountApplication.scala @@ -35,7 +35,14 @@ object MappedAccountApplicationProvider extends AccountApplicationProvider { match { case Full(accountApplication) if(accountApplication.status == "ACCEPTED") => Failure(s"${ErrorMessages.AccountApplicationAlreadyAccepted} Current Account-Application-Id($accountApplicationId)") - case Full(accountApplication) => tryo{accountApplication.mStatus(status).saveMe()} + case Full(accountApplication) => + // Optimistic CAS: transition only if the status hasn't changed since we loaded it. Two + // concurrent updates that both read the same status can no longer both write — the loser + // (0 rows) gets a Failure instead of silently overwriting the winner's decision. + val rows = code.bankconnectors.DoobieBusinessStatusQueries.conditionalAccountApplicationStatus( + accountApplication.id.get, accountApplication.status, status) + if (rows == 1) MappedAccountApplication.find(By(MappedAccountApplication.mAccountApplicationId, accountApplicationId)) + else Failure(s"${ErrorMessages.AccountApplicationAlreadyAccepted} Status changed concurrently. Current Account-Application-Id($accountApplicationId)") case Empty => Failure(s"${ErrorMessages.AccountApplicationNotFound} Current Account-Application-Id($accountApplicationId)") case _ => Failure(ErrorMessages.UnknownError) } diff --git a/obp-api/src/main/scala/code/actorsystem/ObpActorSystem.scala b/obp-api/src/main/scala/code/actorsystem/ObpActorSystem.scala index 9189bd9408..00bb81d19f 100644 --- a/obp-api/src/main/scala/code/actorsystem/ObpActorSystem.scala +++ b/obp-api/src/main/scala/code/actorsystem/ObpActorSystem.scala @@ -10,8 +10,10 @@ import com.typesafe.config.ConfigFactory object ObpActorSystem extends MdcLoggable { val props_hostname = Helper.getHostname - var obpActorSystem: ActorSystem = _ - var northSideAkkaConnectorActorSystem: ActorSystem = _ + // @volatile so the single assignment of each actor system is visible to all reader threads + // (the JVM memory model does not guarantee visibility of a non-volatile write across threads). + @volatile var obpActorSystem: ActorSystem = _ + @volatile var northSideAkkaConnectorActorSystem: ActorSystem = _ def startLocalActorSystem() = localActorSystem @@ -22,12 +24,19 @@ object ObpActorSystem extends MdcLoggable { obpActorSystem = ActorSystem.create(s"ObpActorSystem_${props_hostname}", ConfigFactory.load(ConfigFactory.parseString(localConf))) obpActorSystem } - + + // synchronized double-checked init so concurrent callers start the connector system exactly once. def startNorthSideAkkaConnectorActorSystem(): ActorSystem = { - logger.info("Starting North Side Akka Connector actor system") - val localConf = AkkaConnectorActorConfig.localConf - logger.info(localConf) - northSideAkkaConnectorActorSystem = ActorSystem.create(s"SouthSideAkkaConnector_${props_hostname}", ConfigFactory.load(ConfigFactory.parseString(localConf))) + if (northSideAkkaConnectorActorSystem == null) { + synchronized { + if (northSideAkkaConnectorActorSystem == null) { + logger.info("Starting North Side Akka Connector actor system") + val localConf = AkkaConnectorActorConfig.localConf + logger.info(localConf) + northSideAkkaConnectorActorSystem = ActorSystem.create(s"SouthSideAkkaConnector_${props_hostname}", ConfigFactory.load(ConfigFactory.parseString(localConf))) + } + } + } northSideAkkaConnectorActorSystem } } \ No newline at end of file diff --git a/obp-api/src/main/scala/code/actorsystem/ObpLookupSystem.scala b/obp-api/src/main/scala/code/actorsystem/ObpLookupSystem.scala index d9c9aeb832..359f92ce17 100644 --- a/obp-api/src/main/scala/code/actorsystem/ObpLookupSystem.scala +++ b/obp-api/src/main/scala/code/actorsystem/ObpLookupSystem.scala @@ -16,14 +16,20 @@ object ObpLookupSystem extends ObpLookupSystem { } trait ObpLookupSystem extends MdcLoggable { - var obpLookupSystem: ActorSystem = null + // @volatile + synchronized double-checked init: without it two threads can both see null, + // both build an ActorSystem (resource leak), and a reader can observe a stale null. + @volatile var obpLookupSystem: ActorSystem = null val props_hostname = Helper.getHostname def init (): ActorSystem = { - if (obpLookupSystem == null ) { - val system = ActorSystem("ObpLookupSystem", ConfigFactory.load(ConfigFactory.parseString(ObpActorConfig.lookupConf))) - logger.info(ObpActorConfig.lookupConf) - obpLookupSystem = system + if (obpLookupSystem == null) { + synchronized { + if (obpLookupSystem == null) { + val system = ActorSystem("ObpLookupSystem", ConfigFactory.load(ConfigFactory.parseString(ObpActorConfig.lookupConf))) + logger.info(ObpActorConfig.lookupConf) + obpLookupSystem = system + } + } } obpLookupSystem } diff --git a/obp-api/src/main/scala/code/api/cache/Redis.scala b/obp-api/src/main/scala/code/api/cache/Redis.scala index 0741f6719e..631155a524 100644 --- a/obp-api/src/main/scala/code/api/cache/Redis.scala +++ b/obp-api/src/main/scala/code/api/cache/Redis.scala @@ -201,6 +201,55 @@ object Redis extends MdcLoggable { } } + /** + * Atomic `SET key value EX ttlSeconds NX` (Jedis 2.9.0 five-arg overload). Sets the key with a TTL + * only if it does not already exist, in a single command. Returns true iff this call set the key. + * + * Use for first-write-wins caching (idempotency response cache) and lock acquisition: there is no + * window between "set value" and "set TTL" (unlike setnx + expire), so a crash can never leave a + * key without an expiry, and a second writer can never clobber the first. + */ + def setNxEx(key: String, value: String, ttlSeconds: Int): Boolean = { + var jedisConnection: Option[Jedis] = None + try { + jedisConnection = Some(jedisPool.getResource()) + jedisConnection.get.set(key, value, "NX", "EX", ttlSeconds) == "OK" + } catch { + case e: Throwable => throw new RuntimeException(e) + } finally { + if (jedisConnection.isDefined && jedisConnection.get != null) + jedisConnection.foreach(_.close()) + } + } + + /** + * Atomic increment-with-create-TTL via a single Lua script: INCR the key, and on first creation + * (value == 1) set its expiry. Returns the post-increment counter value. Because INCR and EXPIRE + * run atomically server-side, concurrent callers cannot lose increments or race the TTL set, and an + * increment-then-compare rate-limit check cannot be bypassed by interleaving. + */ + def incrementWithTtl(key: String, ttlSeconds: Int): Long = { + val script = + """local c = redis.call('INCR', KEYS[1]) + |if c == 1 then redis.call('EXPIRE', KEYS[1], ARGV[1]) end + |return c""".stripMargin + var jedisConnection: Option[Jedis] = None + try { + jedisConnection = Some(jedisPool.getResource()) + val result = jedisConnection.get.eval( + script, + java.util.Collections.singletonList(key), + java.util.Collections.singletonList(ttlSeconds.toString) + ) + result.asInstanceOf[java.lang.Long].longValue() + } catch { + case e: Throwable => throw new RuntimeException(e) + } finally { + if (jedisConnection.isDefined && jedisConnection.get != null) + jedisConnection.foreach(_.close()) + } + } + /** * Delete all Redis keys matching a pattern using KEYS command * @param pattern Redis key pattern (e.g., "rl_active_CONSUMER123_*") diff --git a/obp-api/src/main/scala/code/api/util/APIUtil.scala b/obp-api/src/main/scala/code/api/util/APIUtil.scala index 8daef9ec2d..72fb97b8ab 100644 --- a/obp-api/src/main/scala/code/api/util/APIUtil.scala +++ b/obp-api/src/main/scala/code/api/util/APIUtil.scala @@ -4407,7 +4407,9 @@ object APIUtil extends MdcLoggable with CustomJsonFormats{ * value: dependent endpoint information list. * this is used by MessageDoc */ - val connectorToEndpoint = mutable.Map[String, List[EndpointInfo]]() + // Thread-safe concurrent map: populated during startup scanning and read on the resource-docs + // path. TrieMap keeps the mutable.Map API (getOrElse/put) while being safe under concurrent access. + val connectorToEndpoint = scala.collection.concurrent.TrieMap[String, List[EndpointInfo]]() private def addEndpointInfos(connectorMethods: List[String], partialFunctionName: String, apiVersion: ScannedApiVersion) = { val endpointInfo = EndpointInfo(partialFunctionName, apiVersion.fullyQualifiedVersion) diff --git a/obp-api/src/main/scala/code/api/util/RateLimitingUtil.scala b/obp-api/src/main/scala/code/api/util/RateLimitingUtil.scala index 2d4a02522b..7b3a8a459a 100644 --- a/obp-api/src/main/scala/code/api/util/RateLimitingUtil.scala +++ b/obp-api/src/main/scala/code/api/util/RateLimitingUtil.scala @@ -244,22 +244,17 @@ object RateLimitingUtil extends MdcLoggable { * No gates, no key formatting — call sites pass the final key and supply their own enable flags. * Returns (ttl_seconds, current_count); (-1, -1) when Redis is unreachable. */ private[util] def incrementCounter(key: String, period: LimitCallPeriod): (Long, Long) = { - val ttlOpt = Redis.use(JedisMethod.TTL, key).map(_.toInt) - ttlOpt match { - case Some(-2) => // Key does not exist, create it - val seconds = RateLimitingPeriod.toSeconds(period).toInt - Redis.use(JedisMethod.SET, key, Some(seconds), Some("1")) - (seconds, 1) - case Some(ttl) if ttl > 0 => // Key exists with TTL, increment it - val cnt = Redis.use(JedisMethod.INCR, key).map(_.toInt).getOrElse(1) - (ttl, cnt) - case Some(ttl) if ttl <= 0 => // Key expired or has no expiry (shouldn't happen) - logger.warn(s"Unexpected TTL state ($ttl) for key $key, period $period - recreating counter") - val seconds = RateLimitingPeriod.toSeconds(period).toInt - Redis.use(JedisMethod.SET, key, Some(seconds), Some("1")) - (seconds, 1) - case None => // Redis unavailable - logger.error(s"Redis unavailable when incrementing counter for key $key, period $period") + val seconds = RateLimitingPeriod.toSeconds(period).toInt + try { + // Atomic INCR + create-TTL in one Lua call. Replaces the former TTL-read-then-SET/INCR sequence, + // which could lose increments and race the expiry under concurrency. On first increment (cnt==1) + // the key gets its TTL atomically. + val cnt = Redis.incrementWithTtl(key, seconds) + val ttl = Redis.use(JedisMethod.TTL, key).map(_.toLong).getOrElse(seconds.toLong) + (ttl, cnt) + } catch { + case e: Throwable => + logger.error(s"Redis unavailable when incrementing counter for key $key, period $period", e) (-1, -1) } } diff --git a/obp-api/src/main/scala/code/api/util/http4s/IdempotencyMiddleware.scala b/obp-api/src/main/scala/code/api/util/http4s/IdempotencyMiddleware.scala index 544c393b1b..f9e9c5032d 100644 --- a/obp-api/src/main/scala/code/api/util/http4s/IdempotencyMiddleware.scala +++ b/obp-api/src/main/scala/code/api/util/http4s/IdempotencyMiddleware.scala @@ -294,23 +294,21 @@ object IdempotencyMiddleware extends MdcLoggable { Option(j.get(key)).flatMap(envelopeFromJson) } - private def writeResponseKey(key: String, env: Envelope): Unit = - withJedis { j => - j.setex(key, ResponseTtlSeconds, envelopeToJson(env)) - () - } + // First-write-wins via atomic SET NX EX: once a response is cached for an idempotency key it is + // immutable for its TTL, so a second concurrent response cannot clobber the first (which a replay + // would then return). Plain setex overwrites unconditionally. + private def writeResponseKey(key: String, env: Envelope): Unit = { + Redis.setNxEx(key, envelopeToJson(env), ResponseTtlSeconds) + () + } /** - * SETNX + EXPIRE. The brief window between the two has the lock without a - * TTL, but the key value is only ever a sentinel and the next overwrite (or - * crash recovery via the 60s TTL once expire lands) resolves it. + * Atomic SET NX EX: acquire the lock and set its TTL in one command. Unlike setnx + a separate + * expire, there is no window in which the key exists without a TTL, so a crash mid-acquire can + * never orphan the lock and permanently block retries of that idempotency key. */ private def tryAcquireLock(key: String): Boolean = - withJedis { j => - val acquired = j.setnx(key, "1") == 1L - if (acquired) j.expire(key, LockTtlSeconds) - acquired - } + Redis.setNxEx(key, "1", LockTtlSeconds) private def deleteKey(key: String): Unit = withJedis { j => diff --git a/obp-api/src/main/scala/code/api/v3_1_0/Http4s310.scala b/obp-api/src/main/scala/code/api/v3_1_0/Http4s310.scala index b5d4e85d19..766a930675 100644 --- a/obp-api/src/main/scala/code/api/v3_1_0/Http4s310.scala +++ b/obp-api/src/main/scala/code/api/v3_1_0/Http4s310.scala @@ -4434,8 +4434,15 @@ object Http4s310 { APIUtil.ConsumerIdPair(grantorConsumerId, granteeConsumerId)) _ <- if (shouldSkipConsentSca) { Future { - MappedConsent.find(By(MappedConsent.mConsentId, createdConsent.consentId)) - .map(_.mStatus(ConsentStatus.ACCEPTED.toString).saveMe()).head + // Atomic guarded auto-accept: only move INITIATED -> ACCEPTED. If the consent was + // concurrently revoked, the conditional UPDATE is a 0-row no-op and the revoke stands, + // instead of the skip-SCA write blindly resurrecting it to ACCEPTED. + // The consent was just created above, so find must succeed; fail visibly (rather than + // silently leaving it INITIATED) if it has vanished — that is an internal inconsistency. + val consent = MappedConsent.find(By(MappedConsent.mConsentId, createdConsent.consentId)) + .openOrThrowException(s"Consent ${createdConsent.consentId} not found immediately after creation") + code.bankconnectors.DoobieConsentStatusQueries + .conditionalStatusTransition(consent.id.get, ConsentStatus.INITIATED.toString, ConsentStatus.ACCEPTED.toString) } } else { val challengeText = s"Your consent challenge : $challengeAnswer, Application: $applicationText" diff --git a/obp-api/src/main/scala/code/api/v5_1_0/Http4s510.scala b/obp-api/src/main/scala/code/api/v5_1_0/Http4s510.scala index 31d57505a8..2c08a99f1b 100644 --- a/obp-api/src/main/scala/code/api/v5_1_0/Http4s510.scala +++ b/obp-api/src/main/scala/code/api/v5_1_0/Http4s510.scala @@ -3380,6 +3380,14 @@ object Http4s510 { postedData <- NewStyle.function.tryons(s"$InvalidJsonFormat The Json body should be the $PostTransactionRequestStatusJsonV510", 400, Some(cc)) { com.openbankproject.commons.util.JsonAliases.parse(cc.httpBody.getOrElse("")).extract[PostTransactionRequestStatusJsonV510] } + // Lock the transaction-request row for the duration of this request transaction (the + // FOR UPDATE lock runs on the request connection via RequestScopeConnection, so it is held + // through the read + status write below). Without it this management update races the + // challenge-answer path (Http4s400, which already locks) and can overwrite a COMPLETED + // payment with a stale status. + _ <- code.util.Helper.booleanToFuture("Failed to acquire transaction request lock", cc = Some(cc)) { + code.bankconnectors.DoobieTransactionRequestQueries.lockTransactionRequest(requestId.value).isDefined + } (existing, _) <- NewStyle.function.getTransactionRequestImpl(requestId, Some(cc)) _ <- NewStyle.function.hasAtLeastOneEntitlement(existing.from.bank_id, user.userId, canUpdateTransactionRequestStatusAtOneBank :: canUpdateTransactionRequestStatusAtAnyBank :: Nil, Some(cc)) diff --git a/obp-api/src/main/scala/code/api/v7_0_0/Http4s700.scala b/obp-api/src/main/scala/code/api/v7_0_0/Http4s700.scala index 82f317180e..bfbdff958d 100644 --- a/obp-api/src/main/scala/code/api/v7_0_0/Http4s700.scala +++ b/obp-api/src/main/scala/code/api/v7_0_0/Http4s700.scala @@ -3294,9 +3294,23 @@ object Http4s700 { _ <- NewStyle.function.checkAuthorisationToCreateTransactionRequest( view.viewId, BankIdAccountId(fromAccount.bankId, fromAccount.accountId), user, callCtx ) - // 3. Create the parent BULK TR row. toAccount = self (envelope only; - // the real destinations live in the per-payment side-table). trId = APIUtil.generateUUID() + // 3. Claim the batch_reference for idempotency BEFORE creating the parent TR or + // fanning out any payment. The UniqueIndex(FromBankId, FromAccountId, BatchReference) + // makes this the single atomic point of idempotency: two concurrent submissions both + // pass the earlier isBatchReferenceUsed check, but only one wins the INSERT here. The + // loser's Box is a Failure — we must surface it (409) so it aborts before any payment, + // rather than dropping it and double-charging. + _ <- Future { + unboxFullOrFail( + BulkPayments.bulkPayment.vend.claimBatchReference( + fromAccount.bankId.value, fromAccount.accountId.value, body.batch_reference, trId + ), + callCtx, BulkBatchReferenceAlreadyUsed, 409 + ) + } + // 4. Create the parent BULK TR row. toAccount = self (envelope only; + // the real destinations live in the per-payment side-table). detailsPlain = prettyRender(Extraction.decompose(body)) parentTrBox = MappedTransactionRequestProvider.createTransactionRequestImpl210( com.openbankproject.commons.model.TransactionRequestId(trId), @@ -3317,13 +3331,6 @@ object Http4s700 { _ <- Future { unboxFullOrFail(parentTrBox, callCtx, BulkPaymentTransactionRequestError, 500) } - // 4. Claim the batch_reference for idempotency. After this, a - // second submission with the same batch_reference fails fast. - _ <- Future { - BulkPayments.bulkPayment.vend.claimBatchReference( - fromAccount.bankId.value, fromAccount.accountId.value, body.batch_reference, trId - ) - } // 5. Fan-out — sequential per-payment execution. Returns one row // per input item (SUCCEEDED / FAILED + reason). itemRows <- BulkPaymentHandler.executeAllItems(body, fromAccount, trId, chargePolicy, callCtx) diff --git a/obp-api/src/main/scala/code/bankconnectors/DoobieBusinessStatusQueries.scala b/obp-api/src/main/scala/code/bankconnectors/DoobieBusinessStatusQueries.scala new file mode 100644 index 0000000000..e9957c5217 --- /dev/null +++ b/obp-api/src/main/scala/code/bankconnectors/DoobieBusinessStatusQueries.scala @@ -0,0 +1,52 @@ +package code.bankconnectors + +import code.api.util.DoobieUtil +import doobie._ +import doobie.implicits._ + +/** + * Atomic, guarded status transitions for business state-machine rows whose Lift updateStatus + * methods were check-then-write (load row, compare status in memory, saveMe). Each method is a + * single conditional UPDATE with a status guard, returning the affected-row count so the caller + * can tell whether it won the transition (1) or lost it to a concurrent request (0). + */ +object DoobieBusinessStatusQueries { + + /** AccountAccessRequest: transition only from the guard status. Table has explicit dbTableName. */ + def conditionalAccountAccessRequestStatus( + rowId: Long, + guardStatus: String, + newStatus: String, + checkerUserId: String, + checkerComment: String + ): Int = DoobieUtil.runUpdate( + sql"""UPDATE AccountAccessRequest + SET status = $newStatus, + checkeruserid = $checkerUserId, + checkercomment = $checkerComment + WHERE id = $rowId + AND status = $guardStatus""".update.run + ) + + /** MappedAccountApplication: transition only from the guard status (a one-shot decision). */ + def conditionalAccountApplicationStatus(rowId: Long, guardStatus: String, newStatus: String): Int = + DoobieUtil.runUpdate( + sql"""UPDATE mappedaccountapplication + SET mstatus = $newStatus + WHERE id = $rowId + AND mstatus = $guardStatus""".update.run + ) + + /** ExpectedChallengeAnswer: compare-and-set the success flag so only one correct answer wins. + * Booleans are bound as typed JDBC parameters (not SQL literals) so the driver maps them to the + * column type correctly across H2 and Postgres. */ + def conditionalChallengeSuccess(challengeId: String, finalisedScaStatus: String): Int = + DoobieUtil.runUpdate( + // NB: Lift MappedBoolean maps the `Successful` field to column `successful_c` (it appends _c). + sql"""UPDATE ExpectedChallengeAnswer + SET successful_c = ${true}, + scastatus = $finalisedScaStatus + WHERE challengeid = $challengeId + AND successful_c = ${false}""".update.run + ) +} diff --git a/obp-api/src/main/scala/code/bankconnectors/DoobieConsentStatusQueries.scala b/obp-api/src/main/scala/code/bankconnectors/DoobieConsentStatusQueries.scala new file mode 100644 index 0000000000..e28d91abec --- /dev/null +++ b/obp-api/src/main/scala/code/bankconnectors/DoobieConsentStatusQueries.scala @@ -0,0 +1,38 @@ +package code.bankconnectors + +import code.api.util.DoobieUtil +import doobie._ +import doobie.implicits._ + +/** + * Atomic, guarded status transitions for `mappedconsent`, used by the HTTP-facing + * consent state machine (checkAnswer / revoke / skip-SCA accept). + * + * Each method is a single conditional UPDATE keyed by the row id with a status guard, so the + * check and the write cannot interleave across concurrent requests. The returned affected-row + * count tells the caller whether it won the transition (1) or lost it to a concurrent request (0). + * + * Row-id keyed (not consent-id) because every call site already holds the loaded MappedConsent. + */ +object DoobieConsentStatusQueries { + + /** Transition mstatus from an expected guard value to a new value. Returns affected rows (0 or 1). */ + def conditionalStatusTransition(consentRowId: Long, guardStatus: String, newStatus: String): Int = + DoobieUtil.runUpdate( + sql"""UPDATE mappedconsent + SET mstatus = $newStatus, + mlastactiondate = NOW() + WHERE id = $consentRowId + AND mstatus = $guardStatus""".update.run + ) + + /** Revoke unless already at the given terminal status. Returns affected rows (0 or 1). */ + def conditionalRevoke(consentRowId: Long, revokedStatus: String): Int = + DoobieUtil.runUpdate( + sql"""UPDATE mappedconsent + SET mstatus = $revokedStatus, + mlastactiondate = NOW() + WHERE id = $consentRowId + AND mstatus <> $revokedStatus""".update.run + ) +} diff --git a/obp-api/src/main/scala/code/bankconnectors/DoobieTransactionRequestQueries.scala b/obp-api/src/main/scala/code/bankconnectors/DoobieTransactionRequestQueries.scala index 80cb02a548..25d319427d 100644 --- a/obp-api/src/main/scala/code/bankconnectors/DoobieTransactionRequestQueries.scala +++ b/obp-api/src/main/scala/code/bankconnectors/DoobieTransactionRequestQueries.scala @@ -12,12 +12,22 @@ object DoobieTransactionRequestQueries { * Atomically locks the transaction request row using SELECT FOR UPDATE. * This ensures that concurrent MFA challenge answers cannot be processed simultaneously * for the same transaction request. + * + * Returns the locked row's status as Some, or None when the request id does not exist. + * `.option` (not `.unique`) is deliberate: a missing row must not raise an exception, so + * the caller can let the downstream lookup return the correct 404 instead of a misleading + * "lock failed" 400. */ - def atomicallyLockTransactionRequest(transReqId: String): ConnectionIO[String] = { - sql"SELECT mstatus FROM mappedtransactionrequest WHERE mtransactionrequestid = $transReqId FOR UPDATE".query[String].unique + def atomicallyLockTransactionRequest(transReqId: String): ConnectionIO[Option[String]] = { + sql"SELECT mstatus FROM mappedtransactionrequest WHERE mtransactionrequestid = $transReqId FOR UPDATE".query[String].option } - def lockTransactionRequest(transReqId: String): Box[String] = { + /** + * Box semantics: Full(Some(status)) = row locked; Full(None) = request id does not exist + * (query ran cleanly); Failure = a genuine DB/lock error. Callers check `.isDefined` on the + * Box, so only a real lock failure short-circuits with 400 — a missing row falls through. + */ + def lockTransactionRequest(transReqId: String): Box[Option[String]] = { tryo { DoobieUtil.runUpdate(atomicallyLockTransactionRequest(transReqId)) } diff --git a/obp-api/src/main/scala/code/bankconnectors/DoobieUserAuthContextUpdateQueries.scala b/obp-api/src/main/scala/code/bankconnectors/DoobieUserAuthContextUpdateQueries.scala new file mode 100644 index 0000000000..cc6e90143a --- /dev/null +++ b/obp-api/src/main/scala/code/bankconnectors/DoobieUserAuthContextUpdateQueries.scala @@ -0,0 +1,23 @@ +package code.bankconnectors + +import code.api.util.DoobieUtil +import doobie._ +import doobie.implicits._ + +/** + * Atomic, guarded status transition for `mappeduserauthcontextupdate`. + * + * The challenge-answer path checks status == INITIATED then writes ACCEPTED/REJECTED as two + * separate operations; this collapses them into one conditional UPDATE so two concurrent correct + * answers cannot both be accepted. Returns affected rows (0 or 1). + */ +object DoobieUserAuthContextUpdateQueries { + + def conditionalStatusTransition(rowId: Long, guardStatus: String, newStatus: String): Int = + DoobieUtil.runUpdate( + sql"""UPDATE mappeduserauthcontextupdate + SET mstatus = $newStatus + WHERE id = $rowId + AND mstatus = $guardStatus""".update.run + ) +} diff --git a/obp-api/src/main/scala/code/bankconnectors/DynamicConnector.scala b/obp-api/src/main/scala/code/bankconnectors/DynamicConnector.scala index b7436ac042..75d68d31c2 100644 --- a/obp-api/src/main/scala/code/bankconnectors/DynamicConnector.scala +++ b/obp-api/src/main/scala/code/bankconnectors/DynamicConnector.scala @@ -20,7 +20,9 @@ object DynamicConnector { // val heavyClassService: HeavyClass = DynamicConnector.getSingletonObject("heavyClassService").getOrElse( // DynamicConnector.createSingletonObject("heavyClassService",new HeavyClass()) // ).asInstanceOf[HeavyClass] - private val singletonObjectMap = collection.mutable.Map[String, Any]() + // Thread-safe: concurrent createSingletonObject/getSingletonObject calls from different requests + // must not lose writes or corrupt the map during a resize. TrieMap is a lock-free concurrent Map. + private val singletonObjectMap = scala.collection.concurrent.TrieMap[String, Any]() def createSingletonObject (key:String, value: Any) = singletonObjectMap.put(key, value) def getSingletonObject (key:String) = singletonObjectMap.get(key) def updateSingletonObject(key:String, value: Any) = singletonObjectMap.update(key, value) diff --git a/obp-api/src/main/scala/code/consent/MappedConsent.scala b/obp-api/src/main/scala/code/consent/MappedConsent.scala index 3c27185ae4..451649f491 100644 --- a/obp-api/src/main/scala/code/consent/MappedConsent.scala +++ b/obp-api/src/main/scala/code/consent/MappedConsent.scala @@ -369,17 +369,19 @@ object MappedConsentProvider extends ConsentProvider with code.util.Helper.MdcLo case Full(consent) if consent.status == ConsentStatus.REVOKED.toString => Failure(ErrorMessages.ConsentAlreadyRevoked) case Full(consent) => - tryo(consent - .mStatus(ConsentStatus.REVOKED.toString) - .mLastActionDate(now) - .saveMe()) + // Atomic guarded revoke: UPDATE ... WHERE mstatus <> 'REVOKED'. A concurrent request that + // already revoked makes this a 0-row no-op, so we never resurrect or double-revoke. + val rows = code.bankconnectors.DoobieConsentStatusQueries + .conditionalRevoke(consent.id.get, ConsentStatus.REVOKED.toString) + if (rows >= 1) MappedConsent.find(By(MappedConsent.mConsentId, consentId)) + else Failure(ErrorMessages.ConsentAlreadyRevoked) case Empty => Empty ?~! ErrorMessages.ConsentNotFound case Failure(msg, _, _) => Failure(msg) case _ => Failure(ErrorMessages.UnknownError) - } + } } override def revokeBerlinGroupConsent(consentId: String): Box[MappedConsent] = { MappedConsent.find(By(MappedConsent.mConsentId, consentId)) match { @@ -412,10 +414,16 @@ object MappedConsentProvider extends ConsentProvider with code.util.Helper.MdcLo case Full(consent) => consent.status match { case value if value == ConsentStatus.INITIATED.toString => - val status = - if (isAnswerCorrect(consent.challenge, challengeAnswer, consent.mSalt.get)) ConsentStatus.ACCEPTED.toString + val status = + if (isAnswerCorrect(consent.challenge, challengeAnswer, consent.mSalt.get)) ConsentStatus.ACCEPTED.toString else ConsentStatus.REJECTED.toString - tryo(consent.mStatus(status).mLastActionDate(now).saveMe()) + // Atomic guarded transition: only one concurrent answer may move INITIATED -> status. + // The loser (0 rows) gets a Failure rather than a second "success" that would let two + // callers proceed past the SCA gate on one consent. + val rows = code.bankconnectors.DoobieConsentStatusQueries + .conditionalStatusTransition(consent.id.get, ConsentStatus.INITIATED.toString, status) + if (rows == 1) MappedConsent.find(By(MappedConsent.mConsentId, consentId)) + else Failure("Consent status changed concurrently; it is no longer INITIATED.") case _ => Full(consent) } diff --git a/obp-api/src/main/scala/code/context/MappedUserAuthContextUpdateProvider.scala b/obp-api/src/main/scala/code/context/MappedUserAuthContextUpdateProvider.scala index 497f0695db..a95ccbed22 100644 --- a/obp-api/src/main/scala/code/context/MappedUserAuthContextUpdateProvider.scala +++ b/obp-api/src/main/scala/code/context/MappedUserAuthContextUpdateProvider.scala @@ -51,31 +51,31 @@ object MappedUserAuthContextUpdateProvider extends UserAuthContextUpdateProvider override def checkAnswer(consentId: String, challenge: String): Future[Box[MappedUserAuthContextUpdate]] = Future { MappedUserAuthContextUpdate.find(By(MappedUserAuthContextUpdate.mUserAuthContextUpdateId, consentId)) match { - case Full(consent) => - val createDateTime = consent.createdAt.get - val challengeTTL : Long = Helpers.seconds(APIUtil.userAuthContextUpdateRequestChallengeTtl) - val expiredDateTime: Long = createDateTime.getTime+challengeTTL - val currentTime: Long = Platform.currentTime - - if(expiredDateTime > currentTime) - consent.status match { - case value if value == UserAuthContextUpdateStatus.INITIATED.toString => - val status = if (consent.challenge == challenge) UserAuthContextUpdateStatus.ACCEPTED.toString else UserAuthContextUpdateStatus.REJECTED.toString - tryo(consent.mStatus(status).saveMe()) - case _ => - Full(consent) - } - else{ - Failure(s"${ErrorMessages.OneTimePasswordExpired} Current expiration time is ${APIUtil.userAuthContextUpdateRequestChallengeTtl} seconds") - } - case Empty => - Empty ?~! ErrorMessages.UserAuthContextUpdateNotFound - case Failure(msg, _, _) => - Failure(msg) - case _ => - Failure(ErrorMessages.UnknownError) + case Full(consent) => processUacAnswer(consent, challenge, consentId) + case Empty => Empty ?~! ErrorMessages.UserAuthContextUpdateNotFound + case Failure(msg, _, _) => Failure(msg) + case _ => Failure(ErrorMessages.UnknownError) } + } + private def processUacAnswer(consent: MappedUserAuthContextUpdate, challenge: String, consentId: String): Box[MappedUserAuthContextUpdate] = { + val expiredDateTime: Long = consent.createdAt.get.getTime + Helpers.seconds(APIUtil.userAuthContextUpdateRequestChallengeTtl) + if (expiredDateTime <= Platform.currentTime) { + Failure(s"${ErrorMessages.OneTimePasswordExpired} Current expiration time is ${APIUtil.userAuthContextUpdateRequestChallengeTtl} seconds") + } else { + consent.status match { + case value if value == UserAuthContextUpdateStatus.INITIATED.toString => + val status = if (consent.challenge == challenge) UserAuthContextUpdateStatus.ACCEPTED.toString else UserAuthContextUpdateStatus.REJECTED.toString + // Atomic guarded transition: only one concurrent answer may move INITIATED -> status, + // so two correct answers cannot both be accepted (MFA double-authorisation). + val rows = code.bankconnectors.DoobieUserAuthContextUpdateQueries + .conditionalStatusTransition(consent.id.get, UserAuthContextUpdateStatus.INITIATED.toString, status) + if (rows == 1) MappedUserAuthContextUpdate.find(By(MappedUserAuthContextUpdate.mUserAuthContextUpdateId, consentId)) + else Failure("UserAuthContextUpdate status changed concurrently; it is no longer INITIATED.") + case _ => + Full(consent) + } + } } } diff --git a/obp-api/src/main/scala/code/transactionChallenge/MappedChallengeProvider.scala b/obp-api/src/main/scala/code/transactionChallenge/MappedChallengeProvider.scala index 2d6ce838af..9283dc4bdb 100644 --- a/obp-api/src/main/scala/code/transactionChallenge/MappedChallengeProvider.scala +++ b/obp-api/src/main/scala/code/transactionChallenge/MappedChallengeProvider.scala @@ -86,7 +86,15 @@ object MappedChallengeProvider extends ChallengeProvider { userId match { case None => if(currentHashedAnswer==expectedHashedAnswer) { - tryo{challenge.Successful(true).ScaStatus(StrongCustomerAuthenticationStatus.finalised.toString).saveMe()} + { + // Compare-and-set the success flag: only the first correct answer flips + // successful=false -> true. A second concurrent correct answer gets 0 rows and a + // Failure, so one challenge can never green-light a payment twice (MFA double-spend). + val rows = code.bankconnectors.DoobieBusinessStatusQueries + .conditionalChallengeSuccess(challengeId, StrongCustomerAuthenticationStatus.finalised.toString) + if (rows == 1) getChallenge(challengeId) + else Failure(s"${ErrorMessages.InvalidTransactionRequestChallengeId} Challenge already answered.") + } } else { Failure(s"${ s"${ @@ -97,7 +105,15 @@ object MappedChallengeProvider extends ChallengeProvider { } case Some(id) => if(currentHashedAnswer==expectedHashedAnswer && id==challenge.expectedUserId) { - tryo{challenge.Successful(true).ScaStatus(StrongCustomerAuthenticationStatus.finalised.toString).saveMe()} + { + // Compare-and-set the success flag: only the first correct answer flips + // successful=false -> true. A second concurrent correct answer gets 0 rows and a + // Failure, so one challenge can never green-light a payment twice (MFA double-spend). + val rows = code.bankconnectors.DoobieBusinessStatusQueries + .conditionalChallengeSuccess(challengeId, StrongCustomerAuthenticationStatus.finalised.toString) + if (rows == 1) getChallenge(challengeId) + else Failure(s"${ErrorMessages.InvalidTransactionRequestChallengeId} Challenge already answered.") + } } else { Failure(s"${ s"${ diff --git a/obp-api/src/main/scala/code/util/SecureLogging.scala b/obp-api/src/main/scala/code/util/SecureLogging.scala index 522ad2d02b..f3d07ef7ed 100644 --- a/obp-api/src/main/scala/code/util/SecureLogging.scala +++ b/obp-api/src/main/scala/code/util/SecureLogging.scala @@ -131,7 +131,10 @@ object SecureLogging { } // ===== Pattern cache for custom usage ===== - private val customPatternCache: mutable.Map[String, Pattern] = mutable.Map.empty + // Thread-safe: maskWithCustomPattern is called concurrently from many request threads. A plain + // mutable.Map.getOrElseUpdate is not atomic and can corrupt the map during a concurrent resize. + private val customPatternCache: scala.collection.concurrent.Map[String, Pattern] = + scala.collection.concurrent.TrieMap.empty private def getOrCompileCustomPattern(regex: String): Pattern = customPatternCache.getOrElseUpdate(regex, Pattern.compile(regex, Pattern.CASE_INSENSITIVE)) diff --git a/obp-api/src/test/scala/code/concurrency/CONCURRENCY_HAZARDS.md b/obp-api/src/test/scala/code/concurrency/CONCURRENCY_HAZARDS.md index 7d88f9b4d2..89d2384424 100644 --- a/obp-api/src/test/scala/code/concurrency/CONCURRENCY_HAZARDS.md +++ b/obp-api/src/test/scala/code/concurrency/CONCURRENCY_HAZARDS.md @@ -227,3 +227,41 @@ When fixing a confirmed hazard, the corresponding test flips from red to green a | **unique-constraint-unhandled** | Wrap the existing `.saveMe()` in `tryo`; on `Failure`, re-fetch with `find()` and return the existing row | | **check-then-act** (state machine) | Move the status check + flip into a single conditional `UPDATE … WHERE status = 'old'`; check affected-rows count to detect a lost race | | **scheduler stale-save** | Replace unconditional `.save()` with a conditional `UPDATE … WHERE status = 'expected_status'`; skip if 0 rows updated | + +--- + +## Batch 2 — Follow-up Hazards (17 · all fixed) + +A second codebase scan surfaced 17 more hazards (C1, H1–H7, M1–M9), fixed on +`feature/concurrency-hazard-fixes-batch2`. Five suites (tagged `ConcurrencyRace`); red baseline +confirmed before each fix, all green after. + +| ID | Suite | Source | Fix | +|---|---|---|---| +| **C1** | `ConcurrentBulkPaymentRaceTest` | `Http4s700.createTransactionRequestBulk` dropped `claimBatchReference`'s Box | Claim before fan-out; `unboxFullOrFail` → 409 (provider guard already sound — C1a/C1b are guard-verification) | +| **H1** | `ConcurrentConsentStatusRaceTest` | `MappedConsentProvider.checkAnswer` TOCTOU | conditional `UPDATE … WHERE id=? AND mstatus='INITIATED'` (`DoobieConsentStatusQueries`) | +| **H2** | ″ | `MappedUserAuthContextUpdateProvider.checkAnswer` TOCTOU | conditional UPDATE (`DoobieUserAuthContextUpdateQueries`) | +| **H3** | ″ | `MappedConsentProvider.revoke` in-memory guard | conditional `UPDATE … WHERE mstatus<>'REVOKED'` | +| **M5** | ″ | `Http4s310` skip-SCA unconditional accept | conditional `UPDATE … WHERE mstatus='INITIATED'` | +| **H4** | `ConcurrentRateLimiterRaceTest` | `RateLimitingUtil` check-then-increment gap | atomic Lua `Redis.incrementWithTtl` (INCR + create-TTL) | +| **M6** | ″ | `IdempotencyMiddleware.writeResponseKey` used `setex` (overwrite) | `Redis.setNxEx` (first-write-wins) | +| **M7** | ″ | `IdempotencyMiddleware.tryAcquireLock` setnx + separate expire | `Redis.setNxEx` (value+TTL atomic) | +| **H5** | `ConcurrentMutableSingletonRaceTest` | `DynamicConnector.singletonObjectMap` mutable.Map | `TrieMap` | +| **H7** | ″ | `SecureLogging.customPatternCache` mutable.Map | `TrieMap` | +| **M8** | ″ | `APIUtil.connectorToEndpoint` mutable.Map | `TrieMap` (structural reflection test) | +| **H6** | ″ | `ObpLookupSystem.obpLookupSystem` unguarded var | `@volatile` + synchronized init (structural reflection test) | +| **M9** | ″ | `ObpActorSystem` actor-system vars | `@volatile` + synchronized init (structural reflection test) | +| **M2** | `ConcurrentBusinessStatusRaceTest` | `AccountAccessRequest.updateStatus` no terminal guard | conditional `UPDATE … WHERE status='INITIATED'` (`DoobieBusinessStatusQueries`) | +| **M3** | ″ | `MappedAccountApplication.updateStatus` in-memory ACCEPTED guard | optimistic CAS `UPDATE … WHERE mstatus=` | +| **M4** | ″ | `MappedChallengeProvider.validateChallenge` non-CAS success flip | CAS `UPDATE … SET successful_c=true WHERE challengeid=? AND successful_c=false` | + +**M1** (`Http4s510.updateTransactionRequestStatus` lacked the row lock that `Http4s400` has) is fixed +at the endpoint: it now calls `DoobieTransactionRequestQueries.lockTransactionRequest` within the +request transaction. It has **no provider-level standalone test** — the `FOR UPDATE` lock only spans a +read-modify-write when it runs on the request-scoped connection (`RequestScopeConnection`); a barrier +test outside request scope uses the fallback transactor, which commits the lock SELECT immediately and +cannot serialise a separate save. (Same "verified-real without standalone test" category as Q/T/V/X/Y.) + +> Lift→raw-SQL column gotcha hit here: `MappedBoolean` maps the `Successful` field to column +> **`successful_c`** (Lift appends `_c`), not `successful`. Get column names from +> `.mappedFields.map(_.dbColumnName)` when unsure. diff --git a/obp-api/src/test/scala/code/concurrency/ConcurrentBulkPaymentRaceTest.scala b/obp-api/src/test/scala/code/concurrency/ConcurrentBulkPaymentRaceTest.scala new file mode 100644 index 0000000000..7e895240ca --- /dev/null +++ b/obp-api/src/test/scala/code/concurrency/ConcurrentBulkPaymentRaceTest.scala @@ -0,0 +1,142 @@ +/** +Open Bank Project - API +Copyright (C) 2011-2019, TESOBE GmbH. + +This program is free software: you can redistribute it and/or modify +it under the terms of the GNU Affero General Public License as published by +the Free Software Foundation, either version 3 of the License, or +(at your option) any later version. + +This program is distributed in the hope that it will be useful, +but WITHOUT ANY WARRANTY; without even the implied warranty of +MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +GNU Affero General Public License for more details. + +You should have received a copy of the GNU Affero General Public License +along with this program, if not, see . + +Email: contact@tesobe.com +TESOBE GmbH. +Osloer Strasse 16/17 +Berlin 13359, Germany + +This product includes software developed at +TESOBE (http://www.tesobe.com/) + + */ +package code.concurrency + +import code.bulkpayment.{BulkBatchReference, MappedBulkPaymentProvider} +import net.liftweb.common.{Failure, Full} +import net.liftweb.mapper.By + +import java.util.UUID + +/** + * C1: BulkPayment batch-reference check-then-claim race. + * + * THE HAZARD: + * BulkPaymentHandler.validateEnvelope calls isBatchReferenceUsed (a SELECT), and only if the + * reference is absent does the handler proceed to create the TransactionRequest and fan-out + * the payment legs. After the payments are created, Http4s700 calls claimBatchReference + * (an INSERT guarded by UniqueIndex(FromBankId, FromAccountId, BatchReference)). + * + * The race window is between the SELECT in isBatchReferenceUsed and the INSERT in + * claimBatchReference. Two concurrent requests with the same (bankId, accountId, batchRef) + * both pass the SELECT, both build and persist the TransactionRequest, then race to INSERT. + * The losing INSERT hits the UniqueIndex and returns a Failure Box — but in Http4s700.scala + * the result of claimBatchReference is dropped inside a bare Future { claimBatchReference(...) } + * with no unboxFullOrFail check, so the second request silently continues and double-charges. + * + * WHAT THIS TEST SHOWS (guard-verification — both scenarios pass): + * The provider layer is already sound: claimBatchReference wraps saveMe in tryo and the + * UniqueIndex(FromBankId, FromAccountId, BatchReference) makes the duplicate INSERT fail, so the + * losing caller receives a Failure (C1a) and exactly one row survives (C1b). These two scenarios + * prove the *signal* exists for the call site to act on. + * + * The actual bug was at the call site: Http4s700.createTransactionRequestBulk ran + * `Future { claimBatchReference(...) }` and DROPPED the Box, so the losing request silently fanned + * out a duplicate payment. The fix (this PR) claims the batch_reference BEFORE creating the parent + * TR or fanning out, and surfaces the Failure with unboxFullOrFail (409) so the loser aborts early. + * The concurrent-duplicate HTTP path is additionally covered by the sequential 409-reuse scenario + * in Http4s700RoutesTest ("Return 409 when batch_reference is reused on the same source account"). + * + * Tagged ConcurrencyRace. + */ +class ConcurrentBulkPaymentRaceTest extends ConcurrentRaceSetup { + + private val provider = MappedBulkPaymentProvider + + feature("BulkPayment batch-reference idempotency guard") { + + scenario("C1a: claimBatchReference must return Failure when the reference already exists (DB constraint works)", ConcurrencyRace) { + Given("a batch-reference row already exists for (bank, account, ref)") + val bankId = "__conc_bulk_bank_" + UUID.randomUUID.toString.take(8) + val accountId = "__conc_bulk_acc_" + UUID.randomUUID.toString.take(8) + val batchRef = "__conc_bulk_ref_" + UUID.randomUUID.toString.take(8) + val trId1 = UUID.randomUUID.toString + val trId2 = UUID.randomUUID.toString + + val first = provider.claimBatchReference(bankId, accountId, batchRef, trId1) + + When("a second claimBatchReference is attempted with the same (bank, account, ref)") + val second = provider.claimBatchReference(bankId, accountId, batchRef, trId2) + + Then("the second call must return a Failure — the UniqueIndex prevents duplicate claims") + withClue( + s"first=$first second=$second: the UniqueIndex on (FromBankId, FromAccountId, BatchReference) " + + s"should cause the second INSERT to fail — " + ) { + first shouldBe a [Full[_]] + second shouldBe a [Failure] + } + } + + scenario("C1b: concurrent isBatchReferenceUsed + claimBatchReference must not silently allow both to proceed", ConcurrencyRace) { + Given("no existing BulkBatchReference row for a fresh (bank, account, batchRef)") + val bankId = "__conc_bulk2_bank_" + UUID.randomUUID.toString.take(8) + val accountId = "__conc_bulk2_acc_" + UUID.randomUUID.toString.take(8) + val batchRef = "__conc_bulk2_ref_" + UUID.randomUUID.toString.take(8) + val n = 2 + + def rowCount: Long = BulkBatchReference.count( + By(BulkBatchReference.FromBankId, bankId), + By(BulkBatchReference.FromAccountId, accountId), + By(BulkBatchReference.BatchReference, batchRef) + ) + + When(s"$n threads concurrently check isBatchReferenceUsed then call claimBatchReference") + // This reproduces the check-then-act window: + // Thread A: isBatchReferenceUsed → false (passes guard) + // Thread B: isBatchReferenceUsed → false (passes guard — A hasn't committed yet) + // Thread A: claimBatchReference → Full (INSERT succeeds) + // Thread B: claimBatchReference → Failure (UniqueIndex violation) + // Bug: Http4s700 wraps claimBatchReference in Future { ... } without checking the Box, + // so Thread B's Failure is silently dropped and the duplicate payment proceeds. + val results = runConcurrentWithBarrier(n) { i => + val alreadyUsed = provider.isBatchReferenceUsed(bankId, accountId, batchRef) + if (!alreadyUsed) { + provider.claimBatchReference(bankId, accountId, batchRef, UUID.randomUUID.toString) + } else { + Failure("reference already used — correctly rejected before INSERT") + } + } + + Then("exactly one claim must succeed; the other must return Failure (not be silently swallowed)") + val successes = results.collect { case scala.util.Success(Full(_)) => "ok" } + val failures = results.collect { case scala.util.Success(f: Failure) => f.msg } + val rows = rowCount + withClue( + s"successes=${successes.size} failures=${failures.size} dbRows=$rows: " + + s"both threads passed isBatchReferenceUsed because neither had committed yet — " + + s"the second claimBatchReference hit UniqueIndex and returned Failure, but in " + + s"Http4s700 this Failure is dropped inside Future { claimBatchReference(...) } " + + s"with no unboxFullOrFail — the duplicate payment request silently proceeds — " + ) { + rows should equal(1L) + successes should have size 1 + failures should have size (n - 1) + } + } + } +} diff --git a/obp-api/src/test/scala/code/concurrency/ConcurrentBusinessStatusRaceTest.scala b/obp-api/src/test/scala/code/concurrency/ConcurrentBusinessStatusRaceTest.scala new file mode 100644 index 0000000000..16605c28ba --- /dev/null +++ b/obp-api/src/test/scala/code/concurrency/ConcurrentBusinessStatusRaceTest.scala @@ -0,0 +1,184 @@ +package code.concurrency + +import code.accountaccessrequest.{AccountAccessRequest, MappedAccountAccessRequestProvider} +import code.accountapplication.{MappedAccountApplication, MappedAccountApplicationProvider} +import code.transactionChallenge.MappedChallengeProvider +import com.openbankproject.commons.model.enums.AccountAccessRequestStatus +import com.openbankproject.commons.model.ProductCode +import net.liftweb.common.{Failure, Full} +import net.liftweb.mapper.By +import org.mindrot.jbcrypt.BCrypt + +import java.util.UUID +import scala.concurrent.Await +import scala.concurrent.duration._ + +/** + * M1: Scheduler-path updateTransactionRequestStatus bypasses lockTransactionRequest (structural). + * M2: AccountAccessRequest.updateStatus — no terminal state guard (unconditional find+saveMe). + * M3: MappedAccountApplication.updateStatus — ACCEPTED guard is an in-memory check only. + * + * M1 (structural, not reproduced by concurrent test): + * Http4s400's challenge-answer path calls DoobieTransactionRequestQueries.lockTransactionRequest + * before processing payment — this acquires a DB-level row lock, making the INITIATED→COMPLETED + * transition atomic. BUT Http4s510's updateTransactionRequestStatus endpoint calls + * MappedTransactionRequestProvider.updateTransactionRequestStatus which does a plain + * find+mStatus(status).saveMe() with no lock. A concurrent scheduler call racing a challenge- + * answer can overwrite COMPLETED with a stale status, reversing a completed payment. + * + * M2 (testable): + * AccountAccessRequest.updateStatus does `AccountAccessRequest.find(…).flatMap { r => tryo { r.Status(status).saveMe() } }`. + * There is NO terminal-state guard — an already-APPROVED request can be flipped to DECLINED (or + * vice versa) by a concurrent or later admin action. This is a last-writer-wins race with no + * idempotency protection. + * + * M3 (testable): + * MappedAccountApplicationProvider.updateStatus checks `if accountApplication.status == "ACCEPTED" + * → Failure` as a guard against re-processing ACCEPTED applications. But the guard reads status + * from the in-memory object loaded by the find() call that precedes the check. Two concurrent + * calls, one wanting ACCEPTED and one wanting REJECTED, both load status="REQUESTED", both pass + * the guard, and both write — the last one wins non-deterministically. A legitimate ACCEPTED + * transition can be overwritten by a concurrent REJECTED. + * + * EXPECTED TO FAIL (M2, M3) until a conditional UPDATE WHERE status='' is used. + * Tagged ConcurrencyRace. + */ +class ConcurrentBusinessStatusRaceTest extends ConcurrentRaceSetup { + + feature("Business-object status transitions must be atomic") { + + scenario("M2: concurrent approve and decline of the same AccountAccessRequest must not both succeed", ConcurrencyRace) { + Given("an AccountAccessRequest in INITIATED state") + val requestId = UUID.randomUUID.toString + AccountAccessRequest.create + .AccountAccessRequestId(requestId) + .BankId("__conc_m2_bank") + .AccountId("__conc_m2_acc") + .ViewId("owner") + .IsSystemView(false) + .RequestorUserId(resourceUser1.userId) + .TargetUserId(resourceUser2.userId) + .BusinessJustification("concurrency test") + .Status(AccountAccessRequestStatus.INITIATED.toString) + .CheckerUserId("") + .CheckerComment("") + .saveMe() + + When("two threads concurrently update the request — one to APPROVED, one to DECLINED") + val n = 2 + val results = runConcurrentWithBarrier(n) { i => + val newStatus = if (i == 0) "APPROVED" else "DECLINED" + MappedAccountAccessRequestProvider.updateStatus(requestId, newStatus, resourceUser1.userId, "concurrent-test") + } + + val finalStatus = AccountAccessRequest + .find(By(AccountAccessRequest.AccountAccessRequestId, requestId)) + .map(_.Status.get).getOrElse("missing") + + Then("the final status must be a deterministic terminal value, not an overwritten intermediate") + withClue( + s"finalStatus=$finalStatus results=${results.map(_.isSuccess)}: " + + s"AccountAccessRequest.updateStatus does unconditional find+saveMe with no terminal-state " + + s"guard — concurrent APPROVED/DECLINED calls both succeed; the last writer silently wins, " + + s"meaning a legitimate APPROVED decision can be overwritten by a racing DECLINED — " + ) { + // The test currently FAILS because both calls return Full and the final status is + // non-deterministic. After the fix (conditional UPDATE WHERE status='INITIATED'), + // exactly one must succeed and the other must return a Failure. + val successes = results.collect { case scala.util.Success(Full(_)) => 1 } + successes should have size 1 + } + } + + scenario("M3: concurrent ACCEPTED and REJECTED transitions to the same AccountApplication must not both proceed", ConcurrencyRace) { + Given("an AccountApplication in REQUESTED state") + val appId = UUID.randomUUID.toString + MappedAccountApplication.create + .mAccountApplicationId(appId) + .mCode(ProductCode("__conc_m3_product").value) + .mUserId(resourceUser1.userId) + .mCustomerId(UUID.randomUUID.toString) + .mStatus("REQUESTED") + .saveMe() + + When("Thread A wants to ACCEPT and Thread B wants to REJECT — both race") + // Both load status="REQUESTED" before either commits. + // The memory guard `if status == "ACCEPTED" → Failure` does NOT fire for either thread, + // because both loaded "REQUESTED" — neither has committed ACCEPTED yet. + // Thread A writes ACCEPTED, Thread B writes REJECTED; one overwrites the other. + val n = 2 + val results = runConcurrentWithBarrier(n) { i => + val newStatus = if (i == 0) "ACCEPTED" else "REJECTED" + Await.result(MappedAccountApplicationProvider.updateStatus(appId, newStatus), 10.seconds) + } + + val finalStatus = MappedAccountApplication + .find(By(MappedAccountApplication.mAccountApplicationId, appId)) + .map(_.status).getOrElse("missing") + + Then("exactly one transition must succeed — concurrent ACCEPTED+REJECTED must not both write") + withClue( + s"finalStatus=$finalStatus results=${results.map(_.isSuccess)}: " + + s"MappedAccountApplicationProvider.updateStatus checks `if status == ACCEPTED → Failure` on " + + s"the in-memory loaded object, not in the DB — both threads load REQUESTED, both pass the " + + s"guard, and both write; the ACCEPTED→REJECTED overwrite is silent and undetected — " + ) { + val successes = results.collect { case scala.util.Success(Full(_)) => 1 } + successes should have size 1 + } + } + + // M1 (Http4s510 updateTransactionRequestStatus lacks the row lock that Http4s400 has) is fixed at + // the endpoint: it now calls DoobieTransactionRequestQueries.lockTransactionRequest within the + // request transaction. It has no provider-level reproduction here because the FOR UPDATE lock only + // spans a read-modify-write when it runs on the request-scoped connection (RequestScopeConnection); + // a barrier test outside request scope uses the fallback transactor, which commits the lock SELECT + // immediately and cannot serialise a separate save. Documented in CONCURRENCY_HAZARDS.md. + + scenario("M4: concurrent correct challenge answers must flip Successful exactly once — no MFA double-spend", ConcurrencyRace) { + Given("a transaction-request challenge seeded with a known correct answer") + // Raise the attempt limit so the limit-guard never short-circuits the success path. + setPropsValues("transactionRequests_challenge_max_allowed_attempts" -> "100") + val challengeId = UUID.randomUUID.toString + val salt = BCrypt.gensalt() + MappedChallengeProvider.saveChallenge( + challengeId = challengeId, + transactionRequestId = UUID.randomUUID.toString, + salt = salt, + expectedAnswer = BCrypt.hashpw("123", salt).substring(0, 44), + expectedUserId = resourceUser1.userId, + scaMethod = None, + scaStatus = None, + consentId = None, + basketId = None, + authenticationMethodId = None, + challengeType = "OBP_TRANSACTION_REQUEST_CHALLENGE" + ) + val n = 2 + + When(s"$n threads concurrently submit the CORRECT answer to the same challenge") + // validateChallenge does: in-memory hash check, then challenge.Successful(true).ScaStatus(finalised).saveMe(). + // The success flip is not a compare-and-set: both correct answers pass the check and both flip + // Successful=true, so both callers are told the SCA succeeded → the payment can execute twice. + val results = runConcurrentWithBarrier(n) { _ => + MappedChallengeProvider.validateChallenge( + challengeId = challengeId, + challengeAnswer = "123", + userId = Some(resourceUser1.userId) + ) + } + + Then("exactly one validate may succeed — the second must be rejected (challenge already answered)") + val successes = results.collect { case scala.util.Success(Full(_)) => 1 } + withClue( + s"successes=${successes.size} results=${results.map(_.isSuccess)}: " + + s"validateChallenge flips Successful(true) via a plain saveMe after an in-memory hash check — " + + s"two correct concurrent answers both flip it and both return Full, green-lighting the payment " + + s"twice. Fix: conditional UPDATE successful=true WHERE successful=false (CAS); the loser gets " + + s"0 rows → Failure — " + ) { + successes should have size 1 + } + } + } +} diff --git a/obp-api/src/test/scala/code/concurrency/ConcurrentConsentStatusRaceTest.scala b/obp-api/src/test/scala/code/concurrency/ConcurrentConsentStatusRaceTest.scala new file mode 100644 index 0000000000..b4702d9a59 --- /dev/null +++ b/obp-api/src/test/scala/code/concurrency/ConcurrentConsentStatusRaceTest.scala @@ -0,0 +1,174 @@ +package code.concurrency + +import code.consent.{ConsentStatus, MappedConsent, MappedConsentProvider} +import code.context.{MappedUserAuthContextUpdate, MappedUserAuthContextUpdateProvider} +import net.liftweb.common.Full +import net.liftweb.mapper.By +import org.mindrot.jbcrypt.BCrypt + +import java.util.{Date, UUID} +import scala.concurrent.Await +import scala.concurrent.duration._ + +/** + * H1: MappedConsent.checkAnswer TOCTOU race. + * H2: MappedUserAuthContextUpdate.checkAnswer TOCTOU race. + * H3: MappedConsent.revoke vs concurrent checkAnswer race. + * + * THE HAZARD (all three share the same root cause): + * The status check ("is this consent INITIATED?") and the status write ("flip to ACCEPTED/REJECTED/REVOKED") + * are two separate SQL operations with no SELECT FOR UPDATE or conditional UPDATE between them. + * Two concurrent requests can both read INITIATED, both pass the guard, and both write a new status. + * + * H1 / H2: Two concurrent correct answers → both callers get Full(consent_ACCEPTED) and proceed + * as if they independently answered a challenge. In a real SCA flow this means a single + * consent is double-authorised — both callers proceed past the challenge gate. + * + * H3: A revoke call and a checkAnswer call race. The revoker writes REVOKED; the answerer loaded + * a stale INITIATED object and writes ACCEPTED on top, resurrecting the revoked consent. + * + * EXPECTED TO FAIL (all three) until a conditional UPDATE WHERE status='INITIATED' is used. + * Tagged ConcurrencyRace. + */ +class ConcurrentConsentStatusRaceTest extends ConcurrentRaceSetup { + + private def mkConsent(answer: String): (String, String) = { + val salt = BCrypt.gensalt() + val hashed = BCrypt.hashpw(answer, salt).substring(0, 44) + val consentId = UUID.randomUUID.toString + MappedConsent.create + .mConsentId(consentId) + .mStatus(ConsentStatus.INITIATED.toString) + .mChallenge(hashed) + .mSalt(salt) + .saveMe() + (consentId, answer) + } + + private def mkUserAuthContextUpdate(answer: String): String = { + val id = UUID.randomUUID.toString + MappedUserAuthContextUpdate.create + .mUserAuthContextUpdateId(id) + .mUserId(resourceUser1.userId) + .mConsumerId("__conc_consumer") + .mKey("__conc_key") + .mValue("__conc_value") + .mChallenge(answer) + .mStatus(com.openbankproject.commons.model.UserAuthContextUpdateStatus.INITIATED.toString) + .saveMe() + id + } + + private def consentStatus(consentId: String): String = + MappedConsent.find(By(MappedConsent.mConsentId, consentId)) + .map(_.status).getOrElse("missing") + + private def uacStatus(id: String): String = + MappedUserAuthContextUpdate.find(By(MappedUserAuthContextUpdate.mUserAuthContextUpdateId, id)) + .map(_.status).getOrElse("missing") + + feature("Consent and UserAuthContextUpdate status transitions must be atomic") { + + scenario("H1: two concurrent correct answers to the same consent must not both succeed", ConcurrencyRace) { + Given("a consent in INITIATED state with a known challenge answer") + val (consentId, answer) = mkConsent("test-answer-h1") + + When("2 threads concurrently submit the correct answer") + // Both threads load INITIATED, both pass the guard, both write ACCEPTED. + // The hazard is that both return Full — two callers get the green light. + val results = runConcurrentWithBarrier(2) { _ => + MappedConsentProvider.checkAnswer(consentId, answer) + } + + Then("exactly one call should succeed; the other must get a non-INITIATED rejection") + val successes = results.collect { case scala.util.Success(Full(_)) => 1 } + val finalSt = consentStatus(consentId) + withClue( + s"successes=${successes.size} finalStatus=$finalSt: " + + s"MappedConsent.checkAnswer reads status and writes new status as two separate SQL operations " + + s"with no SELECT FOR UPDATE — both threads pass the INITIATED guard before either commits, " + + s"both get Full(ACCEPTED) and proceed through the SCA gate — " + ) { + successes should have size 1 + finalSt should equal(ConsentStatus.ACCEPTED.toString) + } + } + + scenario("H2: two concurrent correct answers to the same UserAuthContextUpdate must not both succeed", ConcurrencyRace) { + Given("a UserAuthContextUpdate in INITIATED state with known plain-text challenge") + // mChallenge is VARCHAR(10) — keep the answer within the column limit. + val answer = "h2ans" + val updateId = mkUserAuthContextUpdate(answer) + + When("2 threads concurrently submit the correct challenge") + val results = runConcurrentWithBarrier(2) { _ => + Await.result(MappedUserAuthContextUpdateProvider.checkAnswer(updateId, answer), 10.seconds) + } + + Then("exactly one must succeed; the race must not allow double-authorisation") + val successes = results.collect { case scala.util.Success(Full(_)) => 1 } + val finalSt = uacStatus(updateId) + withClue( + s"successes=${successes.size} finalStatus=$finalSt: " + + s"MappedUserAuthContextUpdateProvider.checkAnswer checks status then writes status in two " + + s"separate SQL operations — both threads see INITIATED and both write ACCEPTED — " + ) { + successes should have size 1 + finalSt should equal(com.openbankproject.commons.model.UserAuthContextUpdateStatus.ACCEPTED.toString) + } + } + + scenario("H3: a concurrent revoke must not be overwritten by a racing checkAnswer", ConcurrencyRace) { + Given("a consent in INITIATED state") + val (consentId, answer) = mkConsent("test-answer-h3") + val n = 2 + + When("one thread revokes the consent while another concurrently answers the challenge correctly") + // Thread 0 revokes; Thread 1 answers. Both load the consent before either commits. + // The answerer holds a stale INITIATED object and writes ACCEPTED after the revoker commits REVOKED. + val results = runConcurrentWithBarrier(n) { i => + if (i == 0) MappedConsentProvider.revoke(consentId) + else MappedConsentProvider.checkAnswer(consentId, answer) + } + + Then("the final status must be REVOKED — a revocation must survive a concurrent answer") + val finalSt = consentStatus(consentId) + withClue( + s"finalStatus=$finalSt results=${results.map(_.isSuccess)}: " + + s"revoke() and checkAnswer() both do find-then-saveMe with no conditional UPDATE guard; " + + s"the answerer's write of ACCEPTED can land after the revoker's REVOKED commit, " + + s"resurrecting a consent the user explicitly revoked — " + ) { + finalSt should equal(ConsentStatus.REVOKED.toString) + } + } + + scenario("M5: the skip-SCA accept-write must not overwrite a concurrent revoke (shouldSkipConsentSca)", ConcurrencyRace) { + Given("a consent in INITIATED state (just created, SCA about to be skipped)") + val (consentId, _) = mkConsent("m5-unused-answer") + val n = 2 + + When("one thread runs the skip-SCA accept-write while another concurrently revokes the consent") + val results = runConcurrentWithBarrier(n) { i => + if (i == 0) { + // Fixed production path in Http4s310: conditional UPDATE WHERE mstatus='INITIATED'. + // If the consent was already revoked, this is a 0-row no-op and the revoke stands. + MappedConsent.find(By(MappedConsent.mConsentId, consentId)) + .map(c => code.bankconnectors.DoobieConsentStatusQueries + .conditionalStatusTransition(c.id.get, ConsentStatus.INITIATED.toString, ConsentStatus.ACCEPTED.toString)) + } else { + MappedConsentProvider.revoke(consentId) + } + } + + Then("the final status must be REVOKED — an explicit revoke must win over an auto-accept") + val finalSt = consentStatus(consentId) + withClue( + s"finalStatus=$finalSt results=${results.map(_.isSuccess)}: " + + s"conditional UPDATE WHERE mstatus='INITIATED' must be a no-op when revoke lands first — " + ) { + finalSt should equal(ConsentStatus.REVOKED.toString) + } + } + } +} diff --git a/obp-api/src/test/scala/code/concurrency/ConcurrentMutableSingletonRaceTest.scala b/obp-api/src/test/scala/code/concurrency/ConcurrentMutableSingletonRaceTest.scala new file mode 100644 index 0000000000..fcb3fbef00 --- /dev/null +++ b/obp-api/src/test/scala/code/concurrency/ConcurrentMutableSingletonRaceTest.scala @@ -0,0 +1,178 @@ +package code.concurrency + +import code.actorsystem.{ObpActorSystem, ObpLookupSystem} +import code.api.util.APIUtil +import code.bankconnectors.DynamicConnector +import code.util.SecureLogging + +import java.lang.reflect.Modifier +import java.util.UUID + +/** + * H5: DynamicConnector.singletonObjectMap — unsynchronised mutable.Map. + * H7: SecureLogging.customPatternCache — unsynchronised mutable.Map.getOrElseUpdate. + * M8: APIUtil.connectorToEndpoint — mutable.Map written only at startup (structural note). + * M9: ObpActorSystem.northSideAkkaConnectorActorSystem — bare `var` (structural note). + * + * THE HAZARD: + * H5 / H7 share the same root cause: both use scala.collection.mutable.Map, whose resize, + * rehash, and getOrElseUpdate operations are NOT thread-safe. Concurrent mutations can cause: + * - Lost writes (two threads both insert at the same hash bucket; one insert is dropped) + * - HashMap corruption (infinite loop during resize on concurrent structural modification) + * - NPE / ClassCastException from reading partially-written internal state + * + * H5 (DynamicConnector.singletonObjectMap): + * `createSingletonObject` calls `singletonObjectMap.put(key, value)` with no synchronisation. + * In mapped-connector mode, multiple DynamicConnector calls from concurrent HTTP requests can + * race on this map, corrupting the object registry or silently dropping a registration. + * + * H7 (SecureLogging.customPatternCache): + * `maskWithCustomPattern` calls `customPatternCache.getOrElseUpdate(regex, compile(regex))`. + * `getOrElseUpdate` on a mutable.Map is non-atomic: it reads the map, misses, compiles the + * Pattern, then puts it — two concurrent compilers of the same regex both compile and both + * put, and the resulting double-put of a (String → Pattern) entry can tear the HashMap's + * internal chain structure. + * + * M8 (APIUtil.connectorToEndpoint): a mutable.Map populated at startup by addEndpointInfos. + * Startup runs single-threaded, so the write window is narrow, but if two Boot threads ever + * race (e.g. lazy-init re-entrance), the map can be corrupted. + * + * M9 (ObpActorSystem.northSideAkkaConnectorActorSystem): a bare `var` assigned once without + * `@volatile`. JVM memory model does not guarantee visibility of a non-volatile write to + * another thread; a reader spinning on Boot startup can see a stale null. + * + * EXPECTED TO FAIL (H5, H7) under high concurrency until the maps are replaced with + * ConcurrentHashMap or wrapped in synchronised blocks. M8 and M9 are startup-only structural + * hazards — no failing assertion possible in a live server test. + * Tagged ConcurrencyRace. + */ +class ConcurrentMutableSingletonRaceTest extends ConcurrentRaceSetup { + + feature("Mutable singleton maps must be thread-safe") { + + scenario("H5: concurrent createSingletonObject calls must not lose writes or corrupt DynamicConnector.singletonObjectMap", ConcurrencyRace) { + Given("a set of unique keys to be registered concurrently in DynamicConnector.singletonObjectMap") + val n = 50 + val keys = (1 to n).map(i => s"__conc_h5_key_${i}_${UUID.randomUUID.toString.take(6)}") + + When(s"$n threads concurrently call createSingletonObject, one key per thread") + val results = runConcurrentWithBarrier(n) { i => + DynamicConnector.createSingletonObject(keys(i), s"value_$i") + } + + Then("every key must be retrievable from the map — no writes may be lost") + val missing = keys.filter(k => DynamicConnector.getSingletonObject(k).isEmpty) + withClue( + s"missing=${missing.size}/$n keys after concurrent createSingletonObject: " + + s"scala.collection.mutable.Map.put is not thread-safe — concurrent structural modifications " + + s"during a resize can silently drop entries or corrupt the HashMap — " + ) { + missing shouldBe empty + } + } + + scenario("H7: concurrent maskWithCustomPattern calls must not corrupt SecureLogging.customPatternCache", ConcurrencyRace) { + Given("a set of distinct regex patterns to be compiled and cached concurrently") + val n = 30 + val patterns = (1 to n).map(i => s"conc_h7_pattern_${i}_[a-z]+") + val input = "hello world conc_h7_pattern_1_abc" + + When(s"$n threads concurrently call maskWithCustomPattern with different patterns") + val results = runConcurrentWithBarrier(n) { i => + scala.util.Try { + SecureLogging.maskWithCustomPattern(patterns(i), "***", input) + } + } + + Then("no call must throw — customPatternCache.getOrElseUpdate must not corrupt the HashMap") + val failures = results.collect { + case scala.util.Failure(e) => s"${e.getClass.getSimpleName}: ${e.getMessage.take(80)}" + } + withClue( + s"failures=$failures: " + + s"SecureLogging.customPatternCache uses scala.collection.mutable.Map.getOrElseUpdate, which " + + s"is not thread-safe — concurrent compilations of different patterns can cause HashMap " + + s"corruption (NPE, ClassCastException, or infinite loop during resize) — " + ) { + failures shouldBe empty + } + } + + scenario("H7b: the same pattern compiled concurrently must not corrupt the cache", ConcurrencyRace) { + Given("a single regex pattern that n threads will all compile into customPatternCache simultaneously") + val n = 30 + val pattern = s"conc_h7b_${UUID.randomUUID.toString.take(8)}_[0-9]+" + val input = "some text 1234" + + When(s"$n threads concurrently call maskWithCustomPattern with the same new pattern") + val results = runConcurrentWithBarrier(n) { _ => + scala.util.Try { SecureLogging.maskWithCustomPattern(pattern, "***", input) } + } + + Then("no call must throw — double-insert of the same (regex → Pattern) must be idempotent") + val failures = results.collect { + case scala.util.Failure(e) => s"${e.getClass.getSimpleName}: ${e.getMessage.take(80)}" + } + withClue( + s"failures=$failures: concurrent getOrElseUpdate for the same key: both threads miss, both " + + s"compile, both call put — the double-put can tear the HashMap's bucket chain — " + ) { + failures shouldBe empty + } + } + + // ── Structural hardening tests (H6, M8, M9) ────────────────────────────── + // These are init-time vars / maps, not request-path data races, so a failing concurrent test + // can't reliably reproduce them. Instead we assert the hardening primitive is in place: + // - M8: connectorToEndpoint must be a thread-safe concurrent Map (TrieMap), not a plain HashMap. + // - H6/M9: the actor-system vars must be @volatile so a write is visible across threads. + // RED until the fix lands; GREEN once the primitive is present. + + def fieldIsVolatile(holder: AnyRef, fieldName: String): Boolean = { + val f = holder.getClass.getDeclaredField(fieldName) + Modifier.isVolatile(f.getModifiers) + } + + scenario("M8: APIUtil.connectorToEndpoint must be a thread-safe concurrent map", ConcurrencyRace) { + Given("APIUtil.connectorToEndpoint, populated at startup and read on the resource-docs path") + When("inspecting its concrete type") + val isConcurrent = APIUtil.connectorToEndpoint.isInstanceOf[scala.collection.concurrent.Map[_, _]] + Then("it must be a scala.collection.concurrent.Map (e.g. TrieMap), not a plain mutable.HashMap") + withClue( + s"connectorToEndpoint runtimeClass=${APIUtil.connectorToEndpoint.getClass.getName}: " + + s"a plain mutable.Map is not safe for concurrent put/getOrElse during startup re-entrance. " + + s"Fix: scala.collection.concurrent.TrieMap (same Map API, lock-free, thread-safe) — " + ) { + isConcurrent shouldBe true + } + } + + scenario("H6: ObpLookupSystem.obpLookupSystem must be @volatile (visible across threads)", ConcurrencyRace) { + Given("the lazily-initialised actor-system holder var") + When("inspecting the field modifiers") + val volatileField = fieldIsVolatile(ObpLookupSystem, "obpLookupSystem") + Then("the field must be volatile so the double-checked init publishes safely") + withClue( + "ObpLookupSystem.init() does `if (obpLookupSystem == null) { ...; obpLookupSystem = system }` " + + "with no @volatile and no synchronized — two threads can both see null, both build an ActorSystem, " + + "and a reader can see a stale null. Fix: @volatile var + synchronized init — " + ) { + volatileField shouldBe true + } + } + + scenario("M9: ObpActorSystem.northSideAkkaConnectorActorSystem must be @volatile", ConcurrencyRace) { + Given("the north-side Akka connector actor-system var") + When("inspecting the field modifiers") + val volatileField = fieldIsVolatile(ObpActorSystem, "northSideAkkaConnectorActorSystem") + Then("the field must be volatile so its single assignment is visible to all readers") + withClue( + "ObpActorSystem.northSideAkkaConnectorActorSystem is a bare `var ... = _` assigned once without " + + "@volatile — the JVM memory model does not guarantee a reader sees the assignment. " + + "Fix: @volatile var + synchronized start — " + ) { + volatileField shouldBe true + } + } + } +} diff --git a/obp-api/src/test/scala/code/concurrency/ConcurrentRateLimiterRaceTest.scala b/obp-api/src/test/scala/code/concurrency/ConcurrentRateLimiterRaceTest.scala new file mode 100644 index 0000000000..1f59dee045 --- /dev/null +++ b/obp-api/src/test/scala/code/concurrency/ConcurrentRateLimiterRaceTest.scala @@ -0,0 +1,115 @@ +package code.concurrency + +import code.api.JedisMethod +import code.api.cache.Redis + +import java.util.UUID +import java.util.concurrent.atomic.AtomicInteger + +/** + * H4: Rate-limit check-then-increment race (RateLimitingUtil). + * M6: Idempotency response cache uses `setex` (overwrite) instead of `SET NX EX` (first-wins). + * M7: Idempotency lock uses `setnx` + separate `expire` — non-atomic; crash between the two + * leaves a key with no TTL, permanently blocking retries. + * + * WHY THESE REPRODUCE AT THE Redis-PRIMITIVE LEVEL: + * The contended methods are not reachable from this package: + * - RateLimitingUtil.incrementCounter / underConsumerLimits are private / private[util] + * - IdempotencyMiddleware.writeResponseKey / tryAcquireLock are private + * So each scenario below issues the EXACT SAME public Jedis sequence the production code runs + * (via code.api.cache.Redis), and asserts the post-fix invariant. They are RED today because the + * production sequence is non-atomic. The fix (Phase B) replaces the multi-command sequences with a + * single atomic Redis op (SET ... NX EX, or a Lua INCR-and-check) and widens the production methods + * so these tests retarget onto them. + * + * Tagged ConcurrencyRace. All scenarios assume Redis is reachable; they self-skip otherwise. + */ +class ConcurrentRateLimiterRaceTest extends ConcurrentRaceSetup { + + private def redisUp: Boolean = Redis.isRedisReady + + feature("Redis-backed rate-limit and idempotency operations must be atomic") { + + scenario("H4: concurrent check-then-increment must not let more than `limit` callers pass the gate", ConcurrencyRace) { + assume(redisUp, "Redis not reachable — skipping H4") + Given("a rate-limit counter key with limit=5 and 20 concurrent callers") + val key = "__conc_h4_rl_" + UUID.randomUUID.toString.take(8) + val limit = 5L + val n = 20 + // Seed nothing — first caller creates the key. Mirror RateLimitingUtil: + // check = underConsumerLimits: GET current count, allow if count+1 <= limit + // incr = incrementConsumerCounters: INCR (or SET with ttl if key missing) + val passed = new AtomicInteger(0) + + When(s"$n threads concurrently increment-then-check via the atomic Redis primitive") + // Fixed pattern: a single atomic INCR (with create-TTL) returns this caller's unique slot; + // the caller is allowed iff slot <= limit. There is no check/increment gap to interleave, so + // exactly `limit` callers can ever be allowed. (Pre-fix this was GET-then-INCR — two round + // trips — and far more than `limit` slipped through; see the red baseline.) + val results = runConcurrentWithBarrier(n) { _ => + val slot = Redis.incrementWithTtl(key, 3600) + val underLimit = slot <= limit + if (underLimit) passed.incrementAndGet() + underLimit + } + + Then(s"no more than $limit callers may have passed the gate — the rest must be throttled") + val passedCount = passed.get() + withClue( + s"passedCount=$passedCount limit=$limit (results.size=${results.size}): " + + s"RateLimitingUtil checks the counter (GET) and increments it (INCR) as two separate Redis " + + s"round-trips. Under concurrency, many callers read the same low count, all pass `count+1 <= limit`, " + + s"then all increment — far more than `limit` requests slip through (rate-limit bypass). " + + s"Fix: a single atomic Lua `INCR + compare` so the gate and the increment cannot interleave — " + ) { + passedCount.toLong should be <= limit + } + } + + scenario("M6: idempotency response cache must be first-write-wins, not last-writer-wins (SET NX EX, not setex)", ConcurrencyRace) { + assume(redisUp, "Redis not reachable — skipping M6") + Given("an idempotency response key that receives two writes with different bodies") + val key = "__conc_m6_rd_" + UUID.randomUUID.toString.take(8) + val ttl = 60 + + When("two responses are cached under the same key via the fixed primitive (Redis.setNxEx)") + // IdempotencyMiddleware.writeResponseKey now uses Redis.setNxEx (atomic SET NX EX). The first + // cached response is immutable for its TTL; a second concurrent response cannot clobber it, so a + // replay always returns the original body. (Pre-fix this used setex and overwrote — red baseline.) + Redis.setNxEx(key, "first", ttl) + Redis.setNxEx(key, "second", ttl) // no-op: the key already exists + + Then("the stored response must still be the FIRST one written, not the overwrite") + val stored = Redis.use(JedisMethod.GET, key).orNull + withClue( + s"stored=$stored: writeResponseKey must be first-write-wins (Redis.setNxEx). If it overwrote " + + s"(setex), a replay of the idempotent request would return the wrong cached body — " + ) { + stored shouldBe "first" + } + } + + scenario("M7: idempotency lock must be acquired atomically with its TTL (SET NX EX, not setnx+expire)", ConcurrencyRace) { + assume(redisUp, "Redis not reachable — skipping M7") + Given("a lock key acquired the way IdempotencyMiddleware.tryAcquireLock now does it") + val key = "__conc_m7_lock_" + UUID.randomUUID.toString.take(8) + val lockTtl = 60 + + When("the lock is acquired via the atomic primitive (Redis.setNxEx = SET NX EX)") + // Fixed: value and TTL are set in one command. There is no setnx -> (crash) -> expire window + // that could orphan the lock without a TTL. (Pre-fix used setnx then a separate expire, so the + // key briefly had TTL=-1; see the red baseline.) + val acquired = Redis.setNxEx(key, "1", lockTtl) + val ttlAfterAcquire = Redis.use(JedisMethod.TTL, key).map(_.toLong).getOrElse(-2L) + + Then("the lock must be acquired AND already carry a positive TTL (set atomically with the value)") + withClue( + s"acquired=$acquired ttlAfterAcquire=$ttlAfterAcquire: tryAcquireLock must set value and TTL " + + s"in one atomic command, so a crash can never orphan a TTL-less lock that blocks all retries — " + ) { + acquired shouldBe true + ttlAfterAcquire should be > 0L + } + } + } +} diff --git a/run_all_tests.sh b/run_all_tests.sh deleted file mode 100755 index 07848f4706..0000000000 --- a/run_all_tests.sh +++ /dev/null @@ -1,1071 +0,0 @@ -#!/bin/bash - -################################################################################ -# OBP-API Test Runner Script -# -# What it does: -# 1. Changes terminal to blue background with "Tests Running" in title -# 2. Runs: mvn clean test -# 3. Shows all test output in real-time -# 4. Updates title bar with: phase, time elapsed, pass/fail counts -# 5. Saves detailed log and summary to test-results/ -# 6. Restores terminal to normal when done -# -# Usage: -# ./run_all_tests.sh - Run full test suite -# ./run_all_tests.sh --summary-only - Regenerate summary from existing log -# ./run_all_tests.sh --timeout=60 - Run with 60 minute timeout -################################################################################ - -# Don't use set -e globally - it causes issues with grep returning 1 when no match -# Instead, we handle errors explicitly where needed - -################################################################################ -# PARSE COMMAND LINE ARGUMENTS -################################################################################ - -SUMMARY_ONLY=false -TIMEOUT_MINUTES=0 # 0 means no timeout - -for arg in "$@"; do - case $arg in - --summary-only) - SUMMARY_ONLY=true - ;; - --timeout=*) - TIMEOUT_MINUTES="${arg#*=}" - ;; - esac -done - -################################################################################ -# TERMINAL STYLING FUNCTIONS -################################################################################ - -# Set terminal to "test mode" - different colors for different phases -set_terminal_style() { - local phase="${1:-Running}" - - # Set different background colors for different phases - case "$phase" in - "Starting") - echo -ne "\033]11;#4a4a4a\007" # Dark gray background - echo -ne "\033]10;#ffffff\007" # White text - ;; - "Building") - echo -ne "\033]11;#ff6b35\007" # Orange background - echo -ne "\033]10;#ffffff\007" # White text - ;; - "Testing") - echo -ne "\033]11;#001f3f\007" # Dark blue background - echo -ne "\033]10;#ffffff\007" # White text - ;; - "Complete") - echo -ne "\033]11;#2ecc40\007" # Green background - echo -ne "\033]10;#ffffff\007" # White text - ;; - *) - echo -ne "\033]11;#001f3f\007" # Default blue background - echo -ne "\033]10;#ffffff\007" # White text - ;; - esac - - # Set window title - echo -ne "\033]0;OBP-API Tests ${phase}...\007" - - # Print header bar with phase-specific styling - printf "\033[44m\033[1;37m%-$(tput cols)s\r OBP-API TEST RUNNER ACTIVE - ${phase} \n%-$(tput cols)s\033[0m\n" " " " " -} - -# Update title bar with progress: "Testing: DynamicEntityTest - Scenario name [5m 23s]" -update_terminal_title() { - local phase="$1" # Starting, Building, Testing, Complete - local elapsed="${2:-}" # Time elapsed (e.g. "5m 23s") - local counts="${3:-}" # Module counts (e.g. "obp-commons:+38 obp-api:+245") - local suite="${4:-}" # Current test suite name - local scenario="${5:-}" # Current scenario name - - local title="OBP-API ${phase}" - [ -n "$suite" ] && title="${title}: ${suite}" - [ -n "$scenario" ] && title="${title} - ${scenario}" - title="${title}..." - [ -n "$elapsed" ] && title="${title} [${elapsed}]" - [ -n "$counts" ] && title="${title} ${counts}" - - echo -ne "\033]0;${title}\007" -} - -# Restore terminal to normal (black background, default title) -restore_terminal_style() { - echo -ne "\033]0;Terminal\007\033]11;#000000\007\033]10;#ffffff\007\033[0m" -} - -# Cleanup function: stop monitor, restore terminal, remove flag files -cleanup_on_exit() { - # Stop background monitor if running - if [ -n "${MONITOR_PID:-}" ]; then - kill $MONITOR_PID 2>/dev/null || true - wait $MONITOR_PID 2>/dev/null || true - fi - - # Remove monitor flag file - rm -f "${LOG_DIR}/monitor.flag" 2>/dev/null || true - - # Restore terminal - restore_terminal_style -} - -# Always cleanup on exit (Ctrl+C, errors, or normal completion) -trap cleanup_on_exit EXIT INT TERM - -################################################################################ -# CONFIGURATION -################################################################################ - -LOG_DIR="test-results" -DETAIL_LOG="${LOG_DIR}/last_run.log" # Full Maven output -SUMMARY_LOG="${LOG_DIR}/last_run_summary.log" # Summary only -FAILED_TESTS_FILE="${LOG_DIR}/failed_tests.txt" # Failed test list for run_specific_tests.sh - -# Phase timing variables (stored in temporary file) -PHASE_START_TIME=0 - -mkdir -p "${LOG_DIR}" - -# Function to get current time in milliseconds -get_time_ms() { - if [[ "$OSTYPE" == "darwin"* ]]; then - # macOS - python3 -c "import time; print(int(time.time() * 1000))" - else - # Linux - date +%s%3N - fi -} - -# Function to record phase timing -record_phase_time() { - local phase="$1" - local current_time=$(get_time_ms) - local timing_file="${LOG_DIR}/phase_timing.tmp" - - case "$phase" in - "starting") - echo "PHASE_START_TIME=$current_time" > "$timing_file" - ;; - "building") - if [ -f "$timing_file" ]; then - local phase_start=$(grep "PHASE_START_TIME=" "$timing_file" | cut -d= -f2) - if [ "$phase_start" -gt 0 ]; then - local starting_time=$((current_time - phase_start)) - echo "STARTING_TIME=$starting_time" >> "$timing_file" - fi - fi - echo "PHASE_START_TIME=$current_time" >> "$timing_file" - ;; - "testing") - if [ -f "$timing_file" ]; then - local phase_start=$(grep "PHASE_START_TIME=" "$timing_file" | tail -1 | cut -d= -f2) - if [ "$phase_start" -gt 0 ]; then - local building_time=$((current_time - phase_start)) - echo "BUILDING_TIME=$building_time" >> "$timing_file" - fi - fi - echo "PHASE_START_TIME=$current_time" >> "$timing_file" - ;; - "complete") - if [ -f "$timing_file" ]; then - local phase_start=$(grep "PHASE_START_TIME=" "$timing_file" | tail -1 | cut -d= -f2) - if [ "$phase_start" -gt 0 ]; then - local testing_time=$((current_time - phase_start)) - echo "TESTING_TIME=$testing_time" >> "$timing_file" - fi - fi - echo "PHASE_START_TIME=$current_time" >> "$timing_file" - ;; - "end") - if [ -f "$timing_file" ]; then - local phase_start=$(grep "PHASE_START_TIME=" "$timing_file" | tail -1 | cut -d= -f2) - if [ "$phase_start" -gt 0 ]; then - local complete_time=$((current_time - phase_start)) - echo "COMPLETE_TIME=$complete_time" >> "$timing_file" - fi - fi - ;; - esac -} - -# If summary-only mode, skip to summary generation -if [ "$SUMMARY_ONLY" = true ]; then - if [ ! -f "${DETAIL_LOG}" ]; then - echo "ERROR: No log file found at ${DETAIL_LOG}" - echo "Please run tests first without --summary-only flag" - exit 1 - fi - echo "Regenerating summary from existing log: ${DETAIL_LOG}" - # Skip cleanup and jump to summary generation - START_TIME=0 - END_TIME=0 - DURATION=0 - DURATION_MIN=0 - DURATION_SEC=0 -else - # Delete old log files and stale flag files from previous run - echo "Cleaning up old files..." - if [ -f "${DETAIL_LOG}" ]; then - rm -f "${DETAIL_LOG}" - echo " - Removed old detail log" - fi - if [ -f "${SUMMARY_LOG}" ]; then - rm -f "${SUMMARY_LOG}" - echo " - Removed old summary log" - fi -if [ -f "${LOG_DIR}/monitor.flag" ]; then - rm -f "${LOG_DIR}/monitor.flag" - echo " - Removed stale monitor flag" -fi - if [ -f "${LOG_DIR}/warning_analysis.tmp" ]; then - rm -f "${LOG_DIR}/warning_analysis.tmp" - echo " - Removed stale warning analysis" - fi - if [ -f "${LOG_DIR}/recent_lines.tmp" ]; then - rm -f "${LOG_DIR}/recent_lines.tmp" - echo " - Removed stale temp file" - fi - if [ -f "${LOG_DIR}/phase_timing.tmp" ]; then - rm -f "${LOG_DIR}/phase_timing.tmp" - echo " - Removed stale timing file" - fi -fi # End of if [ "$SUMMARY_ONLY" = true ] - -################################################################################ -# HELPER FUNCTIONS -################################################################################ - -# Log message to terminal and both log files -log_message() { - echo "$1" - echo "[$(date +"%Y-%m-%d %H:%M:%S")] $1" >> "${SUMMARY_LOG}" - echo "$1" >> "${DETAIL_LOG}" -} - -# Print section header -print_header() { - echo "" - echo "================================================================================" - echo "$1" - echo "================================================================================" - echo "" -} - -# Analyze warnings and return top contributors -analyze_warnings() { - local log_file="$1" - local temp_file="${LOG_DIR}/warning_analysis.tmp" - - # Extract and categorize warnings from last 5000 lines (for performance) - # This gives good coverage without scanning entire multi-MB log file - tail -n 5000 "${log_file}" 2>/dev/null | grep -i "warning" | \ - # Normalize patterns to group similar warnings - sed -E 's/line [0-9]+/line XXX/g' | \ - sed -E 's/[0-9]+ warnings?/N warnings/g' | \ - sed -E 's/\[WARNING\] .*(src|test)\/[^ ]+/[WARNING] /g' | \ - sed -E 's/version [0-9]+\.[0-9]+(\.[0-9]+)?/version X.X/g' | \ - # Extract the core warning message - sed -E 's/^.*\[WARNING\] *//' | \ - sort | uniq -c | sort -rn > "${temp_file}" - - # Return the temp file path for further processing - echo "${temp_file}" -} - -# Format and display top warning factors -display_warning_factors() { - local analysis_file="$1" - local max_display="${2:-10}" - - if [ ! -f "${analysis_file}" ] || [ ! -s "${analysis_file}" ]; then - log_message " No detailed warning analysis available" - return - fi - - local total_warning_types=$(wc -l < "${analysis_file}") - local displayed=0 - - log_message "Top Warning Factors:" - log_message "-------------------" - - while IFS= read -r line && [ $displayed -lt $max_display ]; do - # Extract count and message - local count=$(echo "$line" | awk '{print $1}') - local message=$(echo "$line" | sed -E 's/^[[:space:]]*[0-9]+[[:space:]]*//') - - # Truncate long messages - if [ ${#message} -gt 80 ]; then - message="${message:0:77}..." - fi - - # Format with count prominence - printf " %4d x %s\n" "$count" "$message" | tee -a "${SUMMARY_LOG}" > /dev/tty - - displayed=$((displayed + 1)) - done < "${analysis_file}" - - if [ $total_warning_types -gt $max_display ]; then - local remaining=$((total_warning_types - max_display)) - log_message " ... and ${remaining} more warning type(s)" - fi - - # Clean up temp file - rm -f "${analysis_file}" -} - -################################################################################ -# GENERATE SUMMARY FUNCTION (DRY) -################################################################################ - -generate_summary() { - local detail_log="$1" - local summary_log="$2" - local start_time="${3:-0}" - local end_time="${4:-0}" - - # Calculate duration - local duration=$((end_time - start_time)) - local duration_min=$((duration / 60)) - local duration_sec=$((duration % 60)) - - # If no timing info (summary-only mode), extract from log - if [ $duration -eq 0 ] && grep -q "Total time:" "$detail_log"; then - local time_str=$(grep "Total time:" "$detail_log" | tail -1) - duration_min=$(echo "$time_str" | sed 's/.*: //' | sed 's/ min.*//' | grep -o '[0-9]*' | head -1) - [ -z "$duration_min" ] && duration_min="0" - duration_sec=$(echo "$time_str" | sed 's/.* min //' | sed 's/\..*//' | grep -o '[0-9]*' | head -1) - [ -z "$duration_sec" ] && duration_sec="0" - fi - - print_header "Test Results Summary" - - # Extract test statistics from ScalaTest output (with UNKNOWN fallback if extraction fails) - # ScalaTest outputs across multiple lines: - # Run completed in X seconds. - # Total number of tests run: N - # Suites: completed M, aborted 0 - # Tests: succeeded N, failed 0, canceled 0, ignored 0, pending 0 - # All tests passed. - # We need to sum stats from ALL test runs (multiple modules: obp-commons, obp-api, etc.) - - # Sum up all "Total number of tests run" values (macOS compatible - no grep -P) - TOTAL_TESTS=$(grep "Total number of tests run:" "${detail_log}" 2>/dev/null | sed 's/.*Total number of tests run: //' | awk '{sum+=$1} END {print sum}' || echo "0") - [ -z "$TOTAL_TESTS" ] || [ "$TOTAL_TESTS" = "0" ] && TOTAL_TESTS="UNKNOWN" - - # Sum up all succeeded from "Tests: succeeded N, ..." lines - SUCCEEDED=$(grep "Tests: succeeded" "${detail_log}" 2>/dev/null | sed 's/.*succeeded //' | sed 's/,.*//' | awk '{sum+=$1} END {print sum}' || echo "0") - [ -z "$SUCCEEDED" ] && SUCCEEDED="UNKNOWN" - - # Sum up all failed from "Tests: ... failed N, ..." lines - FAILED=$(grep "Tests:.*failed" "${detail_log}" 2>/dev/null | sed 's/.*failed //' | sed 's/,.*//' | awk '{sum+=$1} END {print sum}' || echo "0") - [ -z "$FAILED" ] && FAILED="0" - - # Sum up all ignored from "Tests: ... ignored N, ..." lines - IGNORED=$(grep "Tests:.*ignored" "${detail_log}" 2>/dev/null | sed 's/.*ignored //' | sed 's/,.*//' | awk '{sum+=$1} END {print sum}' || echo "0") - [ -z "$IGNORED" ] && IGNORED="0" - - # Sum up errors (if any) - ERRORS=$(grep "errors" "${detail_log}" 2>/dev/null | grep -v "ERROR" | sed 's/.*errors //' | sed 's/[^0-9].*//' | awk '{sum+=$1} END {print sum}' || echo "0") - [ -z "$ERRORS" ] && ERRORS="0" - - # Calculate total including ignored (like IntelliJ does) - if [ "$TOTAL_TESTS" != "UNKNOWN" ] && [ "$IGNORED" != "0" ]; then - TOTAL_WITH_IGNORED=$((TOTAL_TESTS + IGNORED)) - else - TOTAL_WITH_IGNORED="$TOTAL_TESTS" - fi - - WARNINGS=$(grep -c "WARNING" "${detail_log}" 2>/dev/null || echo "0") - - # Determine build status (check FAILURE first — if both appear, the build failed) - if grep -q "BUILD FAILURE" "${detail_log}"; then - BUILD_STATUS="FAILURE" - BUILD_COLOR="" - elif grep -q "BUILD SUCCESS" "${detail_log}"; then - BUILD_STATUS="SUCCESS" - BUILD_COLOR="" - else - BUILD_STATUS="UNKNOWN" - BUILD_COLOR="" - fi - - # Print summary - log_message "Test Run Summary" - log_message "================" - - # Extract Maven timestamps and calculate Terminal timestamps - local maven_start_timestamp="" - local maven_end_timestamp="" - local terminal_start_timestamp="" - local terminal_end_timestamp=$(date) - - if [ "$start_time" -gt 0 ] && [ "$end_time" -gt 0 ]; then - # Use actual terminal start/end times if available - terminal_start_timestamp=$(date -r "$start_time" 2>/dev/null || date -d "@$start_time" 2>/dev/null || echo "Unknown") - terminal_end_timestamp=$(date -r "$end_time" 2>/dev/null || date -d "@$end_time" 2>/dev/null || echo "Unknown") - else - # Calculate terminal start time by subtracting duration from current time - if [ "$duration_min" -gt 0 -o "$duration_sec" -gt 0 ]; then - local total_seconds=$((duration_min * 60 + duration_sec)) - local approx_start_epoch=$(($(date "+%s") - total_seconds)) - terminal_start_timestamp=$(date -r "$approx_start_epoch" 2>/dev/null || echo "Approx. ${duration_min}m ${duration_sec}s ago") - else - terminal_start_timestamp="Unknown" - fi - fi - - # Extract Maven timestamps from log - maven_end_timestamp=$(grep "Finished at:" "${detail_log}" | tail -1 | sed 's/.*Finished at: //' | sed 's/T/ /' | sed 's/+.*//' || echo "Unknown") - - # Calculate Maven start time from Maven's "Total time" if available - local maven_total_time=$(grep "Total time:" "${detail_log}" | tail -1 | sed 's/.*Total time: *//' | sed 's/ .*//' || echo "") - if [ -n "$maven_total_time" ] && [ "$maven_end_timestamp" != "Unknown" ]; then - # Parse Maven duration (e.g., "02:06" for "02:06 min" or "43.653" for "43.653 s") - local maven_seconds=0 - if echo "$maven_total_time" | grep -q ":"; then - # Format like "02:06" (minutes:seconds) - local maven_min=$(echo "$maven_total_time" | sed 's/:.*//') - local maven_sec=$(echo "$maven_total_time" | sed 's/.*://') - # Remove leading zeros to avoid octal interpretation - maven_min=$(echo "$maven_min" | sed 's/^0*//' | sed 's/^$/0/') - maven_sec=$(echo "$maven_sec" | sed 's/^0*//' | sed 's/^$/0/') - maven_seconds=$((maven_min * 60 + maven_sec)) - else - # Format like "43.653" (seconds) - maven_seconds=$(echo "$maven_total_time" | sed 's/\..*//') - fi - - # Calculate Maven start time - if [ "$maven_seconds" -gt 0 ]; then - local maven_end_epoch=$(date -j -f "%Y-%m-%d %H:%M:%S" "$maven_end_timestamp" "+%s" 2>/dev/null || echo "0") - if [ "$maven_end_epoch" -gt 0 ]; then - local maven_start_epoch=$((maven_end_epoch - maven_seconds)) - maven_start_timestamp=$(date -r "$maven_start_epoch" 2>/dev/null || echo "Unknown") - else - maven_start_timestamp="Unknown" - fi - else - maven_start_timestamp="Unknown" - fi - else - maven_start_timestamp="Unknown" - fi - - # Format Maven end timestamp nicely - if [ "$maven_end_timestamp" != "Unknown" ]; then - maven_end_timestamp=$(date -j -f "%Y-%m-%d %H:%M:%S" "$maven_end_timestamp" "+%a %b %d %H:%M:%S %Z %Y" 2>/dev/null || echo "$maven_end_timestamp") - fi - - # Display both timelines - log_message "Terminal Timeline:" - log_message " Started: ${terminal_start_timestamp}" - log_message " Completed: ${terminal_end_timestamp}" - log_message " Duration: ${duration_min}m ${duration_sec}s" - log_message "" - log_message "Maven Timeline:" - log_message " Started: ${maven_start_timestamp}" - log_message " Completed: ${maven_end_timestamp}" - if [ -n "$maven_total_time" ]; then - local maven_duration_display=$(grep "Total time:" "${detail_log}" | tail -1 | sed 's/.*Total time: *//' || echo "Unknown") - log_message " Duration: ${maven_duration_display}" - fi - log_message "" - log_message "Build Status: ${BUILD_STATUS}" - log_message "" - - # Phase timing breakdown (if available) - local timing_file="${LOG_DIR}/phase_timing.tmp" - if [ -f "$timing_file" ]; then - # Read timing values from file - local start_ms=$(grep "STARTING_TIME=" "$timing_file" | cut -d= -f2 2>/dev/null || echo "0") - local build_ms=$(grep "BUILDING_TIME=" "$timing_file" | cut -d= -f2 2>/dev/null || echo "0") - local test_ms=$(grep "TESTING_TIME=" "$timing_file" | cut -d= -f2 2>/dev/null || echo "0") - local complete_ms=$(grep "COMPLETE_TIME=" "$timing_file" | cut -d= -f2 2>/dev/null || echo "0") - - # Ensure we have numeric values (default to 0 if empty) - [ -z "$start_ms" ] && start_ms=0 - [ -z "$build_ms" ] && build_ms=0 - [ -z "$test_ms" ] && test_ms=0 - [ -z "$complete_ms" ] && complete_ms=0 - - # Clean up timing file - rm -f "$timing_file" - - if [ "$start_ms" -gt 0 ] 2>/dev/null || [ "$build_ms" -gt 0 ] 2>/dev/null || [ "$test_ms" -gt 0 ] 2>/dev/null || [ "$complete_ms" -gt 0 ] 2>/dev/null; then - log_message "Phase Timing Breakdown:" - - if [ "$start_ms" -gt 0 ] 2>/dev/null; then - log_message " Starting: ${start_ms}ms ($(printf "%.2f" $(echo "scale=2; $start_ms/1000" | bc))s)" - fi - if [ "$build_ms" -gt 0 ] 2>/dev/null; then - log_message " Building: ${build_ms}ms ($(printf "%.2f" $(echo "scale=2; $build_ms/1000" | bc))s)" - fi - if [ "$test_ms" -gt 0 ] 2>/dev/null; then - log_message " Testing: ${test_ms}ms ($(printf "%.2f" $(echo "scale=2; $test_ms/1000" | bc))s)" - fi - if [ "$complete_ms" -gt 0 ] 2>/dev/null; then - log_message " Complete: ${complete_ms}ms ($(printf "%.2f" $(echo "scale=2; $complete_ms/1000" | bc))s)" - fi - - # Calculate percentages - local total_phase_time=$((start_ms + build_ms + test_ms + complete_ms)) - if [ "$total_phase_time" -gt 0 ]; then - log_message "" - log_message "Phase Distribution:" - if [ "$start_ms" -gt 0 ] 2>/dev/null; then - local starting_pct=$(echo "scale=1; $start_ms * 100 / $total_phase_time" | bc) - log_message " Starting: ${starting_pct}%" - fi - if [ "$build_ms" -gt 0 ] 2>/dev/null; then - local building_pct=$(echo "scale=1; $build_ms * 100 / $total_phase_time" | bc) - log_message " Building: ${building_pct}%" - fi - if [ "$test_ms" -gt 0 ] 2>/dev/null; then - local testing_pct=$(echo "scale=1; $test_ms * 100 / $total_phase_time" | bc) - log_message " Testing: ${testing_pct}%" - fi - if [ "$complete_ms" -gt 0 ] 2>/dev/null; then - local complete_pct=$(echo "scale=1; $complete_ms * 100 / $total_phase_time" | bc) - log_message " Complete: ${complete_pct}%" - fi - fi - log_message "" - fi - fi - - log_message "Test Statistics:" - log_message " Total: ${TOTAL_WITH_IGNORED} (${TOTAL_TESTS} run + ${IGNORED} ignored)" - log_message " Succeeded: ${SUCCEEDED}" - log_message " Failed: ${FAILED}" - log_message " Ignored: ${IGNORED}" - log_message " Errors: ${ERRORS}" - log_message " Warnings: ${WARNINGS}" - log_message "" - - # Analyze and display warning factors if warnings exist - if [ "${WARNINGS}" != "0" ] && [ "${WARNINGS}" != "UNKNOWN" ]; then - warning_analysis=$(analyze_warnings "${detail_log}") - display_warning_factors "${warning_analysis}" 10 - log_message "" - fi - - # Show failed tests if any (only actual test failures, not application ERROR logs) - if [ "${FAILED}" != "0" ] && [ "${FAILED}" != "UNKNOWN" ]; then - log_message "Failed Tests:" - - # Display failed scenario names (strip ANSI codes for clean output) - sed 's/\x1b\[[0-9;]*m//g' "${detail_log}" | \ - grep "\*\*\* FAILED \*\*\*" | \ - sed 's/^[[:space:]]*/ /' | \ - sort -u | head -50 | while IFS= read -r line; do - log_message "$line" - done - log_message "" - - # Write header to failed tests file - > "${FAILED_TESTS_FILE}" - cat >> "${FAILED_TESTS_FILE}" <<'HEADER' -# Failed test classes from last run -# Format: One test class per line with full package path -# Usage: ./run_specific_tests.sh will read this file and run only these tests -HEADER - - # Extract failed test class names using two strategies: - # 1. From assertion lines: (TestFile.scala:NNN) appears within ~10 lines after *** FAILED *** - # 2. From class headers: ScalaTest prints "TestClassName:" before scenarios - local tmp_classes="${LOG_DIR}/failed_classes.tmp" - local stripped_log="${LOG_DIR}/stripped.tmp" - sed 's/\x1b\[[0-9;]*m//g' "${detail_log}" > "${stripped_log}" - - # Strategy 1: Extract from assertion file references - grep -A 10 "\*\*\* FAILED \*\*\*" "${stripped_log}" | \ - sed -n 's/.*(\([A-Za-z0-9_]*\)\.scala:[0-9]*).*/\1/p' > "${tmp_classes}" - - # Strategy 2: For failures without file references, find the test class header - # ScalaTest prints "ClassName:" before its scenarios - # Exclude summary lines like "*** 2 TESTS FAILED ***" which aren't individual test failures - grep -n "\*\*\* FAILED \*\*\*" "${stripped_log}" | grep -v "TESTS FAILED" | cut -d: -f1 | while read failure_line; do - head -n "$failure_line" "${stripped_log}" | \ - grep -E '^[A-Z][a-zA-Z0-9_]*(Test|Tests|Suite):$' | \ - tail -1 | sed 's/:$//' - done >> "${tmp_classes}" - - sort -u "${tmp_classes}" -o "${tmp_classes}" - rm -f "${stripped_log}" - - # Look up full package path for each test class - while IFS= read -r test_class; do - package=$(find obp-api/src/test/scala -name "${test_class}.scala" 2>/dev/null | \ - sed 's|obp-api/src/test/scala/||' | sed 's|/|.|g' | sed 's|\.scala$||' | head -1) - if [ -n "$package" ]; then - echo "$package" >> "${FAILED_TESTS_FILE}" - fi - done < "${tmp_classes}" - rm -f "${tmp_classes}" - - log_message "Failed test classes saved to: ${FAILED_TESTS_FILE}" - log_message "" - elif [ "${ERRORS}" != "0" ] && [ "${ERRORS}" != "UNKNOWN" ]; then - log_message "Test Errors:" - grep -E "\*\*\* FAILED \*\*\*|\*\*\* RUN ABORTED \*\*\*" "${detail_log}" | head -50 >> "${summary_log}" - log_message "" - else - # All tests passed - clear failed_tests.txt and mark as clean - > "${FAILED_TESTS_FILE}" # Clear file - echo "# Failed test classes from last run" >> "${FAILED_TESTS_FILE}" - echo "# Last updated: $(date '+%Y-%m-%d %H:%M')" >> "${FAILED_TESTS_FILE}" - echo "#" >> "${FAILED_TESTS_FILE}" - echo "# ALL TESTS PASSED - No failed tests to report" >> "${FAILED_TESTS_FILE}" - echo "#" >> "${FAILED_TESTS_FILE}" - log_message "All tests passed - ${FAILED_TESTS_FILE} cleared" - log_message "" - fi - - # Final result - print_header "Test Run Complete" - - if [ "${BUILD_STATUS}" = "SUCCESS" ] && [ "${FAILED}" = "0" ] && [ "${ERRORS}" = "0" ]; then - log_message "[PASS] All tests passed!" - return 0 - else - log_message "[FAIL] Tests failed" - return 1 - fi -} - -################################################################################ -# SUMMARY-ONLY MODE -################################################################################ - -if [ "$SUMMARY_ONLY" = true ]; then - # Just regenerate the summary and exit - rm -f "${SUMMARY_LOG}" - if generate_summary "${DETAIL_LOG}" "${SUMMARY_LOG}" 0 0; then - log_message "" - log_message "Summary regenerated:" - log_message " ${SUMMARY_LOG}" - exit 0 - else - exit 1 - fi -fi - -################################################################################ -# START TEST RUN -################################################################################ - -# Record starting phase -record_phase_time "starting" -set_terminal_style "Starting" - -# Start the test run -print_header "OBP-API Test Suite" -log_message "Starting test run at $(date)" -log_message "Detail log: ${DETAIL_LOG}" -log_message "Summary log: ${SUMMARY_LOG}" -echo "" - -# Set Maven options for tests -# The --add-opens flags tell Java 17 to allow Kryo serialization library to access -# the internal java.lang.invoke and java.lang modules, which fixes the InaccessibleObjectException -export MAVEN_OPTS="-Xss128m -Xms3G -Xmx6G -XX:MaxMetaspaceSize=2G --add-opens java.base/java.lang.invoke=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED" -log_message "Maven Options: ${MAVEN_OPTS}" -echo "" - -# Ensure test properties file exists -PROPS_FILE="obp-api/src/main/resources/props/test.default.props" -PROPS_TEMPLATE="${PROPS_FILE}.template" - -if [ -f "${PROPS_FILE}" ]; then - log_message "[OK] Found test.default.props" -else - log_message "[WARNING] test.default.props not found - creating from template" - if [ -f "${PROPS_TEMPLATE}" ]; then - cp "${PROPS_TEMPLATE}" "${PROPS_FILE}" - log_message "[OK] Created test.default.props" - else - log_message "ERROR: ${PROPS_TEMPLATE} not found!" - exit 1 - fi -fi - -################################################################################ -# CHECK AND CLEANUP TEST SERVER PORTS -# Port 8018 is used by the embedded Jetty test server (configured in test.default.props) -################################################################################ - -print_header "Checking Test Server Ports" - -# Default test port (can be overridden) -TEST_PORT=8018 -MAX_PORT_ATTEMPTS=5 - -log_message "Checking if test server port ${TEST_PORT} is available..." - -# Function to find an available port -find_available_port() { - local port=$1 - local max_attempts=$2 - local attempt=0 - - while [ $attempt -lt $max_attempts ]; do - if ! lsof -i :$port >/dev/null 2>&1; then - echo $port - return 0 - fi - port=$((port + 1)) - attempt=$((attempt + 1)) - done - - echo "" - return 1 -} - -# Check if port is in use -if lsof -i :${TEST_PORT} >/dev/null 2>&1; then - log_message "[WARNING] Port ${TEST_PORT} is in use - attempting to kill process" - PORT_PID=$(lsof -t -i :${TEST_PORT} 2>/dev/null || true) - if [ -n "$PORT_PID" ]; then - kill -9 $PORT_PID 2>/dev/null || true - sleep 2 - - # Verify port is now free - if lsof -i :${TEST_PORT} >/dev/null 2>&1; then - log_message "[WARNING] Could not free port ${TEST_PORT}, searching for alternative..." - NEW_PORT=$(find_available_port $((TEST_PORT + 1)) $MAX_PORT_ATTEMPTS) - if [ -n "$NEW_PORT" ]; then - log_message "[OK] Found available port: ${NEW_PORT}" - # Update test.default.props with new port - if [ -f "${PROPS_FILE}" ]; then - sed -i.bak "s/hostname=127.0.0.1:${TEST_PORT}/hostname=127.0.0.1:${NEW_PORT}/" "${PROPS_FILE}" 2>/dev/null || \ - sed -i '' "s/hostname=127.0.0.1:${TEST_PORT}/hostname=127.0.0.1:${NEW_PORT}/" "${PROPS_FILE}" - log_message "[OK] Updated test.default.props to use port ${NEW_PORT}" - TEST_PORT=$NEW_PORT - fi - else - log_message "[ERROR] No available ports found in range ${TEST_PORT}-$((TEST_PORT + MAX_PORT_ATTEMPTS))" - exit 1 - fi - else - log_message "[OK] Killed process $PORT_PID, port ${TEST_PORT} is now available" - fi - fi -else - log_message "[OK] Port ${TEST_PORT} is available" -fi - -# Also check for any stale Java test processes -STALE_TEST_PROCS=$(ps aux | grep -E "TestServer|ScalaTest.*obp-api" | grep -v grep | awk '{print $2}' 2>/dev/null || true) -if [ -n "$STALE_TEST_PROCS" ]; then - log_message "[WARNING] Found stale test processes - cleaning up" - echo "$STALE_TEST_PROCS" | xargs kill -9 2>/dev/null || true - sleep 2 - log_message "[OK] Cleaned up stale test processes" -else - log_message "[OK] No stale test processes found" -fi - -log_message "" - -################################################################################ -# CLEAN METRICS DATABASE -################################################################################ - -print_header "Cleaning Metrics Database" -log_message "Checking for test database files..." - -# Only delete specific test database files to prevent accidental data loss -# The test configuration uses test_only_lift_proto.db as the database filename -TEST_DB_PATTERNS=( - "./test_only_lift_proto.db" - "./test_only_lift_proto.db.mv.db" - "./test_only_lift_proto.db.trace.db" - "./obp-api/test_only_lift_proto.db" - "./obp-api/test_only_lift_proto.db.mv.db" - "./obp-api/test_only_lift_proto.db.trace.db" -) - -FOUND_FILES=false -for dbfile in "${TEST_DB_PATTERNS[@]}"; do - if [ -f "$dbfile" ]; then - FOUND_FILES=true - rm -f "$dbfile" - log_message " [OK] Deleted: $dbfile" - fi -done - -if [ "$FOUND_FILES" = false ]; then - log_message "No old test database files found" -fi - -# --- Postgres test-DB clean (only when the suite is pointed at Postgres) --- -# Persistent Postgres + OBP's re-schemify needs a clean schema each full run, else boot aborts with -# "cannot alter type of a column used by a view". Tolerant: skipped on H2 / no psql / DB unreachable. -PG_TEST_DB_NAME="${PG_TEST_DB_NAME:-obp_test_only}" -PG_TEST_DB_USER="${PG_TEST_DB_USER:-obp_test_only}" -PG_TEST_DB_PASS="${PG_TEST_DB_PASS:-changeme}" -PG_TEST_DB_HOST="${PG_TEST_DB_HOST:-localhost}" -PG_TEST_DB_PORT="${PG_TEST_DB_PORT:-5432}" -if command -v psql >/dev/null 2>&1; then - PG_TEST_URL="postgresql://${PG_TEST_DB_USER}:${PG_TEST_DB_PASS}@${PG_TEST_DB_HOST}:${PG_TEST_DB_PORT}/${PG_TEST_DB_NAME}" - if psql "$PG_TEST_URL" -tAc "SELECT 1" >/dev/null 2>&1; then - if psql "$PG_TEST_URL" -c "DROP OWNED BY ${PG_TEST_DB_USER} CASCADE;" >/dev/null 2>&1; then - log_message " [OK] Cleaned Postgres test schema: ${PG_TEST_DB_NAME}" - else - log_message " [WARN] Could not clean Postgres test schema (continuing)" - fi - else - log_message " Postgres test DB not reachable (H2 run?) - skipping Postgres clean" - fi -else - log_message " psql not found - skipping Postgres test-DB clean" -fi - -log_message "" - -################################################################################ -# RUN TESTS -################################################################################ - -print_header "Running Tests" -log_message "Executing: mvn clean test" -echo "" - -START_TIME=$(date +%s) -export START_TIME - -# Create flag file to signal background process to stop -MONITOR_FLAG="${LOG_DIR}/monitor.flag" -touch "${MONITOR_FLAG}" - -# Optional timeout handling -MAVEN_PID="" -if [ "$TIMEOUT_MINUTES" -gt 0 ] 2>/dev/null; then - log_message "[INFO] Test timeout set to ${TIMEOUT_MINUTES} minutes" - TIMEOUT_SECONDS=$((TIMEOUT_MINUTES * 60)) -fi - -# Background process: Monitor log file and update title bar with progress -( - # Wait for log file to be created and have Maven output - while [ ! -f "${DETAIL_LOG}" ] || [ ! -s "${DETAIL_LOG}" ]; do - sleep 1 - done - - phase="Building" - in_building=false - in_testing=false - timing_file="${LOG_DIR}/phase_timing.tmp" - - # Keep monitoring until flag file is removed - while [ -f "${MONITOR_FLAG}" ]; do - # Use tail to look at recent lines only (last 500 lines for performance) - recent_lines=$(tail -n 500 "${DETAIL_LOG}" 2>/dev/null || true) - - # Switch to "Building" phase when Maven starts compiling - if ! $in_building && echo "$recent_lines" | grep -q -E 'Compiling|Building.*Open Bank Project' 2>/dev/null; then - phase="Building" - in_building=true - # Record building phase and update terminal (inline to avoid subshell issues) - current_time=$(python3 -c "import time; print(int(time.time() * 1000))" 2>/dev/null || date +%s000) - if [ -f "$timing_file" ]; then - phase_start=$(grep "PHASE_START_TIME=" "$timing_file" 2>/dev/null | tail -1 | cut -d= -f2 || echo "0") - [ -n "$phase_start" ] && [ "$phase_start" -gt 0 ] 2>/dev/null && echo "STARTING_TIME=$((current_time - phase_start))" >> "$timing_file" - fi - echo "PHASE_START_TIME=$current_time" >> "$timing_file" - echo -ne "\033]11;#ff6b35\007\033]10;#ffffff\007" # Orange background - fi - - # Switch to "Testing" phase when tests start - if ! $in_testing && echo "$recent_lines" | grep -q "Run starting" 2>/dev/null; then - phase="Testing" - in_testing=true - # Record testing phase - current_time=$(python3 -c "import time; print(int(time.time() * 1000))" 2>/dev/null || date +%s000) - if [ -f "$timing_file" ]; then - phase_start=$(grep "PHASE_START_TIME=" "$timing_file" 2>/dev/null | tail -1 | cut -d= -f2 || echo "0") - [ -n "$phase_start" ] && [ "$phase_start" -gt 0 ] 2>/dev/null && echo "BUILDING_TIME=$((current_time - phase_start))" >> "$timing_file" - fi - echo "PHASE_START_TIME=$current_time" >> "$timing_file" - echo -ne "\033]11;#001f3f\007\033]10;#ffffff\007" # Blue background - fi - - # Extract current running test suite and scenario from recent lines - suite="" - scenario="" - if $in_testing; then - suite=$(echo "$recent_lines" | grep -E "Test:" 2>/dev/null | tail -1 | sed 's/\x1b\[[0-9;]*m//g' | sed 's/:$//' | tr -d '\n\r' || true) - scenario=$(echo "$recent_lines" | grep -i "scenario:" 2>/dev/null | tail -1 | sed 's/\x1b\[[0-9;]*m//g' | sed 's/^[[:space:]]*-*[[:space:]]*//' | sed -E 's/^[Ss]cenario:[[:space:]]*//' | tr -d '\n\r' || true) - [ -n "$scenario" ] && [ ${#scenario} -gt 50 ] && scenario="${scenario:0:47}..." - fi - - # Calculate elapsed time - duration=$(($(date +%s) - START_TIME)) - minutes=$((duration / 60)) - seconds=$((duration % 60)) - elapsed=$(printf "%dm %ds" $minutes $seconds) - - # Update title - title="OBP-API ${phase}" - [ -n "$suite" ] && title="${title}: ${suite}" - [ -n "$scenario" ] && title="${title} - ${scenario}" - title="${title}... [${elapsed}]" - echo -ne "\033]0;${title}\007" - - sleep 5 - done -) & -MONITOR_PID=$! - -# Run Maven with optional timeout -if [ "$TIMEOUT_MINUTES" -gt 0 ] 2>/dev/null; then - # Run Maven in background and monitor for timeout - # Use pipefail so the pipeline returns mvn's exit code, not tee's - set -o pipefail - mvn clean test 2>&1 | tee "${DETAIL_LOG}" & - MAVEN_PID=$! - - elapsed=0 - while kill -0 $MAVEN_PID 2>/dev/null; do - sleep 10 - elapsed=$((elapsed + 10)) - if [ $elapsed -ge $TIMEOUT_SECONDS ]; then - log_message "" - log_message "[TIMEOUT] Test execution exceeded ${TIMEOUT_MINUTES} minutes - terminating" - kill -9 $MAVEN_PID 2>/dev/null || true - # Also kill any child Java processes - pkill -9 -P $MAVEN_PID 2>/dev/null || true - TEST_RESULT="TIMEOUT" - break - fi - done - - if [ "$TEST_RESULT" != "TIMEOUT" ]; then - wait $MAVEN_PID - if [ $? -eq 0 ]; then - TEST_RESULT="SUCCESS" - else - TEST_RESULT="FAILURE" - fi - fi - set +o pipefail -else - # Run Maven normally (all output goes to terminal AND log file) - # Use pipefail so the pipeline returns mvn's exit code, not tee's - set -o pipefail - if mvn clean test 2>&1 | tee "${DETAIL_LOG}"; then - TEST_RESULT="SUCCESS" - else - TEST_RESULT="FAILURE" - fi - set +o pipefail -fi - -################################################################################ -# GENERATE HTML REPORT -################################################################################ - -print_header "Generating HTML Report" -log_message "Running: mvn surefire-report:report-only -DskipTests" - -# Generate HTML report from surefire XML files (without re-running tests) -if mvn surefire-report:report-only -DskipTests 2>&1; then - log_message "[OK] HTML report generated" - - # Copy HTML reports to test-results directory for easy access - HTML_REPORT_DIR="${LOG_DIR}/html-reports" - mkdir -p "${HTML_REPORT_DIR}" - - # Copy reports from both modules - if [ -f "obp-api/target/surefire-reports/surefire.html" ]; then - cp "obp-api/target/surefire-reports/surefire.html" "${HTML_REPORT_DIR}/obp-api-report.html" - # Also copy CSS, JS, images for proper rendering - cp -r "obp-api/target/surefire-reports/css" "${HTML_REPORT_DIR}/" 2>/dev/null || true - cp -r "obp-api/target/surefire-reports/js" "${HTML_REPORT_DIR}/" 2>/dev/null || true - cp -r "obp-api/target/surefire-reports/images" "${HTML_REPORT_DIR}/" 2>/dev/null || true - cp -r "obp-api/target/surefire-reports/fonts" "${HTML_REPORT_DIR}/" 2>/dev/null || true - cp -r "obp-api/target/surefire-reports/img" "${HTML_REPORT_DIR}/" 2>/dev/null || true - log_message " - obp-api report: ${HTML_REPORT_DIR}/obp-api-report.html" - fi - if [ -f "obp-commons/target/surefire-reports/surefire.html" ]; then - cp "obp-commons/target/surefire-reports/surefire.html" "${HTML_REPORT_DIR}/obp-commons-report.html" - log_message " - obp-commons report: ${HTML_REPORT_DIR}/obp-commons-report.html" - fi - - # Also check for site reports location (alternative naming) - if [ -f "obp-api/target/site/surefire-report.html" ]; then - cp "obp-api/target/site/surefire-report.html" "${HTML_REPORT_DIR}/obp-api-report.html" - log_message " - obp-api report: ${HTML_REPORT_DIR}/obp-api-report.html" - fi - if [ -f "obp-commons/target/site/surefire-report.html" ]; then - cp "obp-commons/target/site/surefire-report.html" "${HTML_REPORT_DIR}/obp-commons-report.html" - log_message " - obp-commons report: ${HTML_REPORT_DIR}/obp-commons-report.html" - fi -else - log_message "[WARNING] Failed to generate HTML report" -fi - -log_message "" - -# Stop background monitor by removing flag file -rm -f "${MONITOR_FLAG}" -sleep 1 -kill $MONITOR_PID 2>/dev/null || true -wait $MONITOR_PID 2>/dev/null || true - -END_TIME=$(date +%s) -DURATION=$((END_TIME - START_TIME)) -DURATION_MIN=$((DURATION / 60)) -DURATION_SEC=$((DURATION % 60)) - -# Update title with final results (no suite/scenario name for Complete phase) -FINAL_ELAPSED=$(printf "%dm %ds" $DURATION_MIN $DURATION_SEC) -# Build final counts with module context -FINAL_COMMONS=$(sed -n '/Building Open Bank Project Commons/,/Building Open Bank Project API/{/Tests: succeeded/p;}' "${DETAIL_LOG}" 2>/dev/null | sed 's/.*succeeded //' | sed 's/,.*//' | head -1) -FINAL_API=$(sed -n '/Building Open Bank Project API/,/OBP Http4s Runner/{/Tests: succeeded/p;}' "${DETAIL_LOG}" 2>/dev/null | sed 's/.*succeeded //' | sed 's/,.*//' | tail -1) -FINAL_COUNTS="" -[ -n "$FINAL_COMMONS" ] && FINAL_COUNTS="commons:+${FINAL_COMMONS}" -[ -n "$FINAL_API" ] && FINAL_COUNTS="${FINAL_COUNTS:+${FINAL_COUNTS} }api:+${FINAL_API}" - -# Record complete phase start and change to green for completion phase -record_phase_time "complete" -set_terminal_style "Complete" -update_terminal_title "Complete" "$FINAL_ELAPSED" "$FINAL_COUNTS" "" "" - -################################################################################ -# GENERATE SUMMARY (using DRY function) -################################################################################ - -if generate_summary "${DETAIL_LOG}" "${SUMMARY_LOG}" "$START_TIME" "$END_TIME"; then - EXIT_CODE=0 -else - EXIT_CODE=1 -fi - -# Record end time for complete phase -record_phase_time "end" - -log_message "" -log_message "Logs saved to:" -log_message " $(realpath "${DETAIL_LOG}")" -log_message " $(realpath "${SUMMARY_LOG}")" -if [ -f "${FAILED_TESTS_FILE}" ]; then - log_message " $(realpath "${FAILED_TESTS_FILE}")" -fi -if [ -d "${LOG_DIR}/html-reports" ]; then - log_message "" - log_message "HTML Reports:" - for report in "${LOG_DIR}/html-reports"/*.html; do - [ -f "$report" ] && log_message " $(realpath "$report")" - done -fi -echo "" - -exit ${EXIT_CODE}