Transfer Timeouts are not re-setting positions and status #868

mdebarros · 2019-07-18T14:35:34Z

Summary:

Transfer Timeouts are not re-setting positions and status.

Golden Path QA Framework transfer_timeout failing:

Cause seems to be due to an error on the Position Handler as follows:

2019-07-18T14:24:45.027Z - info: PositionHandler::positions
2019-07-18T14:24:45.028Z - info: PositionHandler::positions::timeout
2019-07-18T14:24:45.029Z - error: Undefined binding(s) detected when compiling FIRST query: select `transferParticipant`.*, `tsc`.`transferStateId`, `tsc`.`reason` from `transferParticipant` inner join `transferStateChange` as `tsc` on `tsc`.`transferId` = `transferParticipant`.`transferId` where `transferParticipant`.`transferId` = ? and `transferParticipant`.`transferParticipantRoleTypeId` = ? and `transferParticipant`.`ledgerEntryTypeId` = ? order by `tsc`.`transferStateChangeId` desc limit ?
2019-07-18T14:24:45.029Z - error: PositionHandler::positions::timeout::Undefined binding(s) detected when compiling FIRST query: select `transferParticipant`.*, `tsc`.`transferStateId`, `tsc`.`reason` from `transferParticipant` inner join `transferStateChange` as `tsc` on `tsc`.`transferId` = `transferParticipant`.`transferId` where `transferParticipant`.`transferId` = ? and `transferParticipant`.`transferParticipantRoleTypeId` = ? and `transferParticipant`.`ledgerEntryTypeId` = ? order by `tsc`.`transferStateChangeId` desc limit ?--0
2019-07-18T14:24:45.029Z - error: Consumer::consume()::syncQueue.queue - error: Error: Undefined binding(s) detected when compiling FIRST query: select `transferParticipant`.*, `tsc`.`transferStateId`, `tsc`.`reason` from `transferParticipant` inner join `transferStateChange` as `tsc` on `tsc`.`transferId` = `transferParticipant`.`transferId` where `transferParticipant`.`transferId` = ? and `transferParticipant`.`transferParticipantRoleTypeId` = ? and `transferParticipant`.`ledgerEntryTypeId` = ? order by `tsc`.`transferStateChangeId` desc limit ?
2019-07-18T14:24:45.029Z - error: Consumer::onError()[topics='topic-transfer-position'] - Error: Undefined binding(s) detected when compiling FIRST query: select `transferParticipant`.*, `tsc`.`transferStateId`, `tsc`.`reason` from `transferParticipant` inner join `transferStateChange` as `tsc` on `tsc`.`transferId` = `transferParticipant`.`transferId` where `transferParticipant`.`transferId` = ? and `transferParticipant`.`transferParticipantRoleTypeId` = ? and `transferParticipant`.`ledgerEntryTypeId` = ? order by `tsc`.`transferStateChangeId` desc limit ?
    at QueryCompiler_MySQL.toSQL (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/knex/lib/query/compiler.js:85:13)
    at Builder.toSQL (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/knex/lib/query/builder.js:72:44)
    at /opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/knex/lib/runner.js:37:34
    at tryCatcher (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/util.js:16:23)
    at /opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/using.js:185:26
    at tryCatcher (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/promise.js:512:31)
    at Promise._settlePromise (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/promise.js:569:18)
    at Promise._settlePromise0 (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/promise.js:614:10)
    at Promise._settlePromises (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/promise.js:694:18)
    at Promise._fulfill (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/promise.js:638:18)
    at PromiseArray._resolve (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/promise_array.js:126:19)
    at PromiseArray._promiseFulfilled (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/promise_array.js:144:14)
    at Promise._settlePromise (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/promise.js:574:26)
    at Promise._settlePromise0 (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/promise.js:614:10)
    at Promise._settlePromises (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/promise.js:694:18)
    at _drainQueueStep (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/async.js:138:12)
    at _drainQueue (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/async.js:131:9)
    at Async._drainQueues (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/async.js:147:5)
    at Immediate.Async.drainQueues [as _onImmediate] (/opt/central-ledger/node_modules/@mojaloop/central-services-database/node_modules/bluebird/js/release/async.js:17:14)
    at runCallback (timers.js:705:18)
    at tryOnImmediate (timers.js:676:5)
    at processImmediate (timers.js:658:5))
2019-07-18T14:24:45.029Z - error: Consumer::consume() - error Error: Undefined binding(s) detected when compiling FIRST query: select `transferParticipant`.*, `tsc`.`transferStateId`, `tsc`.`reason` from `transferParticipant` inner join `transferStateChange` as `tsc` on `tsc`.`transferId` = `transferParticipant`.`transferId` where `transferParticipant`.`transferId` = ? and `transferParticipant`.`transferParticipantRoleTypeId` = ? and `transferParticipant`.`ledgerEntryTypeId` = ? order by `tsc`.`transferStateChangeId` desc limit ?

