View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0007295libeufinlibeufin-nexuspublic2022-08-07 13:072023-01-08 10:32
ReporterChristian Grothoff Assigned ToMS  
PriorityurgentSeverityblockReproducibilityrandom
Status closedResolutionfixed 
Platformi7OSDebian GNU/LinuxOS Versionsqueeze
Product Version0.9.3 
Target Version0.9.0Fixed in Version0.9.0 
Summary0007295: Unexpected EBICS return code: EBICS_PROCESSING_ERROR
Description===========0: normal run with aggregator===========
Launching bank............. DONE
Running exchange aggregator ... DONE
Running exchange closer ... DONE
Running exchange transfer ... DONE
Running Nexus payment submitter ...{
  "code" : 9000,
  "hint" : "nexus error, see detail",
  "detail" : "Unexpected EBICS return code: EBICS_PROCESSING_ERROR"
}
Unexpected response status: 500
Response: {
  "code" : 9000,
  "hint" : "nexus error, see detail",
  "detail" : "Unexpected EBICS return code: EBICS_PROCESSING_ERROR"
}
Killing euFin..
FAIL test-auditor.sh (exit status: 1)
Steps To Reproducerun test-auditor.sh of the exchange
TagsNo tags attached.
Attached Files
libeufin-nexus-stderr.log (1,951 bytes)    
13:05:07.148 [main] INFO  tech.libeufin.nexus - LibEuFin Nexus running on port 8082
13:05:07.221 [DefaultDispatcher-worker-1] INFO  tech.libeufin.nexus - scheduling task exchange-history at Optional[2022-08-07T13:05:08.190878+02:00[Europe/Zurich]] (now is 2022-08-07T13:05:07.190878+02:00[Europe/Zurich])
13:05:07.255 [DefaultDispatcher-worker-1] INFO  tech.libeufin.nexus - running task TaskSchedule(taskId=1, name=exchange-payments, type=submit, resourceType=bank-account, resourceId=exchange-nexus, params={
  "rangeType" : null,
  "level" : null
})
13:05:07.256 [DefaultDispatcher-worker-1] DEBUG tech.libeufin.nexus - auto-submitter started
13:05:07.306 [main] DEBUG tech.libeufin.nexus - Application started: io.ktor.application.Application@396639b
13:05:07.761 [eventLoopGroupProxy-4-1] DEBUG tech.libeufin.nexus - 200 OK: GET - /
13:05:08.283 [DefaultDispatcher-worker-1] INFO  tech.libeufin.nexus - scheduling task exchange-payments at Optional[2022-08-07T13:05:09.282780+02:00[Europe/Zurich]] (now is 2022-08-07T13:05:08.282780+02:00[Europe/Zurich])
13:05:08.287 [DefaultDispatcher-worker-1] INFO  tech.libeufin.nexus - running task TaskSchedule(taskId=2, name=exchange-history, type=fetch, resourceType=bank-account, resourceId=exchange-nexus, params={
  "rangeType" : "latest",
  "level" : "report"
})
13:05:08.478 [DefaultDispatcher-worker-1] DEBUG tech.libeufin.nexus - Requesting C52
13:05:09.218 [eventLoopGroupProxy-4-2] DEBUG tech.libeufin.nexus - 200 OK: GET - /facades/test-facade/taler-wire-gateway/history/incoming
13:05:09.249 [eventLoopGroupProxy-4-2] DEBUG tech.libeufin.nexus - 200 OK: GET - /facades/test-facade/taler-wire-gateway/history/outgoing
13:05:09.620 [eventLoopGroupProxy-4-3] DEBUG tech.libeufin.nexus - 200 OK: GET - /facades/test-facade/taler-wire-gateway/history/incoming
13:05:09.631 [eventLoopGroupProxy-4-3] DEBUG tech.libeufin.nexus - 200 OK: GET - /facades/test-facade/taler-wire-gateway/history/outgoing
libeufin-nexus-stderr.log (1,951 bytes)   
libeufin-sandbox-stderr.log (291 bytes)    
13:05:06.999 [main] INFO  tech.libeufin.sandbox - LibEuFin Sandbox running on port 18082
13:05:09.677 [eventLoopGroupProxy-4-1] DEBUG tech.libeufin.sandbox - handling initialization for order type C52
13:05:09.677 [eventLoopGroupProxy-4-1] DEBUG tech.libeufin.sandbox - Handling C52 request
libeufin-sandbox-stderr.log (291 bytes)   

Activities

Christian Grothoff

