Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

c.h.m.i.r.BalanceReconciliationService Reconciliation completed unsuccessfully #5354

Closed
gitmewai opened this issue Feb 8, 2023 · 8 comments
Labels
bug Type: Something isn't working

Comments

@gitmewai
Copy link

gitmewai commented Feb 8, 2023

Description

Our v0.73.0 node was re-created by renaming the db folder and then with a hedera.mirror.importer.startDate configured as within 24 hours. The node got fully synced within 16 hours.

However, we found from the log that the BalanceReconciliationService did not complete successfully.

Feb 08 00:00:00 hedera-mirror-1 hedera-mirror[11010]: importer_1  | 2023-02-07T18:00:00.009-0600 INFO scheduling-1 c.h.m.i.r.BalanceReconciliationService Reconciling balance files between 1970-01-01T00:00:00Z and 2262-04-11T23:47:16.854775807Z with FAIL remediation strategy
Feb 08 00:00:04 hedera-mirror-1 hedera-mirror[11010]: importer_1  | 2023-02-07T18:00:04.168-0600 WARN scheduling-1 c.h.m.i.r.BalanceReconciliationService Reconciliation completed unsuccessfully after 0 balance files in 4.168 s: Crypto transfers did not reconcile in range (1675641601590035000, 1675642500848254000]: not equal: only on right={1871708=0, 1871709=0, 1871710=0, 1871711=0, 1871704=0, 1871705=0, 1871706=0, 1871707=0, 1871700=0, 1871701=0, 1871702=0, 1871703=0, 1871696=0, 1871697=0, 1871698=0, 1871699=0, 1871693=0, 1871694=0, 1871695=0, 1871740=0, 1871741=0, 1871742=0, 1871743=0, 1871736=0, 1871737=0, 1871738=0, 1871739=0, 1871732=0, 1871733=0, 1871734=0, 1871735=0, 1871728=0, 1871729=0, 1871730=0, 1871731=0, 1871724=0, 1871725=0, 1871726=0, 1871727=0, 1871720=0, 1871721=0, 1871722=0, 1871723=0, 1871717=0, 1871718=0, 1871719=0, 1871712=0, 1871713=0, 1871714=0, 1871715=0, 1871760=0, 1871761=0, 1871762=0, 1871763=0, 1871756=0, 1871757=0, 1871758=0, 1871759=0, 1871752=0, 1871753=0, 1871754=0, 1871755=0, 1871748=0, 1871749=0, 1871750=0, 1871751=0, 1871744=0, 1871745=0, 1871746=0, 1871747=0}: value differences={3=(14398569082421, 14398569210527), 4=(3143085581514, 3143085617099), 5=(4605141330748, 4605141422004), 8=(4032817812561, 4032818175528), 9=(3913784259017, 3913784557931), 11=(4007946512074, 4007946768286), 12=(2730403009674, 2730403230301), 14=(3613491876683, 3613491954970), 15=(3424659610940, 3424665628551), 16=(3503044514071, 3503044613709), 17=(3350369921919, 3350370085610), 18=(4001781727716, 4001781919875), 19=(3955507378595, 3955507592105), 23=(1315600923461, 1315600929313), 98=(1254976935724355, 1254976980375829), 732549=(756655687038, 756649442885), 1459478=(68279665624883, 68279619053147)}

Steps to reproduce

  1. docker-compose down
  2. rename db folder
  3. upgrade the hedera-mirror-node version from v0.72.0 to v0.73.0
  4. docker-compose up
  5. new db folder is created
  6. wait for BalanceReconciliationService to start at 00:00:00

Additional context

No response

Hedera network

mainnet

Version

v0.73.0

Operating system

Linux

@gitmewai gitmewai added the bug Type: Something isn't working label Feb 8, 2023
@steven-sheehy
Copy link
Member

steven-sheehy commented Feb 8, 2023

Do you have all the data in your mainnet database going back to Sep 2019?

@gitmewai
Copy link
Author

