Failed getting block number for transaction

[bkravi73]

When we integrated FSC with our application, we are seeing "Failed getting block number for transaction " error being logged very frequently. However, no error is thrown and invocations are successful.

We would like to know if this is a valid scenario and why transaction doesn't have a block number.

Thanks for your help

[adecaro]

Hi @bkravi73 , when the node restarts, the commit pipeline of the fabric platform tries to restart from the last block processed before the shutdown. To do this, the stack asks the vault what was the last transaction committed. Then the ask queries the peer to learn the block this transaction belongs to. If an error happens here, then the stack simply restart from the genesis block.

Could you post the entire log line? I want to understand which transaction id fails and with what error.

Thanks for reporting this :)

[bkravi73]

Thanks for the details @adecaro . Please find below the logs:

INFO badger 2024/05/28 06:03:12 INFO: ttxdb.SetStatus Streaming about 209 KiB of uncompressed data (60 KiB on disk)
INFO badger 2024/05/28 06:03:12 INFO: Number of ranges found: 22
INFO badger 2024/05/28 06:03:12 INFO: Sent range 0 for iteration: [, 74780061616161616161616161616161616161616161616161616161760030663639386462653862613730303063353635373638353764623834656131383061653538663938623462666632313135616363643036623939663265626334ffffffffffffffda) of size: 349 KiB
INFO badger 2024/05/28 06:03:12 INFO: Sent range 1 for iteration: [74780061616161616161616161616161616161616161616161616161760030663639386462653862613730303063353635373638353764623834656131383061653538663938623462666632313135616363643036623939663265626334ffffffffffffffda, 74780061616161616161616161616161616161616161616161616162720030366136663430643232623836636561646161306162333063653136656266663465393532666636376666656232336639626364636139336465323566616164ffffffffffffffc2) of size: 349 KiB
INFO badger 2024/05/28 06:03:12 INFO: Sent range 2 for iteration: [74780061616161616161616161616161616161616161616161616162720030366136663430643232623836636561646161306162333063653136656266663465393532666636376666656232336639626364636139336465323566616164ffffffffffffffc2, 747800616161616161616161616161616161616161616161616161636e0036333939343261633632313735316534616663336462363934663139363766366233303538636232613537323632323361633332303031633161326635653631ffffffffffffffa8) of size: 349 KiB
INFO 2024-05-28 06:03:13.012 UTC [views] Call -> INFO 5be656 transaction succeeded: e98d1ccf2ac1971c9817c2d014f6bad4b56de4bd1e2d6cc7fc442472ff078499
INFO 2024-05-28 06:03:13.051 UTC [request] func3 -> INFO 5be657 "{"id": "d70f79dd-2d3a-4176-8229-26294f2d0131", "req": {"requestId":"T-1716531049085-CP-1-couponPayment-0","sourceTokenEnrollmentId":"IBRD-PRIMARY","destinationTokenEnrollmentId":"ABC1-PRIMARY","amount":70,"creatorCert":"...nstitutionId":"INST_01_286364","issuerInstitutionId":"INST_03_345699","metadata":"{"receivingOrgName":"04","investorInstitutionId":"INST_01_286364","issuerInstitutionId":"INST_03_345699"}"}, "res": {"amount":70,"destinationTokenEnrollmentId":"ABC1-PRIMARY","investorInstitutionId":"INST_01_286364","issuerInstitutionId":"INST_03_345699","sourceTokenEnrollmentId":"IBRD-PRIMARY","status":"SUCCESS"}
INFO 2024-05-28 06:03:13.051 UTC [request] func2 -> INFO 5be658 {"id": "d70f79dd-2d3a-4176-8229-26294f2d0131", "uri": "/tokens/transfer", "method": "POST", "status": 200, "remote_ip": "172.17.26.204", "user_agent": "weaver-api", "host": "cash-institution-token-service.wb-cash-portal.svc.cluster.local", "latency":4058714857, "latency_human":"4.058714857s", }
INFO 2024-05-28 06:03:13.031 UTC [views] NewView -> INFO 5be659 TransferEventView
INFO e98d1ccf2ac1971c9817c2d014f6bad4b56de4bd1e2d6cc7fc442472ff078499
e98d1ccf2ac1971c9817c2d014f6bad4b56de4bd1e2d6cc7fc442472ff078499
INFO badger 2024/05/28 06:03:13 INFO: Sent range 3 for iteration: [747800616161616161616161616161616161616161616161616161636e0036333939343261633632313735316534616663336462363934663139363766366233303538636232613537323632323361633332303031633161326635653631ffffffffffffffa8, 747800616161616161616161616161616161616161616161616161646a0033333063303739656366343434633131323231653037616139363765396438343864353665626235333335356432653038313866653464636261303134653438ffffffffffffff8e) of size: 349 KiB
INFO badger 2024/05/28 06:03:13 INFO: Sent range 4 for iteration: [747800616161616161616161616161616161616161616161616161646a0033333063303739656366343434633131323231653037616139363765396438343864353665626235333335356432653038313866653464636261303134653438ffffffffffffff8e, 74780061616161616161616161616161616161616161616161616165720033643861353765353431346331613935626162363964316530646661353730313934633563663139636466326662306161363365353239616535306332373863ffffffffffffff72) of size: 349 KiB
INFO badger 2024/05/28 06:03:13 INFO: Sent range 5 for iteration: [74780061616161616161616161616161616161616161616161616165720033643861353765353431346331613935626162363964316530646661353730313934633563663139636466326662306161363365353239616535306332373863ffffffffffffff72, 74780061616161616161616161616161616161616161616161616166720030663466643161393238643764356634656332303632326464376431633539366639663065383661656330663663613665623765393836383438646532306534ffffffffffffff59) of size: 349 KiB
INFO badger 2024/05/28 06:03:13 INFO: Sent range 6 for iteration: [74780061616161616161616161616161616161616161616161616166720030663466643161393238643764356634656332303632326464376431633539366639663065383661656330663663613665623765393836383438646532306534ffffffffffffff59, 747800616161616161616161616161616161616161616161616161676e0063303930646239396530383063376630646437313930633434316539636232396437336335646430343664366533643737336566376436333231373266393031ffffffffffffff3b) of size: 349 KiB
INFO badger 2024/05/28 06:03:13 INFO: Sent range 7 for iteration: [747800616161616161616161616161616161616161616161616161676e0063303930646239396530383063376630646437313930633434316539636232396437336335646430343664366533643737336566376436333231373266393031ffffffffffffff3b, 74780061616161616161616161616161616161616161616161616168740062326465343635663939623961666565343265376436666561646266396130346337346636393636633536613439633836656437393666303262363639366530ffffffffffffff1d) of size: 349 KiB
INFO badger 2024/05/28 06:03:13 INFO: Sent range 8 for iteration: [74780061616161616161616161616161616161616161616161616168740062326465343635663939623961666565343265376436666561646266396130346337346636393636633536613439633836656437393666303262363639366530ffffffffffffff1d, 74780061616161616161616161616161616161616161616161616169760036313634316163616465316435303235356461346566623933333338646333636637366565303962623036333334303466636536366131313032373639346332ffffffffffffff02) of size: 349 KiB
INFO badger 2024/05/28 06:03:13 INFO: Sent range 9 for iteration: [74780061616161616161616161616161616161616161616161616169760036313634316163616465316435303235356461346566623933333338646333636637366565303962623036333334303466636536366131313032373639346332ffffffffffffff02, 7478006161616161616161616161616161616161616161616161616b640066646261653939613266346662313162666165373932303131373464616237373661626130346361396235303264346134383764656565336161633836393030fffffffffffffee6) of size: 349 KiB
INFO badger 2024/05/28 06:03:14 INFO: Sent range 10 for iteration: [7478006161616161616161616161616161616161616161616161616b640066646261653939613266346662313162666165373932303131373464616237373661626130346361396235303264346134383764656565336161633836393030fffffffffffffee6, 7478006161616161616161616161616161616161616161616161616c720035656563316135313264396633376131666265343632303230343333396137646231343466663461353363313765303261616564646566303461383261353366fffffffffffffecc) of size: 349 KiB
INFO badger 2024/05/28 06:03:14 INFO: Sent range 11 for iteration: [7478006161616161616161616161616161616161616161616161616c720035656563316135313264396633376131666265343632303230343333396137646231343466663461353363313765303261616564646566303461383261353366fffffffffffffecc, 7478006161616161616161616161616161616161616161616161616e700032653030313636623630366565366535643734353761353732326464656135633130366461313466343863346432643135623666663237303039346265656463fffffffffffffead) of size: 349 KiB
INFO badger 2024/05/28 06:03:14 INFO: Sent range 12 for iteration: [7478006161616161616161616161616161616161616161616161616e700032653030313636623630366565366535643734353761353732326464656135633130366461313466343863346432643135623666663237303039346265656463fffffffffffffead, 7478006161616161616161616161616161616161616161616161616f7a0039393032623737313934656663656161376464643439393932393631333537303236663263643439663965313732316135373863646365393463333037393164fffffffffffffe8c) of size: 349 KiB
INFO badger 2024/05/28 06:03:14 INFO: Sent range 13 for iteration: [7478006161616161616161616161616161616161616161616161616f7a0039393032623737313934656663656161376464643439393932393631333537303236663263643439663965313732316135373863646365393463333037393164fffffffffffffe8c, 74780061616161616161616161616161616161616161616161616171680035653263633330303062643539643263656330616633356664366333636437373035626330343761336630663862623130303735613362373131333962326364fffffffffffffe73) of size: 349 KiB
INFO badger 2024/05/28 06:03:14 INFO: Sent range 14 for iteration: [74780061616161616161616161616161616161616161616161616171680035653263633330303062643539643263656330616633356664366333636437373035626330343761336630663862623130303735613362373131333962326364fffffffffffffe73, 74780061616161616161616161616161616161616161616161616172760038653436666432613031623336373538303233663430633533333235616665666238616661626637326235323535346231666365636566383436343632313761fffffffffffffe59) of size: 349 KiB
INFO badger 2024/05/28 06:03:14 INFO: Sent range 15 for iteration: [74780061616161616161616161616161616161616161616161616172760038653436666432613031623336373538303233663430633533333235616665666238616661626637326235323535346231666365636566383436343632313761fffffffffffffe59, 74780061616161616161616161616161616161616161616161616173720038353039376234353932613432376431363864623630393736323532343061626164363965363662363466666336383938303431636139663436363835653133fffffffffffffe3d) of size: 349 KiB
INFO badger 2024/05/28 06:03:14 INFO: Sent range 16 for iteration: [74780061616161616161616161616161616161616161616161616173720038353039376234353932613432376431363864623630393736323532343061626164363965363662363466666336383938303431636139663436363835653133fffffffffffffe3d, 74780061616161616161616161616161616161616161616161616175650064643032323962393464616638663964623636343237353638326265353263323437656337363137333737616136366233636563643761633666333636353335fffffffffffffe24) of size: 349 KiB
INFO badger 2024/05/28 06:03:14 INFO: Sent range 17 for iteration: [74780061616161616161616161616161616161616161616161616175650064643032323962393464616638663964623636343237353638326265353263323437656337363137333737616136366233636563643761633666333636353335fffffffffffffe24, 747800616161616161616161616161616161616161616161616161766f0031666637313936373335396339323336393632373236336463303330663164636631393339306663393466326462613861643932333561353735613833326631fffffffffffffe09) of size: 349 KiB
INFO badger 2024/05/28 06:03:14 INFO: Sent range 18 for iteration: [747800616161616161616161616161616161616161616161616161766f0031666637313936373335396339323336393632373236336463303330663164636631393339306663393466326462613861643932333561353735613833326631fffffffffffffe09, 74780061616161616161616161616161616161616161616161616177770061366164373666343936633733306166393463366161633539326232333435326465643835646164343630393836313366633731383565306561376137333266fffffffffffffdf0) of size: 349 KiB
INFO badger 2024/05/28 06:03:14 INFO: Sent range 19 for iteration: [74780061616161616161616161616161616161616161616161616177770061366164373666343936633733306166393463366161633539326232333435326465643835646164343630393836313366633731383565306561376137333266fffffffffffffdf0, 7478006161616161616161616161616161616161616161616161617a710033396237653038333031373935393533346364613766343031646661383161326561333431666562623265393231616262343765333739643136643566346336fffffffffffffdd0) of size: 349 KiB
INFO badger 2024/05/28 06:03:15 INFO: Sent range 20 for iteration: [7478006161616161616161616161616161616161616161616161617a710033396237653038333031373935393533346364613766343031646661383161326561333431666562623265393231616262343765333739643136643566346336fffffffffffffdd0, 74780061616161616161616161616161616161616161616161616261750039346266663833386165643164363731643661316161643832633535333763653735313363383263656139333561626230383462623162343066646162613263fffffffffffffdb8) of size: 349 KiB
INFO badger 2024/05/28 06:03:15 INFO: Sent range 21 for iteration: [74780061616161616161616161616161616161616161616161616261750039346266663833386165643164363731643661316161643832633535333763653735313363383263656139333561626230383462623162343066646162613263fffffffffffffdb8, ) of size: 349 KiB
2024-05-28 06:03:16.611 UTC [fabric-sdk.delivery] GetStartPosition -> ERRO 5be65c failed getting block number for transaction [31a2550218e41e380579aa6b6db906de502ab770b7d873e259e8c7e9b80a9975], restart from genesis [endorsement failure during query. endorsement is nil: [status:500 message:"Failed to get block for txID 31a2550218e41e380579aa6b6db906de502ab770b7d873e259e8c7e9b80a9975, error no such transaction ID [31a2550218e41e380579aa6b6db906de502ab770b7d873e259e8c7e9b80a9975] in index" ]]
INFO badger 2024/05/28 06:03:17 INFO: ttxdb.SetStatus [05s] Scan (10): ~96.7 KiB/209 KiB at 0 B/sec. Sent: 752.0 B at 0 B/sec. jemalloc: 0 B
INFO badger 2024/05/28 06:03:18 INFO: ttxdb.SetStatus Sent data of size 752 B

[adecaro]

Hi @bkravi73 , it looks like that the transaction is not on the ledger. Is that a transaction that failed before reaching the ordering service?

[bkravi73]

@adecaro - Actually, this error is seen whenever a withdrawal is done(not during node start up). We looked for this txID in fabric ledger, and it is the transaction Id which got committed into ledger just a couple of seconds before. So, probably a look up for latest or last transaction is happening, before tx is even committed into ledger. A possible read-write conflict. Please let us know if this is true.
Also, client wants to know if this has impact on application functionality. Are we storing the latest transaction/block everytime a new transaction is performed?
Thanks in advance for your response

[adecaro]

@bkravi73 , apologies for not following up with this. Is it still pending?