2022-08-07 13:16

manager   ~0018992

This was reproducible with c676737f5f6a707ea8bb5b75f776eb619dab110d.

Christian Grothoff

2022-08-07 13:58

manager   ~0018993

Running generate-auditor-basedb.sh to create a new DB "fixed" the issue, but that's not a 'good' solution. We need to find out what went wrong here, and at the very least improve the logging.

Christian Grothoff

2022-08-07 13:58

manager   ~0018994

Same issue also happened with the 'revoke' script, but on a DB that AFAIK previously worked. Strange. Maybe this is non-deterministic?

Christian Grothoff

2022-08-07 14:29

manager   ~0018995

It is definitively non-deterministic. Here is a run of two 'make check's in src/auditor:

$ make check
 cd ../.. && /bin/bash /home/grothoff/research/taler/exchange/build-aux/missing automake-1.16 --gnu src/auditor/Makefile
 cd ../.. && /bin/bash ./config.status src/auditor/Makefile depfiles
config.status: creating src/auditor/Makefile
config.status: executing depfiles commands
make test-auditor.sh test-revocation.sh test-sync.sh
make[1]: Entering directory '/research/taler/exchange/src/auditor'
make[1]: Nothing to be done for 'test-auditor.sh'.
make[1]: Nothing to be done for 'test-revocation.sh'.
make[1]: Nothing to be done for 'test-sync.sh'.
make[1]: Leaving directory '/research/taler/exchange/src/auditor'
make check-TESTS
make[1]: Entering directory '/research/taler/exchange/src/auditor'
make[2]: Entering directory '/research/taler/exchange/src/auditor'
PASS: test-auditor.sh
PASS: test-revocation.sh
PASS: test-sync.sh
============================================================================
Testsuite summary for taler-exchange 0.8.5
============================================================================
# TOTAL: 3
# PASS: 3
# SKIP: 0
# XFAIL: 0
# FAIL: 0
# XPASS: 0
# ERROR: 0
============================================================================
make[2]: Leaving directory '/research/taler/exchange/src/auditor'
make[1]: Leaving directory '/research/taler/exchange/src/auditor'
grothoff@elma:~/research/taler/exchange/src/auditor$ make check
make test-auditor.sh test-revocation.sh test-sync.sh
make[1]: Entering directory '/research/taler/exchange/src/auditor'
make[1]: Nothing to be done for 'test-auditor.sh'.
make[1]: Nothing to be done for 'test-revocation.sh'.
make[1]: Nothing to be done for 'test-sync.sh'.
make[1]: Leaving directory '/research/taler/exchange/src/auditor'
make check-TESTS
make[1]: Entering directory '/research/taler/exchange/src/auditor'
make[2]: Entering directory '/research/taler/exchange/src/auditor'
FAIL: test-auditor.sh

MS

2022-09-07 13:19

manager   ~0019097

The conflict was between Sandbox and the sqlite3 command, because both tried to access the database. In this commit: 70a1c0d68, a function called "test_16_db()" fixed
the test 16 and represents the model to fix more similar errors.

Issue History

Date Modified Username Field Change
2022-08-07 13:07 Christian Grothoff New Issue
2022-08-07 13:07 Christian Grothoff Status new => assigned
2022-08-07 13:07 Christian Grothoff Assigned To => MS
2022-08-07 13:07 Christian Grothoff File Added: libeufin-nexus-stderr.log
2022-08-07 13:07 Christian Grothoff File Added: libeufin-sandbox-stderr.log
2022-08-07 13:16 Christian Grothoff Note Added: 0018992
2022-08-07 13:16 Christian Grothoff Reproducibility have not tried => always
2022-08-07 13:58 Christian Grothoff Note Added: 0018993
2022-08-07 13:58 Christian Grothoff Note Added: 0018994
2022-08-07 14:29 Christian Grothoff Note Added: 0018995
2022-08-07 14:29 Christian Grothoff Priority normal => urgent
2022-08-07 14:29 Christian Grothoff Reproducibility always => random
2022-09-07 13:19 MS Note Added: 0019097
2022-09-07 13:19 MS Status assigned => resolved
2022-09-07 13:19 MS Resolution open => fixed
2023-01-08 10:31 Christian Grothoff Fixed in Version => 0.9.0
2023-01-08 10:31 Christian Grothoff Target Version => 0.9.0
2023-01-08 10:32 Christian Grothoff Status resolved => closed
2023-04-13 20:38 Florian Dold Category nexus => libeufin-nexus