View Issue Details
|ID||Project||Category||View Status||Date Submitted||Last Update|
|0004718||GNUnet||testbed service||public||2016-10-10 17:47||2018-06-07 00:24|
|Reporter||Christian Grothoff||Assigned To||Sree Harsha Totakura|
|Platform||i7||OS||Debian GNU/Linux||OS Version||squeeze|
|Product Version||SVN HEAD|
|Target Version||0.11.0pre66||Fixed in Version||0.11.0pre66|
|Summary||0004718: assertion fails at testbed_api.c:1288.|
|Description||I'm getting this assertion failure when I run |
It is semi-clear what is going on (barrier_map is unexpectedly NULL), but the test passes regardless (!), so I don't know if this was always the case or is a regression. Also, I've not yet followed the test logic to see why we're getting this control event at this time. Further debug logic below.
|Steps To Reproduce||$ ./test_testbed_api_barriers |
Oct 10 17:43:28-884348 testbed-api-hosts-6917 DEBUG Adding host with id: 0
Oct 10 17:43:28-884455 test_testbed_api_barriers-6917 DEBUG Starting HELPER process `/home/grothoff/lib//gnunet/libexec/gnunet-helper-testbed'
Oct 10 17:43:28-885801 test_testbed_api_barriers-6917 DEBUG Transmitted 4556 bytes to /home/grothoff/lib//gnunet/libexec/gnunet-helper-testbed
Oct 10 17:43:28-892247 gnunet-helper-testbed-6931 DEBUG Starting testbed helper...
Oct 10 17:43:28-892336 gnunet-helper-testbed-6931 DEBUG Read 4556 bytes
Oct 10 17:43:28-896821 gnunet-helper-testbed-6931 DEBUG Staring testbed with config: /tmp/testbed-helperTuCwlI/0/config
Oct 10 17:43:28-898532 test_testbed_api_barriers-6917 DEBUG Got 4548 bytes from helper `/home/grothoff/lib//gnunet/libexec/gnunet-helper-testbed'
Oct 10 17:43:28-901391 testbed-api-testbed-6917 DEBUG Creating peers
Oct 10 17:43:28-906073 testbed-6932 DEBUG Starting testbed
Oct 10 17:43:28-906536 testbed-6932 DEBUG Testbed startup complete
Oct 10 17:43:28-906563 testbed-barriers-6932 DEBUG Launching testbed-barrier service
Oct 10 17:43:28-907616 testbed-6932 DEBUG Our IP: 127.0.0.1
Oct 10 17:43:28-908124 testbed-api-hosts-6932 DEBUG Adding host with id: 0
Oct 10 17:43:28-908144 testbed-6932 DEBUG Created master context with host ID: 0
Oct 10 17:43:28-909134 testbed-6932 DEBUG Creating peer with id: 0
Oct 10 17:43:28-912878 testbed-6932 DEBUG Creating peer with id: 1
Oct 10 17:43:28-916416 testbed-6932 DEBUG Creating peer with id: 2
Oct 10 17:43:28-919063 testbed-api-testbed-6917 DEBUG 3 peers created in 17 ms
Oct 10 17:43:28-919102 testbed-api-testbed-6917 DEBUG Starting Peers
Oct 10 17:43:28-919915 testbed-api-testbed-6917 DEBUG 3 peers started in 793 µs
Oct 10 17:43:28-919993 testbed-api-6917 DEBUG Initialising barrier `test_barrier'
Oct 10 17:43:28-920118 testbed-barriers-6932 DEBUG Received BARRIER_INIT for barrier `test_barrier'
Oct 10 17:43:28-920160 testbed-barriers-6932 DEBUG Sending GNUNET_TESTBED_BARRIERSTATUS_INITIALISED for barrier `test_barrier'
Oct 10 17:43:28-920230 testbed-api-6917 DEBUG Received BARRIER_STATUS msg
Oct 10 17:43:28-920273 test_testbed_api_barriers-6917 INFO Barrier initialised
Oct 10 17:43:33-049614 test-barriers-6946 DEBUG Waiting on barrier `test_barrier'
Oct 10 17:43:33-049787 testbed-barriers-6932 DEBUG Client connected to testbed-barrier service
Oct 10 17:43:33-049858 testbed-barriers-6932 DEBUG Received BARRIER_WAIT for barrier `test_barrier'
Oct 10 17:43:33-058468 test-barriers-6968 DEBUG Waiting on barrier `test_barrier'
Oct 10 17:43:33-058654 testbed-barriers-6932 DEBUG Client connected to testbed-barrier service
Oct 10 17:43:33-058706 testbed-barriers-6932 DEBUG Received BARRIER_WAIT for barrier `test_barrier'
Oct 10 17:43:35-066120 test-barriers-6967 DEBUG Waiting on barrier `test_barrier'
Oct 10 17:43:35-066288 testbed-barriers-6932 DEBUG Client connected to testbed-barrier service
Oct 10 17:43:35-066355 testbed-barriers-6932 DEBUG Received BARRIER_WAIT for barrier `test_barrier'
Oct 10 17:43:35-066524 testbed-api-6917 DEBUG Received BARRIER_STATUS msg
Oct 10 17:43:35-066600 test_testbed_api_barriers-6917 INFO Barrier crossed
Oct 10 17:43:35-066644 testbed-api-testbed-6917 DEBUG Shutting down peers
Oct 10 17:43:35-066779 testbed-barriers-6932 DEBUG Received BARRIER_STATUS for barrier `test_barrier'
Oct 10 17:43:35-066866 testbed-6932 DEBUG Received SHUTDOWN_PEERS
Oct 10 17:43:35-066889 testbed-6932 DEBUG Shutting down peers
Oct 10 17:43:35-066969 testbed-api-6917 DEBUG Received BARRIER_STATUS msg
Oct 10 17:43:35-067020 test_testbed_api_barriers-6917 WARNING External protocol violation detected at testbed_api.c:1288.
Oct 10 17:43:35-087076 testbed-barriers-6932 DEBUG Client disconnected from testbed-barrier service
Oct 10 17:43:35-087107 testbed-barriers-6932 DEBUG Client disconnected from testbed-barrier service
Oct 10 17:43:35-087116 testbed-barriers-6932 DEBUG Client disconnected from testbed-barrier service
Oct 10 17:43:35-087264 testbed-api-6917 DEBUG Received BARRIER_STATUS msg
Oct 10 17:43:35-087301 test_testbed_api_barriers-6917 WARNING External protocol violation detected at testbed_api.c:1288.
Oct 10 17:43:35-087323 testbed-api-6917 DEBUG Received BARRIER_STATUS msg
Oct 10 17:43:35-087337 test_testbed_api_barriers-6917 WARNING External protocol violation detected at testbed_api.c:1288.
Oct 10 17:43:35-087362 testbed-api-6917 DEBUG Operation 6 successful
Oct 10 17:43:35-087397 testbed-api-testbed-6917 DEBUG Peers shut down in 20 ms
Oct 10 17:43:35-087467 testbed-6932 DEBUG Master client disconnected
Oct 10 17:43:35-087635 gnunet-helper-testbed-6931 DEBUG STDIN closed
Oct 10 17:43:35-087681 gnunet-helper-testbed-6931 DEBUG Shutting down
Oct 10 17:43:35-087699 gnunet-helper-testbed-6931 DEBUG Killing testbed
Oct 10 17:43:35-088819 testbed-6932 DEBUG Shutting down testbed service
|Additional Information||Sree, it would be great if you could look into this one. I suspect you'll find & fix it faster than I can. You'll need SVN 38095 for the above line numbers and debug output, as I just migrated testbed to the new service API.|
|Tags||No tags attached.|
||ACK; will look into it.|
||Debugging reveals that the test driver is receiving BARRIER_CROSSED messages multiple times (equal to the number of peers running) instead of receiving it once.|
r38095 broke testbed barriers: upon handling BARRIER_STATUS from the master controller or the test driver, the same message is being echoed back instead of sending it to the peers (maintained by client_ctx). See handle_barrier_status in gnunet-service-testbed_barriers.c:864
Moreover, the barrier handle in the client_ctx is being deleted. Why? It should be present in case the barrier needs to be reference later as the status message doesn't mean that the barrier is crossed or invalid anymore.
Need more time to figure out.
||Figured out; working on a fix.|
||Should be fixed SVN #38228. Please confirm.|
||Yes, indeed tests now pass on my system. Thanks!!!|
|2016-10-10 17:47||Christian Grothoff||New Issue|
|2016-10-10 17:47||Christian Grothoff||Status||new => assigned|
|2016-10-10 17:47||Christian Grothoff||Assigned To||=> Sree Harsha Totakura|
|2016-10-11 15:36||Sree Harsha Totakura||Note Added: 0011289|
|2016-10-26 11:28||Sree Harsha Totakura||Note Added: 0011388|
|2016-10-27 13:00||Sree Harsha Totakura||Note Added: 0011390|
|2016-10-27 13:19||Sree Harsha Totakura||Note Added: 0011391|
|2016-10-27 15:00||Sree Harsha Totakura||Note Added: 0011392|
|2016-10-27 15:01||Sree Harsha Totakura||Assigned To||Sree Harsha Totakura => Christian Grothoff|
|2016-10-27 15:01||Sree Harsha Totakura||Status||assigned => feedback|
|2016-10-27 15:06||Christian Grothoff||Note Added: 0011393|
|2016-10-27 15:06||Christian Grothoff||Status||feedback => assigned|
|2016-10-27 15:06||Christian Grothoff||Status||assigned => resolved|
|2016-10-27 15:06||Christian Grothoff||Fixed in Version||=> 0.11.0pre66|
|2016-10-27 15:06||Christian Grothoff||Resolution||open => fixed|
|2016-10-27 15:06||Christian Grothoff||Assigned To||Christian Grothoff => Sree Harsha Totakura|
|2018-06-07 00:24||Christian Grothoff||Status||resolved => closed|