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

Improving the request of tasks of TaskManager (2x) #900

Merged
merged 7 commits into from
Aug 6, 2019

Conversation

yongjiema
Copy link
Contributor

Fix #841

@shargon
Copy link
Member

shargon commented Jul 9, 2019

Please @yongjiema , take a look here yongjiema#2

{
if (!(message is TaskManager.NewTasks tasks)) return false;
// Remove duplicate tasks
if (queue.OfType<TaskManager.NewTasks>().Any(x => x.Payload.Type == tasks.Payload.Type && x.Payload.Hashes.SequenceEqual(tasks.Payload.Hashes))) return true;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
if (queue.OfType<TaskManager.NewTasks>().Any(x => x.Payload.Type == tasks.Payload.Type && x.Payload.Hashes.SequenceEqual(tasks.Payload.Hashes))) return true;
if (queue.OfType<TaskManager.NewTasks>().AsParallel().Any(x => x.Payload.Type == tasks.Payload.Type && x.Payload.Hashes.SequenceEqual(tasks.Payload.Hashes))) return true;

@vncoelho
Copy link
Member

vncoelho commented Jul 9, 2019

Great job and PR! Congrulations for tackling this issue.
TM: Task Manager
PH: ProtocolHandler
IHP: Is High Priority

TM-IHP: Consensus I AM...
PH-IHP: Consensus...
PH-IHP: Consensus...
TM-IHP: Consensus I AM...
TM-IHP: Consensus I AM...
[15:21:20.168] hash=0x6141e5d06780698b3b6022bd8f8fc58620efce8c3c82b46c692e05d27c6b8dc0
[15:21:20.169] OnPrepareResponseReceived: height=2 view=0 index=3 hash=0x6141e5d06780698b3b6022bd8f8fc58620efce8c3c82b46c692e05d27c6b8dc0
TM-IHP: Consensus I AM...
PH-IHP: Consensus...
TM-IHP: Consensus I AM...
[15:21:20.171] hash=0xd38d383d3f10ce2ce15cf194f1b8a6793f98c61074dbd87e64b4eb59eb966755
PH-IHP: Consensus...
OnGetDataMessageReceived(PH): 0x6141e5d06780698b3b6022bd8f8fc58620efce8c3c82b46c692e05d27c6b8dc0
OnGetDataMessageReceived(PH): 0x6141e5d06780698b3b6022bd8f8fc58620efce8c3c82b46c692e05d27c6b8dc0
TM-IHP: Consensus I AM...
TM-IHP: Consensus I AM...
[15:21:20.181] hash=0xdb101a414c8a09ad77e96b6bebac843918c35946df4cdcda87ebddecb3e1a6ca
[15:21:20.181] OnPrepareResponseReceived: height=2 view=0 index=1 hash=0xdb101a414c8a09ad77e96b6bebac843918c35946df4cdcda87ebddecb3e1a6ca
[15:21:20.183] send commit
PH-IHP: Consensus...
PH-IHP: Consensus...
TM-IHP: Consensus I AM...
OnGetDataMessageReceived(PH): 0x6141e5d06780698b3b6022bd8f8fc58620efce8c3c82b46c692e05d27c6b8dc0

Trying to understand this a lit bit more before merging. Let's extend the review for some more couple of days.

@vncoelho
Copy link
Member

vncoelho commented Jul 9, 2019

PH-IHP: Consensus...
OnInvMessageReceived(PH): Neo.UInt256[] Neo.UInt256[]
      printingPayloadHashes(PH): 0xfd5543305bb114f20390c66d84e12f5a594baae8b5d4db4a50a812ac5d0a6714
      printingHashesFiltered(PH): 0xfd5543305bb114f20390c66d84e12f5a594baae8b5d4db4a50a812ac5d0a6714
TM-IHP: Consensus I AM...
OnInvMessageReceived(PH): Neo.UInt256[] Neo.UInt256[]
      printingPayloadHashes(PH): 0xfd5543305bb114f20390c66d84e12f5a594baae8b5d4db4a50a812ac5d0a6714
      printingHashesFiltered(PH): 0xfd5543305bb114f20390c66d84e12f5a594baae8b5d4db4a50a812ac5d0a6714
TM-IHP: Consensus I AM...
[15:43:39.249] hash=0xfd5543305bb114f20390c66d84e12f5a594baae8b5d4db4a50a812ac5d0a6714
OnInvMessageReceived(PH): Neo.UInt256[] Neo.UInt256[]
      printingPayloadHashes(PH): 0xfd5543305bb114f20390c66d84e12f5a594baae8b5d4db4a50a812ac5d0a6714
      printingHashesFiltered(PH): 0xfd5543305bb114f20390c66d84e12f5a594baae8b5d4db4a50a812ac5d0a6714
TM-IHP: Consensus I AM...
[15:43:39.284] OnRecoveryRequestReceived: height=1 index=1 view=0 hash=0xfd5543305bb114f20390c66d84e12f5a594baae8b5d4db4a50a812ac5d0a6714
[15:43:39.284] send recovery: view=0 
OnInvMessageReceived(PH): Neo.UInt256[] Neo.UInt256[]
      printingPayloadHashes(PH): 0xc6c1944ae7da001698b6cdf73d7dcc1d930769767a8f7a7c61961ab7793615de
      printingHashesFiltered(PH): 0xc6c1944ae7da001698b6cdf73d7dcc1d930769767a8f7a7c61961ab7793615de
TM-IHP: Consensus I AM...
OnInvMessageReceived(PH): Neo.UInt256[] Neo.UInt256[]
      printingPayloadHashes(PH): 0xc6c1944ae7da001698b6cdf73d7dcc1d930769767a8f7a7c61961ab7793615de
      printingHashesFiltered(PH): 0xc6c1944ae7da001698b6cdf73d7dcc1d930769767a8f7a7c61961ab7793615de
TM-IHP: Consensus I AM...
OnInvMessageReceived(PH): Neo.UInt256[] Neo.UInt256[]
      printingPayloadHashes(PH): 0xc6c1944ae7da001698b6cdf73d7dcc1d930769767a8f7a7c61961ab7793615de
      printingHashesFiltered(PH): 0xc6c1944ae7da001698b6cdf73d7dcc1d930769767a8f7a7c61961ab7793615de
TM-IHP: Consensus I AM...
PH-IHP: Consensus...
[15:43:39.332] hash=0xc6c1944ae7da001698b6cdf73d7dcc1d930769767a8f7a7c61961ab7793615de
[15:43:39.346] OnRecoveryMessageReceived: height=1 view=0 index=2 hash=0xc6c1944ae7da001698b6cdf73d7dcc1d930769767a8f7a7c61961ab7793615de

@shargon
Copy link
Member

shargon commented Jul 9, 2019

@vncoelho please test it with my patch yongjiema#2, all works fine ?

@vncoelho
Copy link
Member

vncoelho commented Jul 9, 2019

Great, Shargon, these logs above where without this PR as well, still from the original code in master2x.
First trying to understand the duplication and then use this patch.
I will also consider yours as soon as possible, my friend.

@shargon
Copy link
Member

shargon commented Jul 9, 2019

I think that my patch break the consensus.....

@shargon
Copy link
Member

shargon commented Jul 9, 2019

Check this patch, #904 known hashes maybe was not working well

@vncoelho
Copy link
Member

vncoelho commented Jul 9, 2019

Sounds like a great finding, Shargon!

@vncoelho
Copy link
Member

vncoelho commented Jul 9, 2019

@yongjiema, were your tests done on last master-2x or using a released client?

Please check with this last patches.
Thanks for this indeepth analyses and great suggestions!

@yongjiema
Copy link
Contributor Author

yongjiema commented Jul 10, 2019

@yongjiema, were your tests done on last master-2x or using a released client?

Please check with this last patches.
Thanks for this indeepth analyses and great suggestions!

@vncoelho Tested on last master-2x, my local already have the fix which is same with the patch.

Copy link
Member

@shargon shargon left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think that we should use a cache with Merkle tree (for hashes) and merge this patch too. SequenceEqual could be very slow

@lock9
Copy link
Contributor

lock9 commented Jul 13, 2019

@KickSeason Could you confirm if this fixes the issue?

@shargon
Copy link
Member

shargon commented Jul 13, 2019

There are more duplicates after the known hashes fix?

@lock9
Copy link
Contributor

lock9 commented Jul 15, 2019

@shargon are you saying that the known hashes actually made this worse? 🤔
If this solves the problem, we need to apply this fix temporarily. Customers are complaining, we need this fix released ASAP.

@shargon
Copy link
Member

shargon commented Jul 15, 2019

not worse, only asking about if is still necessary

@vncoelho
Copy link
Member

Exactly, as @shargon is highlighting, we need the release 2.9.3 before merging this, being sure that this is a necessary change for master-2x. If that is good for 2x we are also going to apply for 3x.

@superboyiii
Copy link
Member

superboyiii commented Jul 22, 2019

@yongjiema I've applied this PR on one of Mainnet seed nodes and Testnet2 consensus nodes. Seems the empty block bug has been solved. But not sure it'll fix the sync stuck since I found the mainnet seed node stop syncing yesterday for several minutes but finally it returned back. And I found CPU and memory cost was increasing continuoulsy until reached a certain value. Then it became stable. I'll watch it for three more days to ensure if it fix sync stuck. Here's the log:
CPU MEM
[2019-07-16 05:04:11 PM-test_CPU_Memory.py-INFO:result: 0, output: root 29.5 8.9 dotnet]
[2019-07-16 05:34:11 PM-test_CPU_Memory.py-INFO:result: 0, output: root 29.8 8.7 dotnet]
[2019-07-16 06:04:11 PM-test_CPU_Memory.py-INFO:result: 0, output: root 30.1 8.7 dotnet]
[2019-07-16 06:34:11 PM-test_CPU_Memory.py-INFO:result: 0, output: root 30.4 8.8 dotnet]
[2019-07-16 07:04:12 PM-test_CPU_Memory.py-INFO:result: 0, output: root 30.7 8.9 dotnet]
[2019-07-16 07:34:12 PM-test_CPU_Memory.py-INFO:result: 0, output: root 31.0 9.0 dotnet]
[2019-07-16 08:04:12 PM-test_CPU_Memory.py-INFO:result: 0, output: root 31.3 9.2 dotnet]
[2019-07-16 08:34:12 PM-test_CPU_Memory.py-INFO:result: 0, output: root 31.6 9.4 dotnet]
[2019-07-16 09:04:12 PM-test_CPU_Memory.py-INFO:result: 0, output: root 31.8 9.6 dotnet]
[2019-07-16 09:34:12 PM-test_CPU_Memory.py-INFO:result: 0, output: root 32.1 9.7 dotnet]
[2019-07-16 10:04:13 PM-test_CPU_Memory.py-INFO:result: 0, output: root 32.4 10.1 dotnet]
[2019-07-16 10:34:13 PM-test_CPU_Memory.py-INFO:result: 0, output: root 32.6 9.9 dotnet]
[2019-07-16 11:04:13 PM-test_CPU_Memory.py-INFO:result: 0, output: root 32.9 10.2 dotnet]
[2019-07-16 11:34:13 PM-test_CPU_Memory.py-INFO:result: 0, output: root 33.1 10.7 dotnet]
[2019-07-17 12:04:14 AM-test_CPU_Memory.py-INFO:result: 0, output: root 33.4 10.7 dotnet]
[2019-07-17 12:34:14 AM-test_CPU_Memory.py-INFO:result: 0, output: root 33.6 11.0 dotnet]
[2019-07-17 01:04:15 AM-test_CPU_Memory.py-INFO:result: 0, output: root 33.8 11.0 dotnet]
[2019-07-17 01:34:15 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.0 11.3 dotnet]
[2019-07-17 02:04:15 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.2 11.0 dotnet]
[2019-07-17 02:34:16 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.5 11.6 dotnet]
[2019-07-17 03:04:16 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.6 12.0 dotnet]
[2019-07-17 03:34:16 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.8 11.0 dotnet]
[2019-07-17 04:04:16 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.0 10.9 dotnet]
[2019-07-17 04:34:16 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.1 11.3 dotnet]
[2019-07-17 05:04:17 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.3 11.2 dotnet]
[2019-07-17 05:34:17 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.5 11.3 dotnet]
[2019-07-17 06:04:17 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.6 10.7 dotnet]
[2019-07-17 06:34:17 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.8 11.8 dotnet]
[2019-07-17 07:04:17 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.9 12.6 dotnet]
[2019-07-17 07:34:18 AM-test_CPU_Memory.py-INFO:result: 0, output: root 36.1 12.3 dotnet]
[2019-07-17 08:04:18 AM-test_CPU_Memory.py-INFO:result: 0, output: root 36.2 12.3 dotnet]
[2019-07-17 08:34:18 AM-test_CPU_Memory.py-INFO:result: 0, output: root 36.4 12.9 dotnet]
[2019-07-17 09:04:18 AM-test_CPU_Memory.py-INFO:result: 0, output: root 36.5 12.8 dotnet]
[2019-07-17 09:34:20 AM-test_CPU_Memory.py-INFO:result: 0, output: root 36.6 13.4 dotnet]
[2019-07-17 10:04:20 AM-test_CPU_Memory.py-INFO:result: 0, output: root 36.8 13.6 dotnet]
[2019-07-17 10:34:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 36.9 14.0 dotnet]
[2019-07-17 11:04:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 37.1 13.7 dotnet]
[2019-07-17 11:34:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 37.2 14.0 dotnet]
[2019-07-17 11:41:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 24.9 22.8 dotnet]
[2019-07-17 11:43:01 AM-test_CPU_Memory.py-INFO:result: 0, output: root 24.9 23.9 dotnet]
[2019-07-17 12:13:01 PM-test_CPU_Memory.py-INFO:result: 0, output: root 25.1 23.5 dotnet]
[2019-07-17 12:43:01 PM-test_CPU_Memory.py-INFO:result: 0, output: root 25.4 23.7 dotnet]
[2019-07-17 01:13:01 PM-test_CPU_Memory.py-INFO:result: 0, output: root 25.6 24.0 dotnet]
[2019-07-17 01:43:01 PM-test_CPU_Memory.py-INFO:result: 0, output: root 25.9 25.0 dotnet]
[2019-07-17 02:13:02 PM-test_CPU_Memory.py-INFO:result: 0, output: root 26.1 24.4 dotnet]
[2019-07-17 02:43:02 PM-test_CPU_Memory.py-INFO:result: 0, output: root 26.4 24.8 dotnet]
[2019-07-17 03:13:02 PM-test_CPU_Memory.py-INFO:result: 0, output: root 26.6 25.5 dotnet]
[2019-07-17 03:43:02 PM-test_CPU_Memory.py-INFO:result: 0, output: root 26.8 26.1 dotnet]
[2019-07-17 04:13:02 PM-test_CPU_Memory.py-INFO:result: 0, output: root 27.1 26.4 dotnet]
[2019-07-17 04:43:02 PM-test_CPU_Memory.py-INFO:result: 0, output: root 27.5 26.8 dotnet]
[2019-07-17 05:13:02 PM-test_CPU_Memory.py-INFO:result: 0, output: root 28.0 26.7 dotnet]
[2019-07-17 05:43:03 PM-test_CPU_Memory.py-INFO:result: 0, output: root 28.5 23.5 dotnet]
[2019-07-17 06:13:03 PM-test_CPU_Memory.py-INFO:result: 0, output: root 28.8 24.9 dotnet]
[2019-07-17 06:43:03 PM-test_CPU_Memory.py-INFO:result: 0, output: root 29.2 25.3 dotnet]
[2019-07-17 07:13:03 PM-test_CPU_Memory.py-INFO:result: 0, output: root 29.5 25.2 dotnet]
[2019-07-17 07:43:03 PM-test_CPU_Memory.py-INFO:result: 0, output: root 29.8 25.0 dotnet]
[2019-07-17 08:13:03 PM-test_CPU_Memory.py-INFO:result: 0, output: root 30.1 26.4 dotnet]
[2019-07-17 08:43:03 PM-test_CPU_Memory.py-INFO:result: 0, output: root 30.4 25.4 dotnet]
[2019-07-17 09:13:03 PM-test_CPU_Memory.py-INFO:result: 0, output: root 30.7 27.2 dotnet]
[2019-07-17 09:43:04 PM-test_CPU_Memory.py-INFO:result: 0, output: root 30.9 26.9 dotnet]
[2019-07-17 10:13:04 PM-test_CPU_Memory.py-INFO:result: 0, output: root 31.1 27.3 dotnet]
[2019-07-17 10:43:04 PM-test_CPU_Memory.py-INFO:result: 0, output: root 31.4 26.8 dotnet]
[2019-07-17 11:13:04 PM-test_CPU_Memory.py-INFO:result: 0, output: root 31.6 27.1 dotnet]
[2019-07-17 11:43:04 PM-test_CPU_Memory.py-INFO:result: 0, output: root 31.9 25.8 dotnet]
[2019-07-18 12:13:04 AM-test_CPU_Memory.py-INFO:result: 0, output: root 32.1 25.7 dotnet]
[2019-07-18 12:43:04 AM-test_CPU_Memory.py-INFO:result: 0, output: root 32.3 26.6 dotnet]
[2019-07-18 01:13:05 AM-test_CPU_Memory.py-INFO:result: 0, output: root 32.5 26.9 dotnet]
[2019-07-18 01:43:05 AM-test_CPU_Memory.py-INFO:result: 0, output: root 32.7 27.4 dotnet]
[2019-07-18 02:13:05 AM-test_CPU_Memory.py-INFO:result: 0, output: root 32.9 27.5 dotnet]
[2019-07-18 02:43:05 AM-test_CPU_Memory.py-INFO:result: 0, output: root 33.1 27.1 dotnet]
[2019-07-18 03:13:05 AM-test_CPU_Memory.py-INFO:result: 0, output: root 33.3 28.3 dotnet]
[2019-07-18 03:43:06 AM-test_CPU_Memory.py-INFO:result: 0, output: root 33.5 28.7 dotnet]
[2019-07-18 04:13:06 AM-test_CPU_Memory.py-INFO:result: 0, output: root 33.6 29.2 dotnet]
[2019-07-18 04:43:06 AM-test_CPU_Memory.py-INFO:result: 0, output: root 33.8 26.0 dotnet]
[2019-07-18 05:13:06 AM-test_CPU_Memory.py-INFO:result: 0, output: root 33.9 26.4 dotnet]
[2019-07-18 05:43:06 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.1 26.7 dotnet]
[2019-07-18 06:13:06 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.2 27.2 dotnet]
[2019-07-18 06:43:07 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.3 27.2 dotnet]
[2019-07-18 07:13:07 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.4 27.3 dotnet]
[2019-07-18 07:43:07 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.5 27.3 dotnet]
[2019-07-18 08:13:07 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.6 28.0 dotnet]
[2019-07-18 08:43:07 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.7 28.3 dotnet]
[2019-07-18 09:13:07 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.8 29.3 dotnet]
[2019-07-18 09:43:07 AM-test_CPU_Memory.py-INFO:result: 0, output: root 34.9 29.1 dotnet]
[2019-07-18 10:13:07 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.1 29.7 dotnet]
[2019-07-18 10:43:08 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.3 29.6 dotnet]
[2019-07-18 11:13:08 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.4 27.1 dotnet]
[2019-07-18 11:43:08 AM-test_CPU_Memory.py-INFO:result: 0, output: root 35.5 26.1 dotnet]
[2019-07-18 12:13:08 PM-test_CPU_Memory.py-INFO:result: 0, output: root 35.7 27.3 dotnet]
[2019-07-18 12:43:08 PM-test_CPU_Memory.py-INFO:result: 0, output: root 35.8 27.6 dotnet]
[2019-07-18 01:13:08 PM-test_CPU_Memory.py-INFO:result: 0, output: root 36.0 27.8 dotnet]
[2019-07-18 01:43:08 PM-test_CPU_Memory.py-INFO:result: 0, output: root 36.1 27.8 dotnet]
[2019-07-18 02:13:09 PM-test_CPU_Memory.py-INFO:result: 0, output: root 36.2 28.2 dotnet]
[2019-07-18 02:43:09 PM-test_CPU_Memory.py-INFO:result: 0, output: root 36.3 28.7 dotnet]
[2019-07-18 03:13:09 PM-test_CPU_Memory.py-INFO:result: 0, output: root 36.4 29.0 dotnet]
[2019-07-18 03:43:09 PM-test_CPU_Memory.py-INFO:result: 0, output: root 36.6 28.7 dotnet]
[2019-07-18 04:13:09 PM-test_CPU_Memory.py-INFO:result: 0, output: root 36.7 29.1 dotnet]
[2019-07-18 04:43:09 PM-test_CPU_Memory.py-INFO:result: 0, output: root 36.8 29.9 dotnet]
[2019-07-18 05:13:09 PM-test_CPU_Memory.py-INFO:result: 0, output: root 36.9 29.7 dotnet]
[2019-07-18 05:43:09 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.0 27.0 dotnet]
[2019-07-18 06:13:10 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.0 27.6 dotnet]
[2019-07-18 06:43:10 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.1 27.4 dotnet]
[2019-07-18 07:13:10 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.2 27.5 dotnet]
[2019-07-18 07:43:10 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.3 27.9 dotnet]
[2019-07-18 08:13:10 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.4 28.0 dotnet]
[2019-07-18 08:43:10 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.5 28.0 dotnet]
[2019-07-18 09:13:10 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.6 29.2 dotnet]
[2019-07-18 09:43:10 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.6 28.4 dotnet]
[2019-07-18 10:13:10 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.7 29.0 dotnet]
[2019-07-18 10:43:11 PM-test_CPU_Memory.py-INFO:result: 0, output: root 37.8 29.4 dotnet]
[2019-07-18 11:13:11 PM-test_CPU_Memory.py-INFO:result: 0, output: root 38.0 29.5 dotnet]
[2019-07-18 11:43:11 PM-test_CPU_Memory.py-INFO:result: 0, output: root 38.1 26.4 dotnet]
[2019-07-19 12:13:11 AM-test_CPU_Memory.py-INFO:result: 0, output: root 38.2 27.1 dotnet]
[2019-07-19 12:43:11 AM-test_CPU_Memory.py-INFO:result: 0, output: root 38.3 27.2 dotnet]
[2019-07-19 01:13:11 AM-test_CPU_Memory.py-INFO:result: 0, output: root 38.5 27.7 dotnet]
[2019-07-19 01:43:11 AM-test_CPU_Memory.py-INFO:result: 0, output: root 38.6 28.1 dotnet]
[2019-07-19 02:13:12 AM-test_CPU_Memory.py-INFO:result: 0, output: root 38.7 28.3 dotnet]
[2019-07-19 02:43:12 AM-test_CPU_Memory.py-INFO:result: 0, output: root 38.8 28.6 dotnet]
[2019-07-19 03:13:12 AM-test_CPU_Memory.py-INFO:result: 0, output: root 38.9 29.3 dotnet]
[2019-07-19 03:43:12 AM-test_CPU_Memory.py-INFO:result: 0, output: root 38.9 29.4 dotnet]
[2019-07-19 04:13:12 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.0 29.6 dotnet]
[2019-07-19 04:43:12 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.1 30.7 dotnet]
[2019-07-19 05:13:13 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.2 27.4 dotnet]
[2019-07-19 05:43:13 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.3 27.6 dotnet]
[2019-07-19 06:13:13 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.3 27.7 dotnet]
[2019-07-19 06:43:13 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.4 28.0 dotnet]
[2019-07-19 07:13:14 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.5 28.6 dotnet]
[2019-07-19 07:43:14 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.5 28.9 dotnet]
[2019-07-19 08:13:14 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.6 29.4 dotnet]
[2019-07-19 08:43:14 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.6 29.1 dotnet]
[2019-07-19 09:13:14 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.7 29.4 dotnet]
[2019-07-19 09:43:14 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.8 30.2 dotnet]
[2019-07-19 10:13:14 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.8 30.3 dotnet]
[2019-07-19 10:43:15 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.9 31.0 dotnet]
[2019-07-19 11:13:15 AM-test_CPU_Memory.py-INFO:result: 0, output: root 39.9 27.7 dotnet]
[2019-07-19 11:43:15 AM-test_CPU_Memory.py-INFO:result: 0, output: root 40.0 27.9 dotnet]
[2019-07-19 12:13:15 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.0 27.9 dotnet]
[2019-07-19 12:43:15 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.1 28.3 dotnet]
[2019-07-19 01:13:15 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.2 28.5 dotnet]
[2019-07-19 01:43:16 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.2 29.9 dotnet]
[2019-07-19 02:13:16 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.3 29.5 dotnet]
[2019-07-19 02:43:16 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.4 30.2 dotnet]
[2019-07-19 03:13:16 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.5 30.2 dotnet]
[2019-07-19 03:43:16 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.6 30.5 dotnet]
[2019-07-19 04:13:16 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.6 31.2 dotnet]
[2019-07-19 04:43:17 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.8 31.0 dotnet]
[2019-07-19 05:13:17 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.8 28.1 dotnet]
[2019-07-19 05:43:17 PM-test_CPU_Memory.py-INFO:result: 0, output: root 40.9 28.6 dotnet]
[2019-07-19 06:13:18 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.0 29.0 dotnet]
[2019-07-19 06:43:18 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.0 29.3 dotnet]
[2019-07-19 07:13:18 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.1 29.6 dotnet]
[2019-07-19 07:43:18 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.2 29.6 dotnet]
[2019-07-19 08:13:18 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.2 30.9 dotnet]
[2019-07-19 08:43:18 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.3 30.5 dotnet]
[2019-07-19 09:13:19 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.4 31.5 dotnet]
[2019-07-19 09:43:19 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.5 31.7 dotnet]
[2019-07-19 10:13:19 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.6 31.9 dotnet]
[2019-07-19 10:43:19 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.7 29.1 dotnet]
[2019-07-19 11:13:20 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.8 29.5 dotnet]
[2019-07-19 11:43:20 PM-test_CPU_Memory.py-INFO:result: 0, output: root 41.9 29.8 dotnet]
[2019-07-20 12:13:20 AM-test_CPU_Memory.py-INFO:result: 0, output: root 41.9 30.1 dotnet]
[2019-07-20 12:43:20 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.0 30.5 dotnet]
[2019-07-20 01:13:20 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.0 30.7 dotnet]
[2019-07-20 01:43:20 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.1 31.0 dotnet]
[2019-07-20 02:13:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.1 31.2 dotnet]
[2019-07-20 02:43:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.1 32.0 dotnet]
[2019-07-20 03:13:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.2 31.9 dotnet]
[2019-07-20 03:43:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.2 29.2 dotnet]
[2019-07-20 04:13:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.2 29.5 dotnet]
[2019-07-20 04:43:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.3 29.7 dotnet]
[2019-07-20 05:13:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.3 30.0 dotnet]
[2019-07-20 05:43:21 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.3 30.2 dotnet]
[2019-07-20 06:13:22 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.3 30.5 dotnet]
[2019-07-20 06:43:22 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.3 30.7 dotnet]
[2019-07-20 07:13:22 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.3 31.1 dotnet]
[2019-07-20 07:43:22 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.3 31.4 dotnet]
[2019-07-20 08:13:22 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.3 31.6 dotnet]
[2019-07-20 08:43:23 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.3 31.8 dotnet]
[2019-07-20 09:13:23 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 32.0 dotnet]
[2019-07-20 09:43:23 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 32.3 dotnet]
[2019-07-20 10:13:23 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 29.3 dotnet]
[2019-07-20 10:43:23 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 29.8 dotnet]
[2019-07-20 11:13:23 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 30.2 dotnet]
[2019-07-20 11:43:24 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 30.3 dotnet]
[2019-07-20 12:13:24 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 30.4 dotnet]
[2019-07-20 12:43:24 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 31.1 dotnet]
[2019-07-20 01:13:24 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 30.9 dotnet]
[2019-07-20 01:43:24 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 31.2 dotnet]
[2019-07-20 02:13:24 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 31.3 dotnet]
[2019-07-20 02:43:25 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 31.3 dotnet]
[2019-07-20 03:13:25 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 32.0 dotnet]
[2019-07-20 03:43:25 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 31.8 dotnet]
[2019-07-20 04:13:25 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 32.3 dotnet]
[2019-07-20 04:43:25 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 32.4 dotnet]
[2019-07-20 05:13:25 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 29.6 dotnet]
[2019-07-20 05:43:25 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 29.8 dotnet]
[2019-07-20 06:13:25 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 30.1 dotnet]
[2019-07-20 06:43:26 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 30.3 dotnet]
[2019-07-20 07:13:26 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 30.8 dotnet]
[2019-07-20 07:43:26 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.4 30.9 dotnet]
[2019-07-20 08:13:26 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.5 31.2 dotnet]
[2019-07-20 08:43:26 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.5 31.5 dotnet]
[2019-07-20 09:13:27 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.5 31.7 dotnet]
[2019-07-20 09:43:27 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.5 31.9 dotnet]
[2019-07-20 10:13:27 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.5 32.3 dotnet]
[2019-07-20 10:43:27 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.6 32.5 dotnet]
[2019-07-20 11:13:27 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.6 32.7 dotnet]
[2019-07-20 11:43:27 PM-test_CPU_Memory.py-INFO:result: 0, output: root 42.6 29.1 dotnet]
[2019-07-21 12:13:28 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.6 29.3 dotnet]
[2019-07-21 12:43:28 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.7 29.5 dotnet]
[2019-07-21 01:13:28 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.7 29.8 dotnet]
[2019-07-21 01:43:28 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.7 30.1 dotnet]
[2019-07-21 02:13:28 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.8 30.3 dotnet]
[2019-07-21 02:43:28 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.8 30.8 dotnet]
[2019-07-21 03:13:28 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.9 30.8 dotnet]
[2019-07-21 03:43:29 AM-test_CPU_Memory.py-INFO:result: 0, output: root 42.9 31.1 dotnet]
[2019-07-21 04:13:29 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.0 31.4 dotnet]
[2019-07-21 04:43:29 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.1 31.6 dotnet]
[2019-07-21 05:13:29 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.2 31.8 dotnet]
[2019-07-21 05:43:29 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.2 32.3 dotnet]
[2019-07-21 06:13:29 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.3 32.3 dotnet]
[2019-07-21 06:43:29 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.3 30.0 dotnet]
[2019-07-21 07:13:30 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.4 29.8 dotnet]
[2019-07-21 07:43:30 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.5 30.1 dotnet]
[2019-07-21 08:13:30 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.5 30.4 dotnet]
[2019-07-21 08:43:30 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.5 30.7 dotnet]
[2019-07-21 09:13:30 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.6 30.8 dotnet]
[2019-07-21 09:43:30 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.6 31.1 dotnet]
[2019-07-21 10:13:30 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.7 31.4 dotnet]
[2019-07-21 10:43:31 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.7 31.7 dotnet]
[2019-07-21 11:13:31 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.8 31.8 dotnet]
[2019-07-21 11:43:31 AM-test_CPU_Memory.py-INFO:result: 0, output: root 43.8 32.4 dotnet]
[2019-07-21 12:13:31 PM-test_CPU_Memory.py-INFO:result: 0, output: root 43.9 32.6 dotnet]
[2019-07-21 12:43:31 PM-test_CPU_Memory.py-INFO:result: 0, output: root 43.9 32.6 dotnet]
[2019-07-21 01:13:31 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.0 32.9 dotnet]
[2019-07-21 01:43:32 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.0 30.7 dotnet]
[2019-07-21 02:13:32 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.1 30.5 dotnet]
[2019-07-21 02:43:32 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.1 30.5 dotnet]
[2019-07-21 03:13:32 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.2 31.0 dotnet]
[2019-07-21 03:43:32 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.3 30.9 dotnet]
[2019-07-21 04:13:32 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.3 31.3 dotnet]
[2019-07-21 04:43:32 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.4 31.4 dotnet]
[2019-07-21 05:13:33 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.4 31.9 dotnet]
[2019-07-21 05:43:33 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.5 32.2 dotnet]
[2019-07-21 06:13:33 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.6 32.5 dotnet]
[2019-07-21 06:43:33 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.6 32.8 dotnet]
[2019-07-21 07:13:33 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.7 33.1 dotnet]
[2019-07-21 07:43:33 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.7 34.0 dotnet]
[2019-07-21 08:13:33 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.8 33.9 dotnet]
[2019-07-21 08:43:34 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.8 31.0 dotnet]
[2019-07-21 09:13:34 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.8 31.1 dotnet]
[2019-07-21 09:43:34 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.8 31.5 dotnet]
[2019-07-21 10:13:34 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.9 32.1 dotnet]
[2019-07-21 10:43:34 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.9 32.5 dotnet]
[2019-07-21 11:13:34 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.9 32.2 dotnet]
[2019-07-21 11:43:35 PM-test_CPU_Memory.py-INFO:result: 0, output: root 44.9 32.3 dotnet]
[2019-07-22 12:13:35 AM-test_CPU_Memory.py-INFO:result: 0, output: root 44.9 32.6 dotnet]
[2019-07-22 12:43:35 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.0 32.7 dotnet]
[2019-07-22 01:13:35 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.0 33.6 dotnet]
[2019-07-22 01:43:35 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.0 33.4 dotnet]
[2019-07-22 02:13:35 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.0 33.3 dotnet]
[2019-07-22 02:43:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.0 30.6 dotnet]
[2019-07-22 03:13:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.0 30.9 dotnet]
[2019-07-22 03:43:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.4 dotnet]
[2019-07-22 04:13:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.1 dotnet]
[2019-07-22 04:43:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.8 dotnet]
[2019-07-22 05:13:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.9 dotnet]
[2019-07-22 05:43:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.4 dotnet]
[2019-07-22 06:13:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.7 dotnet]
[2019-07-22 06:43:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.2 dotnet]
[2019-07-22 07:13:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.3 dotnet]
[2019-07-22 07:43:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 34.2 dotnet]
[2019-07-22 08:13:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.0 34.1 dotnet]
[2019-07-22 08:43:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.0 31.1 dotnet]
[2019-07-22 09:13:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.2 dotnet]
[2019-07-22 09:43:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.3 dotnet]
[2019-07-22 10:13:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.9 dotnet]
[2019-07-22 10:43:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.1 dotnet]
[2019-07-22 11:13:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.3 dotnet]
[2019-07-22 11:43:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.6 dotnet]
[2019-07-22 12:13:39 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.9 dotnet]
[2019-07-22 12:43:39 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.1 dotnet]
[2019-07-22 01:13:39 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.7 dotnet]

@yongjiema
Copy link
Contributor Author

yongjiema commented Jul 22, 2019

@superboyiii

Seems the empty block bug has been solved.

Good to hear that!

But not sure it'll fix the sync stuck since I found the mainnet seed node stop syncing yesterday for several minutes but finally it returned back.

How long is it? Do you the result of show state command during that period? Is the system time correct at that node?

And I found CPU and memory cost was increasing continuoulsy until reached a certain value.

How much is the total memory? 4GB?

@superboyiii
Copy link
Member

superboyiii commented Jul 22, 2019

@yongjiema

How long is it? Do you the result of show state command during that period? Is the system time correct at that node?

Not sure. I use the monitor (https://seed.ngd.network/) to watch seed nodes' situation. I applied your version on seed8 for about 1 week and yesterday when I took a look, I found seed8 was about hundreds of blocks falling behind. However, in this morning, I found it was back to the latest. This monitor is using RPC request (getblockcount) to get block height.

How much is the total memory? 4GB?

8GB.

@superboyiii
Copy link
Member

I find when most seed nodes falled behind, your version still worked well. The sync stuck only appeared for a while and they soon catched up. Seems a good performance. The cost of CPU and MEM doesn't increase anymore.
image
[2019-07-22 03:43:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.4 dotnet]
[2019-07-22 04:13:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.1 dotnet]
[2019-07-22 04:43:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.8 dotnet]
[2019-07-22 05:13:36 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.9 dotnet]
[2019-07-22 05:43:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.4 dotnet]
[2019-07-22 06:13:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.7 dotnet]
[2019-07-22 06:43:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.2 dotnet]
[2019-07-22 07:13:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.3 dotnet]
[2019-07-22 07:43:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 34.2 dotnet]
[2019-07-22 08:13:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.0 34.1 dotnet]
[2019-07-22 08:43:37 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.0 31.1 dotnet]
[2019-07-22 09:13:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.2 dotnet]
[2019-07-22 09:43:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.3 dotnet]
[2019-07-22 10:13:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.9 dotnet]
[2019-07-22 10:43:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.1 dotnet]
[2019-07-22 11:13:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.3 dotnet]
[2019-07-22 11:43:38 AM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.6 dotnet]
[2019-07-22 12:13:39 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.9 dotnet]
[2019-07-22 12:43:39 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.1 dotnet]
[2019-07-22 01:13:39 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.7 dotnet]
[2019-07-22 01:43:39 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.7 dotnet]
[2019-07-22 02:13:39 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 33.9 dotnet]
[2019-07-22 02:43:40 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.8 dotnet]
[2019-07-22 03:13:40 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 31.6 dotnet]
[2019-07-22 03:43:40 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.3 dotnet]
[2019-07-22 04:13:40 PM-test_CPU_Memory.py-INFO:result: 0, output: root 45.1 32.5 dotnet]

@yongjiema
Copy link
Contributor Author

The sync stuck only appeared for a while and they soon catched up.

Then it should be OK, this is a case this PR try to handle it by commit (42d6b88), but we can introduce a faster solution in the future as I just want to do a small change previously.

…s higher than them if it is not updated for a while
@yongjiema
Copy link
Contributor Author

@superboyiii I just pushed a commit (eb5ec67) which can handle another sync problem.

@vncoelho
Copy link
Member

vncoelho commented Jul 22, 2019

@yongjiema, we pushed a PR with this last commit before, but at that time it was not accepted and kept with start height.

We need to remember the reason. Maybe something related to spam the network naturally. Not sure anymore, because other changes came after that.

But, in general, I agree, use the start height does not look so good without the ping.

Copy link
Member

@vncoelho vncoelho left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@yongjiema, @shargon, @erikzhang

The check && x.Payload.Hashes.SequenceEqual(tasks.Payload.Hashes) checks the entire sequence of the Payload, forcing a drop of natural rebroadcasted tasks, right?

However, an attack would still be possible if someone modifies the sequence of hashes, correct?

@shargon
Copy link
Member

shargon commented Jul 30, 2019

However, an attack would still be possible if someone modifies the sequence of hashes, correct?

Yes, or creating a new ones

igormcoelho
igormcoelho previously approved these changes Jul 31, 2019
Copy link
Contributor

@igormcoelho igormcoelho left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Congratulations, priceless contribution.

@yongjiema
Copy link
Contributor Author

yongjiema commented Jul 31, 2019

However, an attack would still be possible if someone modifies the sequence of hashes, correct?

@vncoelho This PR is not trying to resolve the existing potential network attacks, I think the solution of network attacks should be a basic strategy for all connections.

@erikzhang
Copy link
Member

please give me 3-5 days for another analyses and then I will approve it.

@vncoelho I will wait for your review before merging.


internal protected override bool ShallDrop(object message, IEnumerable queue)
{
if (!(message is TaskManager.NewTasks tasks)) return false;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@yongjiema, maybe add this case before the removal of duplicated tasks on line 285:
check if message is a task with tasks.Payload.Type == InventoryType.Consensus.

Because I believe that we do not need the next check for blocks, correct?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do you mean adding the below code between line 283 and line 285?

if (tasks.Payload.Type == InventoryType.Consensus) return false;

But I think it doesn't matter for Consensus or Block as both are high priority, I think you can try TX, but I think it may slow down the transaction broadcast.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I mean the contrary if (tasks.Payload.Type != InventoryType.Consensus) return false;
aehauheuaea

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can try it as most duplicated tasks are consensus, but it still got a chance to make the sync stuck or the empty block happen.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@yongjiema, what I am saying is exactly in this line of reasoning, to avoid the check for blocks, since the most duplicated are consensus. Thus, we would save some efficiency be not needing to check the Queue when it is not Consensus.

@vncoelho
Copy link
Member

vncoelho commented Aug 1, 2019

Please take a look at this log, the problem still persists, TaskManager is trying to process the same consensus payload twice.

OnReceive-CP-OnInventoryReceived(PH): **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799**        // Message arrives in Protocol Handler, goes to the switch and case `consensus`
OnInventoryReceived - Task **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799** completed (PH)    // It becomes IIventory of type Consensus and Task Manager and Local Nodes are notified

OnNewTasks(TM)-BGN-1147100768
OnNewTasks(TM)-BKS-1147100768:
       NewTaskHashesOnTM(TM)-1147100768: 0xae2edbad1dcc4754f85d1b073ae3b0e06f5c3cc7162341e61082718231acd4f5
OnNewTasks(TM)-AKS-1147100768-count: 0
OnNewTasks(TM)-AGT-1147100768-count: 0
OnInvMessageReceived(PH):
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-1803982457: 0x52971036eaca911a5982169cddd04d50dfc13e52b07c36fc491aa44a35f4282c
      printingPayloadHashes(PH)-847339451: 0x52971036eaca911a5982169cddd04d50dfc13e52b07c36fc491aa44a35f4282c
      printingHashesFiltered(PH)-847339451: 0x52971036eaca911a5982169cddd04d50dfc13e52b07c36fc491aa44a35f4282c
      printingHashesFiltered(PH)-1803982457: 0x52971036eaca911a5982169cddd04d50dfc13e52b07c36fc491aa44a35f4282c
TM-IHP: Consensus I AM...
TM-IHP: Consensus I AM...
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-2077882442: 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-1532328650: 0xae2edbad1dcc4754f85d1b073ae3b0e06f5c3cc7162341e61082718231acd4f5
      printingHashesFiltered(PH)-1532328650: 0xae2edbad1dcc4754f85d1b073ae3b0e06f5c3cc7162341e61082718231acd4f5
TM-IHP: Consensus I AM...
      printingHashesFiltered(PH)-2077882442: 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
TM-IHP: Consensus I AM...
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-1048543181: **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799** // OnInvMessageReceived of Protocol Handler notifies an InvPayload of Consensus
OnNewTasks(TM)-BGN-316305475 // TaskManager consequently receives it I
      printingHashesFiltered(PH)-1048543181: **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799** // Filtered from PH, almost the same as the previous msg from it, it is out of order
TM-IHP: Consensus I AM...
OnInvMessageReceived(PH):
OnNewTasks(TM)-BKS-316305475: // TaskManager consequently receives it II
       NewTaskHashesOnTM(TM)-316305475: 0x52971036eaca911a5982169cddd04d50dfc13e52b07c36fc491aa44a35f4282c // TaskManager consequently receives it III BUT THE Hash is different: 0x52971036eaca911a5982169cddd04d50dfc13e52b07c36fc491aa44a35f4282c
      printingPayloadHashes(PH)-2019427263: 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
      printingHashesFiltered(PH)-2019427263: 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
OnNewTasks(TM)-AKS-316305475-count: 0 // NO Consensus Payload was detected to be processed, it has been filtered 
OnNewTasks(TM)-AGT-316305475-count: 0 // NO Consensus Payload was detected to be processed, it has been filtered, OnNewTasks EXIT without reaching its END 
OnRelay(LN): **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799**
OnNewTasks(TM)-BGN-187516306
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-1403265557: **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799**  // OnInvMessageReceived of Protocol Handler notifies an InvPayload of Consensus
      printingHashesFiltered(PH)-1403265557: **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799**
OnNewTasks(TM)-BKS-187516306:
       NewTaskHashesOnTM(TM)-187516306: 0x52971036eaca911a5982169cddd04d50dfc13e52b07c36fc491aa44a35f4282c
OnNewTasks(TM)-AKS-187516306-count: 0
OnNewTasks(TM)-AGT-187516306-count: 0
OnNewTasks(TM)-BGN-95397302
OnNewTasks(TM)-BKS-95397302:
       NewTaskHashesOnTM(TM)-95397302: 0xae2edbad1dcc4754f85d1b073ae3b0e06f5c3cc7162341e61082718231acd4f5
OnNewTasks(TM)-AKS-95397302-count: 0
OnNewTasks(TM)-AGT-95397302-count: 0
OnNewTasks(TM)-BGN-2023390691
OnNewTasks(TM)-BKS-2023390691:
       NewTaskHashesOnTM(TM)-2023390691: 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
OnNewTasks(TM)-AKS-2023390691-count: 1
OnNewTasks(TM)-AGT-2023390691-count: 1
OnNewTasks(TM)-END-2023390691:
OnNewTasks(TM)-BGN-41171727 // TASK MANAGER BEGINS
OnNewTasks(TM)-BKS-41171727:
       NewTaskHashesOnTM(TM)-41171727: **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799**
OnNewTasks(TM)-AKS-41171727-count: 1
OnNewTasks(TM)-AGT-41171727-count: 1
OnNewTasks(TM)-END-41171727: // TASK MANAGER END, THIS TIME WITH SUCESS
[10:41:33.478] OnConsensusPayload hash=0x52971036eaca911a5982169cddd04d50dfc13e52b07c36fc491aa44a35f4282c
[10:41:33.479] OnCommitReceived: height=6 view=0 index=0 nc=1 nf=0 hash=0x52971036eaca911a5982169cddd04d50dfc13e52b07c36fc491aa44a35f4282c
PH-IHP: Consensus...
OnReceive-CP-OnInventoryReceived(PH): 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
OnInventoryReceived - Task 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c completed (PH)
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-2064377315: **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799** // OnInvMessageReceived of Protocol Handler notifies an InvPayload of Consensus
      printingHashesFiltered(PH)-2064377315: **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799**
TM-IHP: Consensus I AM...
OnRelay(LN): 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-56733811: 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
      printingHashesFiltered(PH)-56733811: 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
TM-IHP: Consensus I AM...
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-1727359454: 0x177a5167f86afe4f08b25a1e89c53cffc5d50d08ded669c83fc64941ff88e934
      printingHashesFiltered(PH)-1727359454: 0x177a5167f86afe4f08b25a1e89c53cffc5d50d08ded669c83fc64941ff88e934
TM-IHP: Consensus I AM...
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-376189730: **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799** // OnInvMessageReceived of Protocol Handler notifies an InvPayload of Consensus
      printingHashesFiltered(PH)-376189730: **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799**
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-1908722687: 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
      printingHashesFiltered(PH)-1908722687: 0xfcef703bd9f60a77e15e8a3b3d05e20fb6db24c100ad92857a164a159dbca62c
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-43468792: 0x177a5167f86afe4f08b25a1e89c53cffc5d50d08ded669c83fc64941ff88e934
      printingHashesFiltered(PH)-43468792: 0x177a5167f86afe4f08b25a1e89c53cffc5d50d08ded669c83fc64941ff88e934
OnNewTasks(TM)-BGN-1070228700
OnNewTasks(TM)-BKS-1070228700:
       NewTaskHashesOnTM(TM)-1070228700: **0xa1650e7ae34ff408e6b2122417e71857ab079ab38c254c2dfeacaefbd2a05799** // OnInvMessageReceived of Protocol Handler notifies an InvPayload of Consensus

While I was commenting the screen flushed...aheuahuea
I will try again with another example.

There is something really strange, please check the logs and comments attached @shargon @igormcoelho @erikzhang

@vncoelho
Copy link
Member

vncoelho commented Aug 1, 2019

@yongjiema, look how this is strange:

PH-IHP: Consensus... I
OnReceive-CP-OnInventoryReceived(PH) - II: 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnInventoryReceived - Task Completed will be called (PH): 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnInventoryReceived - Local Node Relay will be called (PH): 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnRelay(LN): 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-866702590: 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
      printingHashesFiltered(PH)-866702590: 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-384175155: 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
      printingHashesFiltered(PH)-384175155: 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnInvMessageReceived(PH):
      printingPayloadHashes(PH)-1779624940: 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
      printingHashesFiltered(PH)-1779624940: 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
TM-IHP: Consensus I AM...
TM-IHP: Consensus I AM...
TM-IHP: Consensus I AM...
OnNewTasks(TM)-BGN-1796313429
OnNewTasks(TM)-BKS-1796313429:
       NewTaskHashesOnTM(TM)-1796313429: 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnNewTasks(TM)-AKS-1796313429-count: 0
OnNewTasks(TM)-AGT-1796313429-count: 0
OnNewTasks(TM)-BGN-1931910902
OnNewTasks(TM)-BKS-1931910902:
       NewTaskHashesOnTM(TM)-1931910902: 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnNewTasks(TM)-AKS-1931910902-count: 0
OnNewTasks(TM)-AGT-1931910902-count: 0
OnNewTasks(TM)-BGN-950499347
OnNewTasks(TM)-BKS-950499347:
       NewTaskHashesOnTM(TM)-950499347: 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnNewTasks(TM)-AKS-950499347-count: 0
OnNewTasks(TM)-AGT-950499347-count: 0
[12:56:09.026] OnConsensusPayload hash=0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnRelay(RN): 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnRelay(RN): 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
OnRelay(RN): 0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6
[12:56:09.031] OnChangeViewReceived: height=1 view=0 index=0 nv=1 hash=0x030f32bb25d352a5358669c87d68659b839f4c6e5248924bda5b04692e54d5f6

I think that we are still missing a drop on protocol handler.

Copy link
Member

@vncoelho vncoelho left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

[13:29:16.554] OnConsensusPayload hash=0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
[13:29:16.555] OnCommitReceived: height=96 view=0 index=0 nc=2 nf=1 hash=0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
OnReceive-CP-OnInventoryReceived(PH) - II: 0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
OnInventoryReceived - Task Completed will be called (PH): 0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
OnInventoryReceived - Local Node Relay will be called (PH): 0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
OnReceive-CP-OnInventoryReceived(PH) - II: 0x859a3bf0f60930fd64f8af36dbf43adf24991690639b0c315feb5d5922475b42
OnInventoryReceived - Task Completed will be called (PH): 0x859a3bf0f60930fd64f8af36dbf43adf24991690639b0c315feb5d5922475b42
OnInventoryReceived - Local Node Relay will be called (PH): 0x859a3bf0f60930fd64f8af36dbf43adf24991690639b0c315feb5d5922475b42
OnReceive-CP-OnInventoryReceived(PH) - II: 0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
OnInventoryReceived - Task Completed will be called (PH): 0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
OnInventoryReceived - Local Node Relay will be called (PH): 0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
OnRelay(LN): 0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
OnRelay(LN): 0x859a3bf0f60930fd64f8af36dbf43adf24991690639b0c315feb5d5922475b42
OnRelay(LN): 0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
OnRelay(RN): 0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
OnRelay(RN): 0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
OnRelay(RN): 0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
OnRelay(RN): 0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
OnRelay(RN): 0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
[13:29:16.562] relay block: height=96 hash=0x31b1cd7104a0a9f15e1a308fde6822dc5678f724552fbf9f862a980dd1177aba tx=1
[13:29:16.563] OnConsensusPayload hash=0x03a899c6ba7478a1d767a7b298f88bf6216b7be3e0b2d272ce528aee01e960f8
[13:29:16.566] OnConsensusPayload hash=0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
OnRelay(RN): 0x03a899c6ba7478a1d767a7b298f88bf6216b7be3e0b2d272ce528aee01e960f8
OnRelay(RN): 0x03a899c6ba7478a1d767a7b298f88bf6216b7be3e0b2d272ce528aee01e960f8
OnRelay(RN): 0x03a899c6ba7478a1d767a7b298f88bf6216b7be3e0b2d272ce528aee01e960f8
OnRelay(RN): 0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
OnRelay(RN): 0x03a899c6ba7478a1d767a7b298f88bf6216b7be3e0b2d272ce528aee01e960f8
[13:29:16.570] OnConsensusPayload hash=0x03a899c6ba7478a1d767a7b298f88bf6216b7be3e0b2d272ce528aee01e960f8
[13:29:16.572] OnConsensusPayload hash=0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
[13:29:16.572] OnConsensusPayload hash=0x859a3bf0f60930fd64f8af36dbf43adf24991690639b0c315feb5d5922475b42
OnRelay(RN): 0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
OnRelay(RN): 0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
OnRelay(RN): 0x03a899c6ba7478a1d767a7b298f88bf6216b7be3e0b2d272ce528aee01e960f8
OnRelay(RN): 0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
OnRelay(RN): 0x262a68def5be892b70bfc5220a31f7b2845e3873f9920077d73d86a9656b3643
[13:29:16.573] OnConsensusPayload hash=0xb385ad6ddb6c91f6a5bfbeee1b376eb23cb2ef72cd95b75a1298033ecde68e47
  • Consensus nodes are still processing a ConsensusPayload twice.
  • There is still a leak or on TaskManager or at ProtocolHandler, which is allowing tasks to be processed twice.
  • In particular, ProtocolHandler is still processing several OnInvMessageReceived

In this sense, I am not in favor of the the merge of this fix until we really find how to remove the source of all these duplicated packages being processed.

@yongjiema, let's try to find this all together.
You already triggered us to investigate this. Thus, let's move on.

@vncoelho
Copy link
Member

vncoelho commented Aug 1, 2019

I am also thinking about renaming the issue to be more precise on what we are looking for.

@vncoelho vncoelho changed the title Fix sync stuck (2x) Fix duplicated processing of P2P tasks and payloads (2x) Aug 1, 2019
@vncoelho
Copy link
Member

vncoelho commented Aug 1, 2019

@yongjiema, @igormcoelho, @erikzhang, @shargon, maybe we can merge this.

The first change is:

  • Adding:
OR 
(Blockchain.Singleton.Height == Blockchain.Singleton.HeaderHeight 
&& Blockchain.Singleton.HeaderHeight >= sessions.Select(x => x.Value.Version.StartHeight).Max()
&& TimeProvider.Current.UtcNow.ToTimestamp() - 60 >= Blockchain.Singleton.GetBlock(Blockchain.Singleton.CurrentHeaderHash)?.Timestamp)

The first condition:

  1. Blockchain.Singleton.Height == Blockchain.Singleton.HeaderHeight, I believe it is good, because it ensures that node is synced until the last HeaderHeight and needs blocks of Headers, right?
  2. Blockchain.Singleton.HeaderHeight >= sessions.Select(x => x.Value.Version.StartHeight).Max(), make the request only if there is, at least, one session (with someone) that we know that is on higher heights, which gives us a signal that the current session can also have information to be given, right?
  3. TimeProvider.Current.UtcNow.ToTimestamp() - 60 >= Blockchain.Singleton.GetBlock(Blockchain.Singleton.CurrentHeaderHash)?.Timestamp, just do this request if 60s have passed, at least (avoiding spamming the network)

Could you create another PR with just this change of line 230 and then we try to find, completely, how to avoid duplicated tasks, invpayload and, consequently, single processing of ConsesusPayloads (by hash)?

I believe that there is no problem in merging this first part for both 2.x and 3.x.

@vncoelho
Copy link
Member

vncoelho commented Aug 1, 2019

log_4nodes_20s_blocks.txt

Please, take a look at this log and search for hash: 0x55673eb0cf0c939ee8e1e588b56d2429a7f1a6c6db682e4c41c9d6ce98b279e9

This was obtained with only 170 blocks of 20 seconds in a privatenet with 5 nodes (4CN + 1 RPC).
Image on the testnet or mainet?
There is still something that we need to handle.

I do not know why TaskCompleted is triggered quite quick:

OnReceive-CP-OnInventoryReceived(PH) - II: 0x55673eb0cf0c939ee8e1e588b56d2429a7f1a6c6db682e4c41c9d6ce98b279e9
      printingPayloadHashes(PH)-2081283276: 0x4911277fca18e38445d760edb7980725a66d03ae5033476c06e1ca7f8d8809d9
      printingPayloadHashes(PH)-1610240410: 0x97389c43ad730b6fa0868f86b3c600d17c68282c27b3d6c845557d003744cc75
OnInventoryReceived - Task Completed will be called (PH): 0x55673eb0cf0c939ee8e1e588b56d2429a7f1a6c6db682e4c41c9d6ce98b279e9

And then we still keep processing different OnInvMessageReceived.

Maybe the logs are out of order, but I do not think so, I also included random number for helping us in this hunt.

I believe that you solved the TaskManager @yongjiema, maybe we just need to kind of replicate this idea on ProtocolHandler now.

@vncoelho
Copy link
Member

vncoelho commented Aug 1, 2019

@shargon,
There might be still something wrong with FifoSet.

        private void OnInvMessageReceived(InvPayload payload)
        {
            UInt256[] hashes = payload.Hashes.Where(p => knownHashes.Add(p)).ToArray();
            if (hashes.Length == 0) return;

This should be enough for do not processing an InvPayload with the same hash twice

@vncoelho
Copy link
Member

vncoelho commented Aug 1, 2019

@shargon, we do not have the OrderedDictionary.cs file in the master2x, yes? We just use the native System.Collections.Specialized, right?

@shargon
Copy link
Member

shargon commented Aug 1, 2019

I am not sure if was tested with the last patch, maybe only without the knownhash patch, anyway, this PR is good.

@yongjiema
Copy link
Contributor Author

@vncoelho Hashes are possible duplicated at ProtocolHandler level (e.g. two nodes can request a block BLOCK_A as both of them are needed)

@vncoelho vncoelho dismissed stale reviews from igormcoelho and shargon via e4f106d August 4, 2019 12:37
@vncoelho vncoelho changed the title Fix duplicated processing of P2P tasks and payloads (2x) Improving the request of tasks of TaskManager (2x) Aug 4, 2019
Copy link
Member

@vncoelho vncoelho left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@yongjiema,

I modified the PR to just include the improvement on tasks requests.
During this week I will keep analyzing the other part of the PR in order that we completely solve these duplicated tasks.

In this sense, could you open another PR with this part of the code:

using System.Collections;

        internal protected override bool ShallDrop(object message, IEnumerable queue)
        {
            if (!(message is TaskManager.NewTasks tasks)) return false;
            // Remove duplicate tasks
            if (queue.OfType<TaskManager.NewTasks>().Any(x => x.Payload.Type == tasks.Payload.Type && x.Payload.Hashes.SequenceEqual(tasks.Payload.Hashes))) return true;
            return false;
        }

@yongjiema
Copy link
Contributor Author

@vncoelho Please check #997

lock9
lock9 previously requested changes Aug 5, 2019
Copy link
Contributor

@lock9 lock9 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hello,
We need some basic UT, it is not possible to test this without it.
Thanks

@vncoelho
Copy link
Member

vncoelho commented Aug 5, 2019

@erikzhang, this is ready to merge.

The other one I still want to investigate more regarding duplicated tasks.

@lock9 lock9 dismissed their stale review August 5, 2019 18:24

The rule is that reviewers must test before approving a PR. This PR does not have UT and cannot be tested locally, however, I won't stop other people from approving it.

@erikzhang erikzhang merged commit d083132 into neo-project:master-2.x Aug 6, 2019
Thacryba pushed a commit to simplitech/neo that referenced this pull request Feb 17, 2020
* Add some questions

* Fixes (neo-project#900)

* update English files and Chinese files

* update
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

8 participants