gitmewai commented Feb 9, 2023

We only configured the following in application.yml:

hedera:
  mirror:
    importer:
      downloader:
        accessKey: xxx
        cloudProvider: "xxx"
        gcpProjectId: xxx
        secretKey: xxx
        bucketName: hedera-mainnet-streams
      network: MAINNET
      retention:
        enabled: true
        period: 28d
      startDate: 2023-02-06T00:00:00Z
    monitor:
      network: MAINNET
      mirrorNode:
        grpc:
          host: hedera-mirror_grpc_1
        rest:
          host: hedera-mirror_rest_1
    rosetta:
      network: MAINNET

And there should be no data going back to Sep 2019 as even without startDate defined in application.yml and when the database is empty (because we renamed db folder), startDate should take the value of NOW when the process starts.

@steven-sheehy
Copy link
Member

You have to explicitly set startDate=2019 or earlier on an empty database if you want all data going back to genesis. Since you did not do that and have partial data, reconciliation job will not reconcile. You can disable the job via hedera.mirror.importer.reconciliation.enabled=false.

@gitmewai
Copy link
Author

With the partial data, what would be the actual impact if the reconciliation job is not completed successfully? What kind of the queries will return incorrect values as a result?

And which balance files are involved by the reconciliation job?

In other words, what is the proper way to enable retention on a running node by removing the data from year 2019 up to (now - 28) days ago?

Thanks.

@steven-sheehy
Copy link
Member

The reconciliation job is just an informational job mainly for alerting Hedera of issues with the stream files. It does not take action from the results of its execution, so it can always be safely disabled.

All balances files present in the db are used by the job.

If you had all data then enabled retention then there's no problem. If you had startDate set to current time (e.g. partial mirror node) then you will want to reinitialize the entity balances so they're correct.

@gitmewai
Copy link
Author

Thanks @steven-sheehy . How can I verify the reinitialization is completed successfully (i.e. how to confirm the entity balances are correct, and which entities are available after the InitializeEntityBalanceMigration job execution)? I can only see the following from the log:

From node #1:

Feb 14 05:45:04 hedera-mirror-1 hedera-mirror[24683]: importer_1  | 2023-02-13T23:45:04.220-0600 INFO main o.f.c.i.c.DbMigrate Migrating schema "public" with repeatable migration "Initialize entity balance"
Feb 14 05:45:07 hedera-mirror-1 hedera-mirror[24683]: importer_1  | 2023-02-13T23:45:07.475-0600 INFO main c.h.m.i.m.InitializeEntityBalanceMigration Initialized 54015 entities balance in 3.251 s
Feb 14 05:45:07 hedera-mirror-1 hedera-mirror[24683]: importer_1  | 2023-02-13T23:45:07.476-0600 INFO main c.h.m.i.m.InitializeEntityBalanceMigration Ran migration Initialize entity balance in 3.252 s.

From node #2:

Feb 14 09:48:46 hedera-mirror-2 hedera-mirror[417]: importer_1  | 2023-02-14T03:48:46.170-0600 INFO main o.f.c.i.c.DbMigrate Migrating schema "public" with repeatable migration "Initialize entity balance"
Feb 14 09:48:54 hedera-mirror-2 hedera-mirror[417]: importer_1  | 2023-02-14T03:48:54.180-0600 INFO main c.h.m.i.m.InitializeEntityBalanceMigration Initialized 145341 entities balance in 8.009 s
Feb 14 09:48:54 hedera-mirror-2 hedera-mirror[417]: importer_1  | 2023-02-14T03:48:54.180-0600 INFO main c.h.m.i.m.InitializeEntityBalanceMigration Ran migration Initialize entity balance in 8.009 s.

Thanks again!

@steven-sheehy
Copy link
Member

You can compare the real-time balance in entity.balance for specific accounts matches what's in the balance file.

@steven-sheehy
Copy link
Member

@gitmewai Can we close this?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Type: Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants