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.

Sign up for GitHub

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

Jump to bottom

two_node_network test in app_tests is failing #55

Closed
theoreticalbts opened this issue Jun 18, 2015 · 6 comments
Closed

two_node_network test in app_tests is failing #55

theoreticalbts opened this issue Jun 18, 2015 · 6 comments
Assignees
@nathanielhourt
Labels
needs testing p2p
Milestone
DevShares 2.0

Comments

@theoreticalbts
Copy link
Contributor

Test doesn't connect, which causes subsequent assert to segfault (it tries to get the first connected peer without checking if vector length is nonzero).
@vikramrajkumar
Copy link
Contributor

@emfrias Possibly related to currently broken p2p code.

@emfrias
Copy link
Collaborator

emfrias commented Jun 18, 2015

don't think so, the p2p errors shouldn't have mattered for that test. I've identified the change to block_database::open() as the cause (or at least, without that change, app_test passes)

2724939#diff-76b01416e354adac72143229e73775d8L12

[edit: that's not right. that file is to blame, but not the open() function]

@emfrias emfrias mentioned this issue Jun 18, 2015
Merged
@vikramrajkumar
Copy link
Contributor

Confirmed fixed by the patch above.

@nathanielhourt
Copy link
Contributor

This is still happening:

2912581ms th_a       thread.cpp:95                 thread               ] name:p2p tid:4598190080
2912582ms p2p        node.cpp:4111                 load_configuration   ] generating new private key for this node
2912582ms p2p        node.cpp:968                  trigger_p2p_network_ ] Triggering connect loop now
2912583ms p2p        node.cpp:4227                 listen_to_p2p_networ ] listening for connections on endpoint 127.0.0.1:3939 (our first choice)
2912584ms th_a       application.cpp:85            reset_p2p_node       ] Configured p2p node to listen on 127.0.0.1:3939
2912584ms p2p        node.cpp:875                  p2p_network_connect_ ] Starting an iteration of p2p_network_connect_loop().
2912584ms p2p        node.cpp:1619                 display_current_conn ] Currently have 0 of [20/200] connections
2912584ms p2p        node.cpp:1620                 display_current_conn ]    my id is c2f7efa23930bd8fc964a9bff2f5a2038ba6402b2783a8ae419fe1285978594f95
2912584ms p2p        node.cpp:1619                 display_current_conn ] Currently have 0 of [20/200] connections
2912584ms p2p        node.cpp:1620                 display_current_conn ]    my id is c2f7efa23930bd8fc964a9bff2f5a2038ba6402b2783a8ae419fe1285978594f95
2912584ms p2p        node.cpp:1014                 fetch_sync_items_loo ] beginning another iteration of the sync items loop
2912584ms p2p        node.cpp:1064                 fetch_sync_items_loo ] no sync items to fetch right now, going to sleep
2912584ms p2p        node.cpp:1098                 fetch_items_loop     ] beginning an iteration of fetch items (0 items to fetch)
2912584ms p2p        node.cpp:1169                 advertise_inventory_ ] beginning an iteration of advertise inventory
2912585ms p2p        node.cpp:4364                 dump_node_status     ] ----------------- PEER STATUS UPDATE --------------------
2912585ms p2p        node.cpp:4367                 dump_node_status     ]  number of peers: 0 active, 0, 0 closing.  attempting to maintain 20 - 200 peers
2912585ms p2p        node.cpp:4385                 dump_node_status     ] --------- MEMORY USAGE ------------
2912585ms p2p        node.cpp:4386                 dump_node_status     ] node._active_sync_requests size: 0
2912585ms p2p        node.cpp:4387                 dump_node_status     ] node._received_sync_items size: 0
2912585ms p2p        node.cpp:4388                 dump_node_status     ] node._new_received_sync_items size: 0
2912585ms p2p        node.cpp:4389                 dump_node_status     ] node._items_to_fetch size: 0
2912585ms p2p        node.cpp:4390                 dump_node_status     ] node._new_inventory size: 0
2912585ms p2p        node.cpp:4391                 dump_node_status     ] node._message_cache size: 0
2912585ms p2p        node.cpp:4401                 dump_node_status     ] --------- END MEMORY USAGE ------------
2912587ms th_a       application.cpp:169           startup              ] Allocating all stake to 5KQwrPbwdL6PhXujxW37FSSQZ1JiwsST4cqQzDeyXtP79zkvFD3
2912590ms th_a       thread.cpp:95                 thread               ] name:p2p tid:4611846144
2912590ms p2p        node.cpp:4111                 load_configuration   ] generating new private key for this node
2912591ms p2p        node.cpp:968                  trigger_p2p_network_ ] Triggering connect loop now
2912592ms th_a       application.cpp:74            reset_p2p_node       ] Adding seed node 127.0.0.1:3939
2912592ms p2p        node.cpp:968                  trigger_p2p_network_ ] Triggering connect loop now
2912592ms p2p        node.cpp:4304                 connect_to_endpoint  ] node_impl::connect_to_endpoint(127.0.0.1:3939)
2912592ms p2p        node.cpp:4227                 listen_to_p2p_networ ] listening for connections on endpoint 127.0.0.1:4040 (our first choice)
2912592ms p2p        node.cpp:3885                 accept_loop          ] accepted inbound connection from 127.0.0.1:58489
2912593ms th_a       application.cpp:85            reset_p2p_node       ] Configured p2p node to listen on 127.0.0.1:4040
2912603ms p2p        node.cpp:875                  p2p_network_connect_ ] Starting an iteration of p2p_network_connect_loop().
2912603ms p2p        node.cpp:1619                 display_current_conn ] Currently have 1 of [20/200] connections
2912603ms p2p        node.cpp:1620                 display_current_conn ]    my id is f3375cafb5cf73763d22a0ebcb8bff6245beb629fc5e720a45a7c3116bec828a22
2912603ms p2p        node.cpp:1634                 display_current_conn ]    handshaking: 127.0.0.1:3939 with 000000000000000000000000000000000000000000000000000000000000000000  [outbound]
2912603ms p2p        node.cpp:883                  p2p_network_connect_ ] Processing "add once" node list containing 1 peers:
2912603ms p2p        node.cpp:886                  p2p_network_connect_ ]     127.0.0.1:3939
2912603ms p2p        node.cpp:896                  p2p_network_connect_ ] Done processing "add once" node list
2912604ms p2p        node.cpp:1619                 display_current_conn ] Currently have 1 of [20/200] connections
2912604ms p2p        node.cpp:1620                 display_current_conn ]    my id is f3375cafb5cf73763d22a0ebcb8bff6245beb629fc5e720a45a7c3116bec828a22
2912604ms p2p        node.cpp:1634                 display_current_conn ]    handshaking: 127.0.0.1:3939 with 000000000000000000000000000000000000000000000000000000000000000000  [outbound]
2912604ms p2p        node.cpp:1014                 fetch_sync_items_loo ] beginning another iteration of the sync items loop
2912604ms p2p        node.cpp:1064                 fetch_sync_items_loo ] no sync items to fetch right now, going to sleep
2912604ms p2p        node.cpp:1098                 fetch_items_loop     ] beginning an iteration of fetch items (0 items to fetch)
2912604ms p2p        node.cpp:1169                 advertise_inventory_ ] beginning an iteration of advertise inventory
2912604ms p2p        node.cpp:4364                 dump_node_status     ] ----------------- PEER STATUS UPDATE --------------------
2912604ms p2p        node.cpp:4367                 dump_node_status     ]  number of peers: 0 active, 1, 0 closing.  attempting to maintain 20 - 200 peers
2912604ms p2p        node.cpp:4382                 dump_node_status     ]   handshaking peer 127.0.0.1:3939 in state ours(just_connected) theirs(just_connected)
2912604ms p2p        node.cpp:4385                 dump_node_status     ] --------- MEMORY USAGE ------------
2912604ms p2p        node.cpp:4386                 dump_node_status     ] node._active_sync_requests size: 0
2912604ms p2p        node.cpp:4387                 dump_node_status     ] node._received_sync_items size: 0
2912604ms p2p        node.cpp:4388                 dump_node_status     ] node._new_received_sync_items size: 0
2912604ms p2p        node.cpp:4389                 dump_node_status     ] node._items_to_fetch size: 0
2912604ms p2p        node.cpp:4390                 dump_node_status     ] node._new_inventory size: 0
2912604ms p2p        node.cpp:4391                 dump_node_status     ] node._message_cache size: 0
2912605ms p2p        node.cpp:4401                 dump_node_status     ] --------- END MEMORY USAGE ------------
2912605ms p2p        node.cpp:1645                 on_message           ] handling message hello_message_type 4591e3bfb6dc6ca1f023f5e01ade5bde736bb9e9 size 526 from peer 127.0.0.1:3939
2912606ms p2p        node.cpp:1961                 on_hello_message     ] Received a hello_message from peer 127.0.0.1:3939, sending reply to accept connection
2912606ms p2p        node.cpp:1645                 on_message           ] handling message connection_accepted_message_type 9c1185a5c5e9fc54612808977ee8f548b2258d31 size 0 from peer 127.0.0.1:58489
2912606ms p2p        node.cpp:4053                 connect_to_task      ] Sent "hello" to peer 127.0.0.1:3939
2912606ms p2p        node.cpp:1986                 on_connection_accept ] Received a connection_accepted in response to my "hello" from 127.0.0.1:58489
2912606ms p2p        node.cpp:1645                 on_message           ] handling message hello_message_type 2285e120b572e5da9ad0187369c811d2dbe77839 size 526 from peer 127.0.0.1:58489
2912606ms p2p        node.cpp:1645                 on_message           ] handling message address_request_message_type 9c1185a5c5e9fc54612808977ee8f548b2258d31 size 0 from peer 127.0.0.1:3939
2912606ms p2p        node.cpp:2043                 on_address_request_m ] Received an address request message
2912607ms p2p        node.cpp:1961                 on_hello_message     ] Received a hello_message from peer 127.0.0.1:58489, sending reply to accept connection
2912607ms p2p        node.cpp:1645                 on_message           ] handling message address_message_type c81b94933420221a7ac004a90242d8b1d3e5070d size 1 from peer 127.0.0.1:58489
2912607ms p2p        node.cpp:1645                 on_message           ] handling message connection_accepted_message_type 9c1185a5c5e9fc54612808977ee8f548b2258d31 size 0 from peer 127.0.0.1:3939
2912607ms p2p        node.cpp:2072                 on_address_message   ] Received an address message containing 0 addresses
2912607ms p2p        node.cpp:1986                 on_connection_accept ] Received a connection_accepted in response to my "hello" from 127.0.0.1:3939
2912607ms p2p        node.cpp:1996                 on_connection_accept ] I don't know if I'm firewalled.  Sending a firewall check message to peer 127.0.0.1:3939
2912608ms th_a       application.cpp:331           get_blockchain_synop ] reference_point: 0000000000000000000000000000000000000000 number_of_blocks_after_reference_point: 0 result: ["0000000000000000000000000000000000000000"]
2912615ms p2p        node.cpp:1645                 on_message           ] handling message current_time_request_message_type 9738ef4a2c8451a2dcb8210cb6306cf4c182e01c size 8 from peer 127.0.0.1:3939
2912615ms p2p        node.cpp:2284                 fetch_next_batch_of_ ] sync: sending a request for the next items after 0000000000000000000000000000000000000000 to peer 127.0.0.1:58489, (full request is ["0000000000000000000000000000000000000000"])
2912615ms p2p        node.cpp:1645                 on_message           ] handling message address_request_message_type 9c1185a5c5e9fc54612808977ee8f548b2258d31 size 0 from peer 127.0.0.1:58489
2912616ms p2p        node.cpp:2043                 on_address_request_m ] Received an address request message
2912616ms p2p        node.cpp:1645                 on_message           ] handling message fetch_blockchain_item_ids_message_type 64fb04b7185d8fb73d7c4938215f09bb007b33a0 size 25 from peer 127.0.0.1:3939
2912621ms p2p        node.cpp:2126                 on_fetch_blockchain_ ] sync: received a request for item ids after {"item_type":1001,"item_hash":"0000000000000000000000000000000000000000"} from peer 127.0.0.1:3939 (full request: ["0000000000000000000000000000000000000000"])
2912621ms p2p        node.cpp:1645                 on_message           ] handling message check_firewall_message_type 2a9597be4ab20f69ce57c3504db6327b45617915 size 39 from peer 127.0.0.1:58489
2912621ms p2p        node.cpp:3314                 on_check_firewall_me ] Peer 127.0.0.1:58489 wants us to check whether it is firewalled
2912621ms p2p        node.cpp:2137                 on_fetch_blockchain_ ] reply_message: {"total_remaining_item_count":0,"item_type":1001,"item_hashes_available":[]} fetch_blockchain_item_ids_message_received.blockchain_synopsis: ["0000000000000000000000000000000000000000"]
2912621ms p2p        node.cpp:3288                 forward_firewall_che ] Unable to forward firewall check for node 127.0.0.1:4040 to any other peers, returning 'unable'
2912625ms p2p        node.cpp:2157                 on_fetch_blockchain_ ] sync: peer is already in sync with us
2912625ms p2p        node.cpp:1645                 on_message           ] handling message current_time_reply_message_type 3531dcb1242d6916afd612ef38d10b577a0756fb size 24 from peer 127.0.0.1:58489
2912625ms p2p        node.cpp:1645                 on_message           ] handling message address_message_type ce4826c4f6ff676d31b2e3ceb52f7e07216e8f45 size 54 from peer 127.0.0.1:3939
2912626ms p2p        node.cpp:2072                 on_address_message   ] Received an address message containing 1 addresses
2912626ms p2p        node.cpp:1645                 on_message           ] handling message blockchain_item_ids_inventory_message_type 67c6fdf3cff497eefe3771d6d17fea69791725a4 size 9 from peer 127.0.0.1:58489
2912626ms p2p        node.cpp:2300                 on_blockchain_item_i ] sync: received a list of 0 available items from 127.0.0.1:58489
2912626ms p2p        node.cpp:2315                 on_blockchain_item_i ] sync: peer said we're up-to-date, entering normal operation with this peer
2912626ms p2p        node.cpp:2075                 on_address_message   ]     127.0.0.1:58489 last seen 2015-06-19T14:48:32
2912626ms p2p        node.cpp:968                  trigger_p2p_network_ ] Triggering connect loop now
2912626ms p2p        node.cpp:1645                 on_message           ] handling message current_time_request_message_type 1df558adec4d89665ae24e526ed87629fc529a5c size 8 from peer 127.0.0.1:58489
2912626ms th_a       application.cpp:331           get_blockchain_synop ] reference_point: 0000000000000000000000000000000000000000 number_of_blocks_after_reference_point: 0 result: ["0000000000000000000000000000000000000000"]
2912626ms p2p        node.cpp:2284                 fetch_next_batch_of_ ] sync: sending a request for the next items after 0000000000000000000000000000000000000000 to peer 127.0.0.1:3939, (full request is ["0000000000000000000000000000000000000000"])
2912627ms p2p        node.cpp:1645                 on_message           ] handling message fetch_blockchain_item_ids_message_type 64fb04b7185d8fb73d7c4938215f09bb007b33a0 size 25 from peer 127.0.0.1:58489
2912627ms p2p        node.cpp:1645                 on_message           ] handling message check_firewall_reply_message_type 67ac11705e711367106a8f116afc6276d89f4b25 size 40 from peer 127.0.0.1:3939
2912627ms p2p        node.cpp:2126                 on_fetch_blockchain_ ] sync: received a request for item ids after {"item_type":1001,"item_hash":"0000000000000000000000000000000000000000"} from peer 127.0.0.1:58489 (full request: ["0000000000000000000000000000000000000000"])
2912627ms p2p        node.cpp:3413                 on_check_firewall_re ] Firewall check we initiated has returned with result: unable_to_check, endpoint = 127.0.0.1:4040
2912627ms p2p        node.cpp:2137                 on_fetch_blockchain_ ] reply_message: {"total_remaining_item_count":0,"item_type":1001,"item_hashes_available":[]} fetch_blockchain_item_ids_message_received.blockchain_synopsis: ["0000000000000000000000000000000000000000"]
2912627ms p2p        node.cpp:2157                 on_fetch_blockchain_ ] sync: peer is already in sync with us
2912627ms p2p        node.cpp:1645                 on_message           ] handling message current_time_reply_message_type b175979ed3d82dc1ad8149d12149b658ea6ec731 size 24 from peer 127.0.0.1:3939
2912630ms p2p        node.cpp:2719                 on_connection_closed ] Remote peer 127.0.0.1:58489 closed their connection to us
2912630ms p2p        node.cpp:1619                 display_current_conn ] Currently have 0 of [20/200] connections
2912630ms p2p        node.cpp:1620                 display_current_conn ]    my id is c2f7efa23930bd8fc964a9bff2f5a2038ba6402b2783a8ae419fe1285978594f95
2912630ms p2p        node.cpp:968                  trigger_p2p_network_ ] Triggering connect loop now
2912630ms p2p        node.cpp:1528                 schedule_peer_for_de ] scheduling peer for deletion: ${peer} (this will not block)
2912630ms p2p        node.cpp:1533                 schedule_peer_for_de ] asyncing delayed_peer_deletion_task to delete 1 peers
2912631ms p2p        node.cpp:1492                 delayed_peer_deletio ] beginning an iteration of delayed_peer_deletion_task with 1 in queue
2912631ms p2p        node.cpp:2719                 on_connection_closed ] Remote peer 127.0.0.1:3939 closed their connection to us
2912631ms p2p        node.cpp:1619                 display_current_conn ] Currently have 0 of [20/200] connections
2912631ms p2p        node.cpp:1620                 display_current_conn ]    my id is f3375cafb5cf73763d22a0ebcb8bff6245beb629fc5e720a45a7c3116bec828a22
2912631ms p2p        node.cpp:968                  trigger_p2p_network_ ] Triggering connect loop now
2912631ms p2p        node.cpp:1528                 schedule_peer_for_de ] scheduling peer for deletion: ${peer} (this will not block)
2912631ms p2p        node.cpp:1533                 schedule_peer_for_de ] asyncing delayed_peer_deletion_task to delete 1 peers
2912631ms p2p        node.cpp:1492                 delayed_peer_deletio ] beginning an iteration of delayed_peer_deletion_task with 1 in queue
2912631ms p2p        node.cpp:1495                 delayed_peer_deletio ] leaving delayed_peer_deletion_task
2912631ms p2p        node.cpp:1495                 delayed_peer_deletio ] leaving delayed_peer_deletion_task
tests/app/main.cpp:64: fatal error in "two_node_network": critical check app1.p2p_node()->get_connection_count() == 1 failed [0 != 1]
2913107ms th_a       node.cpp:4933                 close                ] .... WARNING NOT DOING ANYTHING WHEN I SHOULD ......
2913108ms p2p        node.cpp:817                  ~node_impl           ] cleaning up node
2913108ms p2p        node.cpp:836                  ~node_impl           ] close
2913108ms p2p        node.cpp:3603                 close                ] P2P TCP server closed
2913108ms p2p        node.cpp:3617                 close                ] P2P accept loop terminated
2913108ms p2p        node.cpp:968                  trigger_p2p_network_ ] Triggering connect loop now
2913108ms p2p        node.cpp:3639                 close                ] P2P connect loop terminated
2913108ms p2p        node.cpp:3653                 close                ] Process backlog of sync items task terminated
2913108ms p2p        node.cpp:1075                 trigger_fetch_sync_i ] Triggering fetch sync items loop now
2913108ms p2p        node.cpp:3702                 close                ] Fetch sync items loop terminated
2913108ms p2p        node.cpp:3723                 close                ] Fetch items loop terminated
2913109ms p2p        node.cpp:3744                 close                ] Advertise inventory loop terminated
2913109ms p2p        node.cpp:3795                 close                ] Delayed peer deletion task terminated
2913109ms p2p        node.cpp:3814                 close                ] Terminate inactive connections loop terminated
2913109ms p2p        node.cpp:3828                 close                ] Fetch updated peer lists loop terminated
2913109ms p2p        node.cpp:3842                 close                ] Bandwidth monitor loop terminated
2913109ms p2p        node.cpp:3856                 close                ] Dump node status task terminated
2913109ms p2p        node.cpp:843                  ~node_impl           ] done
2913109ms th_a       node.cpp:756                  operator()           ] deleting the p2p thread
2913109ms th_a       thread.cpp:115                ~thread              ] calling quit() on p2p
2913109ms th_a       thread.cpp:160                quit                 ] destroying boost thread 4611846144
2913109ms p2p        thread.cpp:246                exec                 ] thread canceled: 9 canceled_exception: Canceled
cancellation reason: [none given]
    {"reason":"[none given]"}
    p2p  thread_d.hpp:463 start_next_fiber
2913110ms th_a       node.cpp:759                  operator()           ] done deleting the p2p thread
2913121ms th_a       node.cpp:4933                 close                ] .... WARNING NOT DOING ANYTHING WHEN I SHOULD ......
2913121ms p2p        node.cpp:817                  ~node_impl           ] cleaning up node
2913121ms p2p        node.cpp:836                  ~node_impl           ] close
2913121ms p2p        node.cpp:3603                 close                ] P2P TCP server closed
2913122ms p2p        node.cpp:3617                 close                ] P2P accept loop terminated
2913122ms p2p        node.cpp:968                  trigger_p2p_network_ ] Triggering connect loop now
2913122ms p2p        node.cpp:3639                 close                ] P2P connect loop terminated
2913122ms p2p        node.cpp:3653                 close                ] Process backlog of sync items task terminated
2913122ms p2p        node.cpp:1075                 trigger_fetch_sync_i ] Triggering fetch sync items loop now
2913122ms p2p        node.cpp:3702                 close                ] Fetch sync items loop terminated
2913122ms p2p        node.cpp:3723                 close                ] Fetch items loop terminated
2913122ms p2p        node.cpp:3744                 close                ] Advertise inventory loop terminated
2913122ms p2p        node.cpp:3795                 close                ] Delayed peer deletion task terminated
2913122ms p2p        node.cpp:3814                 close                ] Terminate inactive connections loop terminated
2913122ms p2p        node.cpp:3828                 close                ] Fetch updated peer lists loop terminated
2913122ms p2p        node.cpp:3842                 close                ] Bandwidth monitor loop terminated
2913123ms p2p        node.cpp:3856                 close                ] Dump node status task terminated
2913123ms p2p        node.cpp:843                  ~node_impl           ] done
2913123ms th_a       node.cpp:756                  operator()           ] deleting the p2p thread
2913123ms th_a       thread.cpp:115                ~thread              ] calling quit() on p2p
2913123ms th_a       thread.cpp:160                quit                 ] destroying boost thread 4598190080
2913123ms p2p        thread.cpp:246                exec                 ] thread canceled: 9 canceled_exception: Canceled
cancellation reason: [none given]
    {"reason":"[none given]"}
    p2p  thread_d.hpp:463 start_next_fiber
