[bisq-network/bisq] Improve DAO state store persistence and statistics logging [chimp1984] (PR #5935)

jmacxx notifications at github.com
Fri Dec 24 01:46:11 CET 2021 

The first commit in this PR (https://github.com/bisq-network/bisq/commit/9378fe4603d2a0839e38baa03187a8cb0c1f5fb0) , written by @chimp1984, aims to improve the persistence of DAO state store files.

The motivation was from several user issues (#5929, #5917, #5925, #5934) which cropped up during the upgrade from 1.7.5 to 1.8.0.  Each log file provided in the issues showed an error during the persistence of DAO state store files while shutting down v1.7.5 (likely timing related) which then caused a problem of corrupted DAO state files manifested when v1.8.0 started up.  [The resolution for that](https://github.com/bisq-network/bisq/issues/5917#issuecomment-994911406) is to delete both DAO state files and let them be regenerated by the app at startup.


I have not managed to reproduce the users' issue, but I have tested this PR over several days, both regtest and mainnet.  The types of test performed were:

- SPV resync
- restore from seed
- repeated startup & shutdown
- new user sync
- leave running for extended periods & observe
- generate blocks




The second commit (https://github.com/bisq-network/bisq/commit/0b66fdcbef461cc3353fa33234bb034b6200d1e7) changes the stats logging to include the count of threads and adjust the frequency of logging from 5 minutes to 1 hour.  This change of frequency is requested by myself after checking many logs over the past 12 months the connection statistics being repeated every 5 minutes was too frequent, getting in the way of being able to read the log efficiently.


<details>
  <summary>Here is an example of the statistics logging:</summary>


    Dec-23 17:38:29.879 [JavaFX Application Thread] INFO  b.n.p2p.peers.PeerManager: Connection statistics: 

    Connection 1
    Age: 3 hours, 58 minutes, 59.264 seconds
    Peer: x7z5tvdcqqq6z5hat33qsj6qxyuglkv3ay2emsmugi2afjninufmbyad.onion:9999 
    Type: PEER 
    Direction: Outbound
    UID: c3756e7b-b151-4be0-b071-0cb0e78a1233
    Time since last message: 1.536 seconds
    Sent data: 4.226 MB; {AddDataMessage=1630, NewDaoStateHashMessage=30, AddPersistableNetworkPayloadMessage=153, RefreshOfferMessage=8106, RemoveDataMessage=96, NewBlockBroadcastMessage=23, GetPeersRequest=1, RemoveMailboxDataMessage=31, BundleOfEnvelopes=1830}
    Received data: 4.58 MB; {AddDataMessage=1746, NewDaoStateHashMessage=29, AddPersistableNetworkPayloadMessage=190, GetPeersResponse=1, RefreshOfferMessage=8953, RemoveDataMessage=106, NewBlockBroadcastMessage=23, RemoveMailboxDataMessage=36}
    CPU time spent on sending messages: 2.818 seconds
    CPU time spent on receiving messages: 26.082 seconds

    Connection 2
    Age: 3 hours, 58 minutes, 57.752 seconds
    Peer: s65qzl3rk2o4q4vk4q7tj7dt34caj7izzkyoehrydqczqnz73jdoorid.onion:9999 
    Type: PEER 
    Direction: Outbound
    UID: 814ffab5-934d-41a2-8b77-56337a478fd8
    Time since last message: 1.162 seconds
    Sent data: 4.212 MB; {AddDataMessage=1625, NewDaoStateHashMessage=30, AddPersistableNetworkPayloadMessage=175, RefreshOfferMessage=8387, RemoveDataMessage=99, NewBlockBroadcastMessage=23, GetPeersRequest=1, RemoveMailboxDataMessage=16, BundleOfEnvelopes=1846}
    Received data: 3.616 MB; {AddDataMessage=1381, NewDaoStateHashMessage=29, AddPersistableNetworkPayloadMessage=130, GetPeersResponse=1, RefreshOfferMessage=6906, NewBlockBroadcastMessage=21, RemoveDataMessage=91, RemoveMailboxDataMessage=30}
    CPU time spent on sending messages: 1.751 seconds
    CPU time spent on receiving messages: 16.251 seconds

    Connection 3
    Age: 3 hours, 58 minutes, 51.209 seconds
    Peer: 3rra3cwkvsxjry47fkwp7vgxgp3r3nequq6ra6rynpmibh5agn4w6fqd.onion:9999 
    Type: PEER 
    Direction: Outbound
    UID: c9052c04-f936-4bf3-8d01-4dc122377518
    Time since last message: 2.254 seconds
    Sent data: 4.282 MB; {AddDataMessage=1622, NewDaoStateHashMessage=29, AddPersistableNetworkPayloadMessage=160, RefreshOfferMessage=8218, RemoveDataMessage=109, NewBlockBroadcastMessage=29, GetPeersRequest=1, RemoveMailboxDataMessage=43, BundleOfEnvelopes=1841}
    Received data: 3.529 MB; {AddDataMessage=1327, NewDaoStateHashMessage=29, AddPersistableNetworkPayloadMessage=162, GetPeersResponse=1, RefreshOfferMessage=7029, RemoveDataMessage=92, NewBlockBroadcastMessage=18, RemoveMailboxDataMessage=24}
    CPU time spent on sending messages: 2.618 seconds
    CPU time spent on receiving messages: 20.609 seconds

    Connection 4
    Age: 3 hours, 58 minutes, 44.986 seconds
    Peer: icgsh6tgf3jf764l65uelqduc3zxvftuld35h74tgwuqugblphngk7qd.onion:9999 
    Type: PEER 
    Direction: Outbound
    UID: 30f2a431-dc9d-4bb3-96a3-a61203533e8d
    Time since last message: 2.042 seconds
    Sent data: 4.436 MB; {AddDataMessage=1712, NewDaoStateHashMessage=29, AddPersistableNetworkPayloadMessage=162, RefreshOfferMessage=8534, RemoveDataMessage=113, NewBlockBroadcastMessage=27, GetPeersRequest=1, RemoveMailboxDataMessage=20, BundleOfEnvelopes=1901}
    Received data: 3.773 MB; {AddDataMessage=1413, NewDaoStateHashMessage=29, AddPersistableNetworkPayloadMessage=127, GetPeersResponse=1, RefreshOfferMessage=7370, RemoveDataMessage=99, NewBlockBroadcastMessage=22, RemoveMailboxDataMessage=37}
    CPU time spent on sending messages: 1.819 seconds
    CPU time spent on receiving messages: 14.028 seconds

    Connection 5
    Age: 3 hours, 58 minutes, 25.881 seconds
    Peer: 2xcyvtyqqgcxrsrrucvg6kikppqxoj622aqw3b7nysson4an5xsufkid.onion:9999 
    Type: PEER 
    Direction: Outbound
    UID: 254db17f-0da0-48e0-b03a-d7c1b6539b92
    Time since last message: 1.357 seconds
    Sent data: 3.887 MB; {AddDataMessage=1387, NewDaoStateHashMessage=29, AddPersistableNetworkPayloadMessage=155, RefreshOfferMessage=8304, RemoveDataMessage=106, NewBlockBroadcastMessage=29, GetPeersRequest=1, RemoveMailboxDataMessage=34, BundleOfEnvelopes=1834}
    Received data: 3.767 MB; {AddDataMessage=1485, AddPersistableNetworkPayloadMessage=150, GetPeersResponse=1, RefreshOfferMessage=7264, RemoveDataMessage=78, RemoveMailboxDataMessage=10}
    CPU time spent on sending messages: 2.070 seconds
    CPU time spent on receiving messages: 18.766 seconds

    Connection 6
    Age: 2 hours, 54 minutes, 56.227 seconds
    Peer: fy25nlv6pphjvacqjvzm7kpjbwmiagx22aph7sdqyzwxw76qplzadqad.onion:9999 
    Type: PEER 
    Direction: Inbound
    UID: bc96dd0f-91b0-4a9d-bf41-256bdf0b83e0
    Time since last message: 1.616 seconds
    Sent data: 3.128 MB; {AddDataMessage=1215, NewDaoStateHashMessage=22, AddPersistableNetworkPayloadMessage=125, GetPeersResponse=1, RefreshOfferMessage=6132, RemoveDataMessage=67, NewBlockBroadcastMessage=21, RemoveMailboxDataMessage=10, BundleOfEnvelopes=1361}
    Received data: 3.322 MB; {AddDataMessage=1291, NewDaoStateHashMessage=22, AddPersistableNetworkPayloadMessage=117, RefreshOfferMessage=6557, RemoveDataMessage=67, NewBlockBroadcastMessage=21, GetPeersRequest=1, RemoveMailboxDataMessage=15}
    CPU time spent on sending messages: 1.308 seconds
    CPU time spent on receiving messages: 13.962 seconds

    Connection 7
    Age: 57 minutes, 31.993 seconds
    Peer: awfnnb67kg7xv5gn62q5kkgetsn5cefu2czirnk4lrpsfszuopubrnqd.onion:9999 
    Type: PEER 
    Direction: Outbound
    UID: 2edb6527-bb01-43c7-a621-64043913c7c3
    Time since last message: 1.764 seconds
    Sent data: 1.136 MB; {AddDataMessage=443, NewDaoStateHashMessage=8, AddPersistableNetworkPayloadMessage=45, RefreshOfferMessage=2411, RemoveDataMessage=23, NewBlockBroadcastMessage=7, GetPeersRequest=1, RemoveMailboxDataMessage=2, BundleOfEnvelopes=498}
    Received data: 689.273 kB; {AddDataMessage=254, NewDaoStateHashMessage=8, AddPersistableNetworkPayloadMessage=26, GetPeersResponse=1, RefreshOfferMessage=1553, RemoveDataMessage=15, NewBlockBroadcastMessage=7}
    CPU time spent on sending messages: 0.271 seconds
    CPU time spent on receiving messages: 4.983 seconds

    Connection 8
    Age: 37 minutes, 32.361 seconds
    Peer: aswlhotqhgfaicl22x6ijplv3disrxyxg3boegytb3j6q2cebqhqkkid.onion:9999 
    Type: PEER 
    Direction: Outbound
    UID: 10b3d3e7-e769-4964-a6f8-36880af66027
    Time since last message: 1.861 seconds
    Sent data: 697.281 kB; {AddDataMessage=273, NewDaoStateHashMessage=6, AddPersistableNetworkPayloadMessage=22, RefreshOfferMessage=1343, RemoveDataMessage=15, NewBlockBroadcastMessage=4, GetPeersRequest=1, BundleOfEnvelopes=293}
    Received data: 611.673 kB; {AddDataMessage=231, NewDaoStateHashMessage=6, AddPersistableNetworkPayloadMessage=22, GetPeersResponse=1, RefreshOfferMessage=1292, RemoveDataMessage=14, NewBlockBroadcastMessage=4}
    CPU time spent on sending messages: 0.424 seconds
    CPU time spent on receiving messages: 2.611 seconds
     
    Dec-23 17:38:53.216 [JavaFX Application Thread] INFO  b.n.p2p.network.Statistic: Accumulated network statistics:
    Bytes sent: 40.519 MB;
    Number of sent messages/Sent messages: 22260 / {PreliminaryGetDataRequest=2, NewDaoStateHashMessage=51, GetBlocksRequest=1, GetProposalStateHashesRequest=2, RefreshOfferMessage=4363, RemoveDataMessage=143, GetPeersRequest=12, BundleOfEnvelopes=16509, AddDataMessage=814, GetDaoStateHashesRequest=2, GetBlindVoteStateHashesRequest=2, AddPersistableNetworkPayloadMessage=291, GetPeersResponse=13, Ping=1, NewBlockBroadcastMessage=36, GetUpdatedDataRequest=2, RemoveMailboxDataMessage=15, Pong=1};
    Number of sent messages per sec: 1.5458333333333334;
    Bytes received: 36.465 MB
    Number of received messages/Received messages: 19804 / {NewDaoStateHashMessage=39, GetProposalStateHashesResponse=2, RefreshOfferMessage=3837, RemoveDataMessage=119, GetPeersRequest=13, GetBlindVoteStateHashesResponse=2, BundleOfEnvelopes=14734, AddDataMessage=729, GetDaoStateHashesResponse=2, AddPersistableNetworkPayloadMessage=252, GetPeersResponse=12, Ping=1, GetDataResponse=4, NewBlockBroadcastMessage=32, CloseConnectionMessage=11, RemoveMailboxDataMessage=13, GetBlocksResponse=1, Pong=1};
    Number of received messages per sec: 1.3752777777777778;
    Number of threads: 77


</details>
You can view, comment on, or merge this pull request online at:

  https://github.com/bisq-network/bisq/pull/5935

-- Commit Summary --

  * Patch from chimp1984 improving the DaoState persistence
  * Statistics logging changes

-- File Changes --

    M core/src/main/java/bisq/core/dao/monitoring/DaoStateMonitoringService.java (2)
    M core/src/main/java/bisq/core/dao/node/BsqNode.java (1)
    M core/src/main/java/bisq/core/dao/state/DaoStateSnapshotService.java (3)
    M core/src/main/java/bisq/core/dao/state/storage/DaoStateStorageService.java (53)
    M p2p/src/main/java/bisq/network/p2p/network/Statistic.java (10)
    M p2p/src/main/java/bisq/network/p2p/peers/PeerManager.java (2)

-- Patch Links --

https://github.com/bisq-network/bisq/pull/5935.patch
https://github.com/bisq-network/bisq/pull/5935.diff

-- 
Reply to this email directly or view it on GitHub:
https://github.com/bisq-network/bisq/pull/5935
You are receiving this because you are subscribed to this thread.

Message ID: <bisq-network/bisq/pull/5935 at github.com>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.bisq.network/pipermail/bisq-github/attachments/20211223/502d7f7d/attachment-0001.htm>

More information about the bisq-github mailing list