Severity:
High

Priority:
Critical

Expected Behavior

Steps to Reproduce

Store Payerfsp position before prepare:

REQUEST:
curl -X GET \
  http://dev2-central-ledger.mojaloop.live/participants/payerfsp/positions \
  -H 'Authorization: Bearer {{BEARER_TOKEN}}' \
  -H 'FSPIOP-Source: payerfsp' \
  -H 'Postman-Token: acadede1-3d20-4a87-be28-135582115052' \
  -H 'cache-control: no-cache'

RESPONSE:
[
    {
        "currency": "USD",
        "value": 488,
        "changedDate": "2019-07-18T13:53:27.000Z"
    }
]

Send prepare

curl -X POST \
  http://dev2-ml-api-adapter.mojaloop.live/transfers \
  -H 'Accept: application/vnd.interoperability.transfers+json;version=1' \
  -H 'Authorization: Bearer {{BEARER_TOKEN}}' \
  -H 'Content-Type: application/vnd.interoperability.transfers+json;version=1' \
  -H 'Date: Thu, 24 Jan 2019 10:22:12 GMT' \
  -H 'FSPIOP-Destination: noresponsepayeefsp' \
  -H 'FSPIOP-Source: payerfsp' \
  -H 'Postman-Token: 751dcac0-0a87-4d81-af1d-ecb7f44d8e2a' \
  -H 'cache-control: no-cache' \
  -d '{
  "transferId": "f999c714-7665-4390-a0ea-4a6767bbb973",
  "payerFsp": "payerfsp",
  "payeeFsp": "noresponsepayeefsp",
  "amount": {
    "amount": "10",
    "currency": "USD"
  },
  "expiration": "2019-07-18T14:24:38.091Z",
  "ilpPacket": "AQAAAAAAAADIEHByaXZhdGUucGF5ZWVmc3CCAiB7InRyYW5zYWN0aW9uSWQiOiIyZGY3NzRlMi1mMWRiLTRmZjctYTQ5NS0yZGRkMzdhZjdjMmMiLCJxdW90ZUlkIjoiMDNhNjA1NTAtNmYyZi00NTU2LThlMDQtMDcwM2UzOWI4N2ZmIiwicGF5ZWUiOnsicGFydHlJZEluZm8iOnsicGFydHlJZFR5cGUiOiJNU0lTRE4iLCJwYXJ0eUlkZW50aWZpZXIiOiIyNzcxMzgwMzkxMyIsImZzcElkIjoicGF5ZWVmc3AifSwicGVyc29uYWxJbmZvIjp7ImNvbXBsZXhOYW1lIjp7fX19LCJwYXllciI6eyJwYXJ0eUlkSW5mbyI6eyJwYXJ0eUlkVHlwZSI6Ik1TSVNETiIsInBhcnR5SWRlbnRpZmllciI6IjI3NzEzODAzOTExIiwiZnNwSWQiOiJwYXllcmZzcCJ9LCJwZXJzb25hbEluZm8iOnsiY29tcGxleE5hbWUiOnt9fX0sImFtb3VudCI6eyJjdXJyZW5jeSI6IlVTRCIsImFtb3VudCI6IjIwMCJ9LCJ0cmFuc2FjdGlvblR5cGUiOnsic2NlbmFyaW8iOiJERVBPU0lUIiwic3ViU2NlbmFyaW8iOiJERVBPU0lUIiwiaW5pdGlhdG9yIjoiUEFZRVIiLCJpbml0aWF0b3JUeXBlIjoiQ09OU1VNRVIiLCJyZWZ1bmRJbmZvIjp7fX19",
  "condition": "nMel-FDPpp3T77jfC11fUXdcy935hy089AJ9v2OTXBI"
}'

Check position before timeout

REQUEST:
curl -X GET \
  http://dev2-central-ledger.mojaloop.live/participants/payerfsp/positions \
  -H 'Authorization: Bearer {{BEARER_TOKEN}}' \
  -H 'FSPIOP-Source: payerfsp' \
  -H 'Postman-Token: 2efcca9f-2ed3-4589-9e3f-20ba4d1d6e31' \
  -H 'cache-control: no-cache'

RESPONSE:
[
    {
        "currency": "USD",
        "value": 488,
        "changedDate": "2019-07-18T13:53:27.000Z"
    }
]

Check Payerfsp position after timeout <-- Fails

REQUEST:
curl -X GET \
  http://dev2-central-ledger.mojaloop.live/participants/payerfsp/positions \
  -H 'FSPIOP-Source: payerfsp' \
  -H 'Postman-Token: 4553c55e-9cf9-49f0-8d11-c0a814b3254e' \
  -H 'cache-control: no-cache'

RESPONSE:
[
    {
        "currency": "USD",
        "value": 488, <-- Filed due to value being same as step 3. This should now be 478.
        "changedDate": "2019-07-18T13:53:27.000Z"
    }
]

