View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0004718GNUnettestbed servicepublic2016-10-10 17:472018-06-07 00:24
ReporterChristian Grothoff Assigned ToSree Harsha Totakura  
PriorityhighSeverityminorReproducibilityalways
Status closedResolutionfixed 
Platformi7OSDebian GNU/LinuxOS Versionsqueeze
Product VersionGit master 
Target Version0.11.0pre66Fixed in Version0.11.0pre66 
Summary0004718: assertion fails at testbed_api.c:1288.
DescriptionI'm getting this assertion failure when I run

./test_testbed_api_barriers

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 InformationSree, 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.
TagsNo tags attached.

Activities

Sree Harsha Totakura

2016-10-11 15:36

developer   ~0011289

ACK; will look into it.

Sree Harsha Totakura

2016-10-26 11:28

developer   ~0011388

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.

Sree Harsha Totakura

2016-10-27 13:00

developer   ~0011390

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.

Sree Harsha Totakura

2016-10-27 13:19

developer   ~0011391

Figured out; working on a fix.

Sree Harsha Totakura

2016-10-27 15:00

developer   ~0011392

Should be fixed SVN #38228. Please confirm.

Christian Grothoff

2016-10-27 15:06

manager   ~0011393

Yes, indeed tests now pass on my system. Thanks!!!

Issue History

Date Modified Username Field Change
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