2913123ms th_a       node.cpp:759                  operator()           ] done deleting the p2p thread

@nathanielhourt
Copy link
Contributor

I note that this only occurs on some runs. On other runs, it connects and passes just fine.

@vikramrajkumar vikramrajkumar modified the milestone: alpha Jun 19, 2015
emfrias added a commit that referenced this issue Jun 20, 2015
@emfrias
Add wallet command for whitelisting accounts.
1b9ca9f 
Re-enable shutdown in node code which was causing some (not all) of the
errors in two_node_network test #55, and likely occasional crashes at
shutdown for the witness node
nathanielhourt added a commit that referenced this issue Jun 24, 2015
@nathanielhourt
Address #79: Should be fixed, but I can't test because of #55
44313ac
@nathanielhourt nathanielhourt mentioned this issue Jun 24, 2015
Closed
emfrias added a commit that referenced this issue Jun 25, 2015
@emfrias
Fix up application_impl's has_item() which was throwing to indicate a
49acfb3 
missing item instead of returning false.  #55
@nathanielhourt
Copy link
Contributor

Appears to be fixed.

@theoreticalbts theoreticalbts mentioned this issue Jul 14, 2015
Closed
@vikramrajkumar vikramrajkumar modified the milestones: alpha, devshares Aug 10, 2015
@vikramrajkumar vikramrajkumar mentioned this issue Jan 17, 2017
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@nathanielhourt nathanielhourt

Labels
needs testing p2p
Projects
None yet
Milestone
DevShares 2.0
Development

No branches or pull requests
4 participants
@nathanielhourt @vikramrajkumar @emfrias @theoreticalbts