Check Transfer status - ABORTED

REQUEST:
curl -X GET \
  http://dev2-ml-api-adapter.mojaloop.live/transfers/f999c714-7665-4390-a0ea-4a6767bbb973 \
  -H 'Accept: application/vnd.interoperability.transfers+json;version=1' \
  -H 'Authorization: Bearer {{BEARER_TOKEN}}' \
  -H 'Content-Type: application/vnd.interoperability.transfers+json;version=1.0' \
  -H 'Date: Thu, 18 Jul 2019 14:24:08 GMT' \
  -H 'FSPIOP-Source: payerfsp' \
  -H 'Postman-Token: b869606f-bc08-4600-9374-4851272b2f30' \
  -H 'cache-control: no-cache'

RESPONSE:
{
    completedTimestamp:"2019-07-18T14:24:45.000Z"
    transferState:"RESERVED" <-- This failed as it should be "ABORTED"
}

Tasks

Add the missing content.uriParams.id field to the message in src/handlers/timeouts/handler.js
Add new integration and unit test(s)
Create a new story to update the messages to use common/streaming factory method instead of the current ad-hoc approach.

Pull Request

Fix/868 timeout handler error central-ledger#331

Specifications

Component (if known): Central-Ledger Position Handler
Version: v7.1.2
Platform: All
Subsystem: n/a
Type of testing: QA - Golden Path
Bug found/raised by: @mdebarros

Notes:

Severity when opened: High
Priority when opened: Critical

The text was updated successfully, but these errors were encountered:

lewisdaly · 2019-07-22T06:27:52Z

I couldn't reproduce this error with a new deployment from scratch, (with a central-lefger of mojaloop/central-ledger:v6.2.5). @mdebarros is there a helm chart you are working on that I can try this with?

lewisdaly · 2019-07-22T14:42:45Z

Can confirm I managed to reproduce this locally with the current master (v7.1.2) of central-ledger

lewisdaly · 2019-07-22T14:51:35Z

In src/handlers/positions/handler.js, line 191:

const transferInfo = await TransferService.getTransferInfoToChangePosition(transferId, Enum.TransferParticipantRoleType.PAYER_DFSP, Enum.LedgerEntryType.PRINCIPLE_VALUE)

transferId appears to be undefined

lewisdaly · 2019-07-22T15:06:53Z

In the same file, we set transferId as follows:

const transferId = payload.transferId || (message.value.content.uriParams && message.value.content.uriParams.id)

However, during an error callback, there is no payload.transferId, and there is no message.value.content.uriParams.

So either there is a problem with how we are accessing the transferId here, or there is an issue with the callbacks not passing through the correct message.value.content parameters.

mdebarros added the bug label Jul 18, 2019

mdebarros mentioned this issue Jul 18, 2019

Support QA, testing on Mojaloop pre-releases / releases on Dev envt for PI7 (ended with v7.4.0 Helm release) #750

Closed

21 tasks

mdebarros added the test-bug This is a bug in tests or test automation framework, not a code or functionality issue label Jul 18, 2019

lewisdaly self-assigned this Jul 22, 2019

elnyry-sam-k added this to the Sprint 7.2 milestone Jul 22, 2019

lewisdaly mentioned this issue Jul 23, 2019

Fix/868 timeout handler error mojaloop/central-ledger#331

Merged

lewisdaly closed this as completed in mojaloop/central-ledger#331 Jul 24, 2019

This was referenced Jul 24, 2019

Replace ad-hoc message creation with consistent message parsing #878

Closed

Duplicate Transfer Response Header validation failing on QA Framework #869

Closed

elnyry-sam-k modified the milestone: Sprint 7.2 Jul 30, 2019

elnyry-sam-k removed this from the Sprint 7.2 milestone Aug 7, 2019

dependabot-preview bot mentioned this issue Aug 26, 2019

Bump @mojaloop/central-ledger from 5.2.1 to 7.4.0 mojaloop/central-settlement#99

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Transfer Timeouts are not re-setting positions and status #868

Transfer Timeouts are not re-setting positions and status #868

mdebarros commented Jul 18, 2019 •

edited by elnyry-sam-k

Loading

lewisdaly commented Jul 22, 2019

lewisdaly commented Jul 22, 2019

lewisdaly commented Jul 22, 2019

lewisdaly commented Jul 22, 2019

Transfer Timeouts are not re-setting positions and status #868

Transfer Timeouts are not re-setting positions and status #868

Comments

mdebarros commented Jul 18, 2019 • edited by elnyry-sam-k Loading

lewisdaly commented Jul 22, 2019

lewisdaly commented Jul 22, 2019

lewisdaly commented Jul 22, 2019

lewisdaly commented Jul 22, 2019

mdebarros commented Jul 18, 2019 •

edited by elnyry-sam-k

Loading