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

Assertion `!attr->community' failed #62

Closed
reuteran opened this Issue Mar 25, 2018 · 20 comments

Comments

Projects
None yet
4 participants
@reuteran

reuteran commented Mar 25, 2018

I have a daily script that uses pybgpstream to load RIB data from all routeviews/ris collectors.
This has been working without problems for a few months now.
The last few days, this has been failing with this error message:

python3: bgpdump_lib.c:970: process_one_attr: Assertion !attr->community' failed.

I am using the bgpstream build from the master branch (commit 1115a80), both for the lib and for pybgpstream.

The error message is preceded by a lot of 'incomplete dump' error messages:

2018-03-22 23:15:57 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.sg/ribs/2018/03/20/routeviews.route-views.sg.ribs.1521561600.bz2 incomplete dump record (171 bytes read, expecting 315)
2018-03-22 23:16:06 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views3/ribs/2018/03/20/routeviews.route-views3.ribs.1521561600.bz2 incomplete dump record (672 bytes read, expecting 1071)
2018-03-22 23:16:06 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views4/ribs/2018/03/20/routeviews.route-views4.ribs.1521561600.bz2 incomplete dump record (1003 bytes read, expecting 1415)
2018-03-22 23:16:07 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views6/ribs/2018/03/20/routeviews.route-views6.ribs.1521561600.bz2 incomplete dump record (640 bytes read, expecting 2715)
2018-03-22 23:16:08 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.wide/ribs/2018/03/20/routeviews.route-views.wide.ribs.1521561600.bz2 incomplete dump record (22 bytes read, expecting 111)
2018-03-22 23:16:12 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.sydney/ribs/2018/03/20/routeviews.route-views.sydney.ribs.1521561600.bz2 incomplete dump record (410 bytes read, expecting 448)
2018-03-22 23:16:13 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.jinx/ribs/2018/03/20/routeviews.route-views.jinx.ribs.1521561600.bz2 incomplete dump record (172 bytes read, expecting 246)
2018-03-22 23:16:14 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.saopaulo/ribs/2018/03/20/routeviews.route-views.saopaulo.ribs.1521561600.bz2 incomplete dump record (225 bytes read, expecting 630)
2018-03-22 23:16:14 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views2/ribs/2018/03/20/routeviews.route-views2.ribs.1521561600.bz2 incomplete dump record (949 bytes read, expecting 2992)
2018-03-22 23:16:16 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.eqix/ribs/2018/03/20/routeviews.route-views.eqix.ribs.1521561600.bz2 incomplete dump record (626 bytes read, expecting 733)
Unexpected EOF while reading compressed file -- file is probably incomplete
2018-03-23 01:11:17 [error] bgpdump_read_next: http://bgp-archive.caida.org/ris/rrc13/ribs/2018/03/21/ris.rrc13.ribs.1521590400.gz incomplete dump record (440 bytes read, expecting 656)
Unexpected EOF while reading compressed file -- file is probably incomplete
2018-03-23 01:11:20 [error] bgpdump_read_next: http://bgp-archive.caida.org/ris/rrc14/ribs/2018/03/21/ris.rrc14.ribs.1521590400.gz incomplete dump record (2723 bytes read, expecting 5760)
Unexpected EOF while reading compressed file -- file is probably incomplete
2018-03-23 01:11:22 [error] bgpdump_read_next: http://bgp-archive.caida.org/ris/rrc15/ribs/2018/03/21/ris.rrc15.ribs.1521590400.gz incomplete dump record (4397 bytes read, expecting 41579)
2018-03-23 01:11:26 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.linx/ribs/2018/03/21/routeviews.route-views.linx.ribs.1521590400.bz2 incomplete dump record (805 bytes read, expecting 1655)
2018-03-23 01:11:28 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.telxatl/ribs/2018/03/21/routeviews.route-views.telxatl.ribs.1521590400.bz2 incomplete dump record (19 bytes read, expecting 417)
2018-03-23 01:11:48 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views6/ribs/2018/03/21/routeviews.route-views6.ribs.1521590400.bz2 incomplete dump record (1126 bytes read, expecting 2544)
2018-03-23 01:11:50 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views4/ribs/2018/03/21/routeviews.route-views4.ribs.1521590400.bz2 incomplete dump record (1240 bytes read, expecting 1794)
2018-03-23 01:11:52 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.chicago/ribs/2018/03/21/routeviews.route-views.chicago.ribs.1521590400.bz2 incomplete dump record (412 bytes read, expecting 461)
2018-03-23 01:11:52 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.sg/ribs/2018/03/21/routeviews.route-views.sg.ribs.1521590400.bz2 incomplete dump record (236 bytes read, expecting 295)
2018-03-23 01:11:54 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views2/ribs/2018/03/21/routeviews.route-views2.ribs.1521590400.bz2 incomplete dump record (2012 bytes read, expecting 2591)
2018-03-23 01:11:56 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views3/ribs/2018/03/21/routeviews.route-views3.ribs.1521590400.bz2 incomplete dump record (825 bytes read, expecting 962)
2018-03-23 01:11:57 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.saopaulo/ribs/2018/03/21/routeviews.route-views.saopaulo.ribs.1521590400.bz2 incomplete dump record (191 bytes read, expecting 678)
2018-03-23 01:11:57 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.jinx/ribs/2018/03/21/routeviews.route-views.jinx.ribs.1521590400.bz2 incomplete dump record (47 bytes read, expecting 250)
2018-03-23 01:11:57 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.sydney/ribs/2018/03/21/routeviews.route-views.sydney.ribs.1521590400.bz2 incomplete dump record (241 bytes read, expecting 528)
python3: bgpdump_lib.c:970: process_one_attr: Assertion `!attr->community' failed.
Aborted

I haven't changed anything in the system, or the script.

@alistairking

This comment has been minimized.

Member

alistairking commented Mar 26, 2018

I think I have been seeing some similar failures in processing that we do.
I'll try and find some time either today or tomorrow to look into it.

@alistairking

This comment has been minimized.

Member

alistairking commented Mar 28, 2018

I've been trying to track this problem down, and I have some ideas about what is going on, but I can't explain why so many dumps failed. Can you give me a bit more information?

  • On what dates did it fail? (Can you send me more log info?)
  • Has the processing been taking longer than normal? (Especially on those days that it failed.)
@reuteran

This comment has been minimized.

reuteran commented Mar 29, 2018

This last time it worked was on March 20th, since then it has been failing daily at the same Assertion. I don't have any more detailed logs than above.
So far, the last dump to cause an error before the Assertion failed was always from routeviews. I'm gonna run it with only RIS collectors now and see if that makes a difference.

@reuteran

This comment has been minimized.

reuteran commented Mar 29, 2018

It works fine when only pulling from RIS collectors.

@alistairking

This comment has been minimized.

Member

alistairking commented Mar 29, 2018

Thanks for checking. Is the problem is reproducible? That is, if you run your script on yesterday's data, would it fail in the same way? Or does the problem only happen when processing data in real time?

@alistairking

This comment has been minimized.

Member

alistairking commented Mar 29, 2018

Nevermind, I think I've been able to reproduce the problem. Working on a patch now.

@alistairking

This comment has been minimized.

Member

alistairking commented Mar 29, 2018

Ok, @reuteran, can you try checking out the bgpdump-fixes branch from this repo (https://github.com/CAIDA/bgpstream/compare/bgpdump-fixes) and trying that? I have made the bgpdump code less fragile when it comes across data that it doesn't expect.
That said, it will still be unable to parse these dumps that have the non-standard data (I think it is the RIB dump from the route-views.eqix collector), but with these fixes it will at least be able to recover and continue processing data from other collectors.

Please try this patch and if it solves the problem for you, I'll merge it into master.

Also, we have an early beta version of BGPStream v2 available which uses a completely different parsing library that is much more robust, so should be able to handle these cases more gracefully (for example, the patched v1 code can only read 253,809 elems from one of these eqix dumps before it has to give up, whereas v2 can read all 8,733,060 elems). If you are interested in being part of the testing of this code, please contact bgpstream-info@caida.org for more information.

@reuteran

This comment has been minimized.

reuteran commented Apr 4, 2018

Thanks! I tested the build you provided. The assertion error is fixed, but the problem now is that my script has slowed down considerably. Usually it took 9 hours to run, now its been running for almost 2 days (no idea if its actually gonna finish or if its stuck).

@alistairking

This comment has been minimized.

Member

alistairking commented Apr 4, 2018

That is unusual. Those changes shouldn't have affected anything like that. I'll try and reproduce the problem and get back to you.

@alistairking

This comment has been minimized.

Member

alistairking commented Apr 4, 2018

I haven't been able to reproduce this problem for the March 29th 00:00 RIB dumps. What time period were you processing when it got stuck?

@reuteran

This comment has been minimized.

reuteran commented Apr 5, 2018

Hmm, it got stuck for the dumps on 2017-03-21 and 2017-04-02 (whole day in both cases). Although for 2017-04-03 it worked. I will run a few more and let you know if this keeps happening.

@digizeph

This comment has been minimized.

Contributor

digizeph commented Apr 6, 2018

@reuteran Do you still see any error messages when it happens? Could you post it if you see them? Thanks!

@reuteran

This comment has been minimized.

reuteran commented Apr 6, 2018

The scripts that were stuck have now completed on second try, in about the same time as usual. So everything is working as it should now
@digizeph
Here is the log for a script that loads all data from all collectors for 2017-03-21:

2018-04-05 12:38:28 [warn] process_one_attr failed, stopping attribute processing
2018-04-05 12:38:28 [error] process_attributes failed
2018-04-05 12:54:49 [error] ERROR attr->community is already set
2018-04-05 12:54:49 [warn] process_one_attr failed, stopping attribute processing
2018-04-05 12:54:49 [error] process_attributes failed
2018-04-05 13:09:32 [error] ERROR attr->community is already set
2018-04-05 13:09:32 [warn] process_one_attr failed, stopping attribute processing
2018-04-05 13:09:32 [error] process_attributes failed
2018-04-05 13:29:09 [error] ERROR attr->community is already set
2018-04-05 13:29:09 [warn] process_one_attr failed, stopping attribute processing
2018-04-05 13:29:09 [error] process_attributes failed
Unexpected EOF while reading compressed file -- file is probably incomplete
2018-04-05 14:32:41 [error] bgpdump_read_next: http://bgp-archive.caida.org/ris/rrc13/ribs/2018/03/21/ris.rrc13.ribs.1521648000.gz incomplete dump record (978 bytes read, expecting 1218)
Unexpected EOF while reading compressed file -- file is probably incomplete
2018-04-05 14:32:43 [error] bgpdump_read_next: http://bgp-archive.caida.org/ris/rrc14/ribs/2018/03/21/ris.rrc14.ribs.1521648000.gz incomplete dump record (5559 bytes read, expecting 8682)
Unexpected EOF while reading compressed file -- file is probably incomplete
2018-04-05 14:32:44 [error] bgpdump_read_next: http://bgp-archive.caida.org/ris/rrc00/ribs/2018/03/21/ris.rrc00.ribs.1521648000.gz incomplete dump record (1665 bytes read, expecting 34252)
2018-04-05 14:32:47 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.linx/ribs/2018/03/21/routeviews.route-views.linx.ribs.1521648000.bz2 incomplete dump record (1402 bytes read, expecting 1579)
2018-04-05 14:32:59 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.sfmix/ribs/2018/03/21/routeviews.route-views.sfmix.ribs.1521648000.bz2 incomplete dump record (1 bytes read, expecting 216)
2018-04-05 14:33:07 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.saopaulo/ribs/2018/03/21/routeviews.route-views.saopaulo.ribs.1521648000.bz2 incomplete dump record (273 bytes read, expecting 662)
2018-04-05 14:33:08 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.telxatl/ribs/2018/03/21/routeviews.route-views.telxatl.ribs.1521648000.bz2 incomplete dump record (210 bytes read, expecting 301)
2018-04-05 14:33:08 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views3/ribs/2018/03/21/routeviews.route-views3.ribs.1521648000.bz2 incomplete dump record (61 bytes read, expecting 1231)
2018-04-05 14:33:09 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views4/ribs/2018/03/21/routeviews.route-views4.ribs.1521648000.bz2 incomplete dump record (827 bytes read, expecting 1413)
2018-04-05 14:33:10 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views6/ribs/2018/03/21/routeviews.route-views6.ribs.1521648000.bz2 incomplete dump record (2040 bytes read, expecting 2868)
2018-04-05 14:33:12 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.chicago/ribs/2018/03/21/routeviews.route-views.chicago.ribs.1521648000.bz2 incomplete dump record (46 bytes read, expecting 414)
2018-04-05 14:33:12 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.sg/ribs/2018/03/21/routeviews.route-views.sg.ribs.1521648000.bz2 incomplete dump record (332 bytes read, expecting 374)
2018-04-05 14:33:14 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views2/ribs/2018/03/21/routeviews.route-views2.ribs.1521648000.bz2 incomplete dump record (339 bytes read, expecting 3139)
2018-04-05 14:33:14 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.jinx/ribs/2018/03/21/routeviews.route-views.jinx.ribs.1521648000.bz2 incomplete dump record (170 bytes read, expecting 266)
2018-04-05 14:33:15 [error] bgpdump_read_next: http://bgp-archive.caida.org/routeviews/route-views.sydney/ribs/2018/03/21/routeviews.route-views.sydney.ribs.1521648000.bz2 incomplete dump record (56 bytes read, expecting 456)
2018-04-05 14:34:13 [error] ERROR attr->community is already set
2018-04-05 14:34:13 [warn] process_one_attr failed, stopping attribute processing
2018-04-05 14:34:13 [error] process_attributes failed
2018-04-05 14:50:25 [error] ERROR attr->community is already set
2018-04-05 14:50:25 [warn] process_one_attr failed, stopping attribute processing
2018-04-05 14:50:25 [error] process_attributes failed
2018-04-05 15:03:33 [error] ERROR attr->community is already set
2018-04-05 15:03:33 [warn] process_one_attr failed, stopping attribute processing
2018-04-05 15:03:33 [error] process_attributes failed
@digizeph

This comment has been minimized.

Contributor

digizeph commented Apr 6, 2018

@reuteran that's great! We will continue digging into this issue. Seems like the attr->community parsing has some problems.

One more thing I'd like to confirm with you: have you pulled this commit b1a154a before your second run? We'd like to know if it is this change fixes the problem.

Thank you!

@reuteran

This comment has been minimized.

reuteran commented Apr 6, 2018

I had not pulled that commit. Will give it a try now.

@sclintow

This comment has been minimized.

sclintow commented Apr 6, 2018

I have the same issue with the route-views.eqix data source, but I'm using the bgpreader command line. I have cloned the bgpdump-fixes branch and I'm testing now.

@sclintow

This comment has been minimized.

sclintow commented Apr 6, 2018

bgpreader stop processing the route-views.eqix data source, but it will continue to read other data sources if provided.

bgpreader -t ribs -c route-views.eqix -w1523026106,1523033306 -k 23.16.0.0/15 -k 2001:568::/29 -k 2607:fe8
8::/32 -k 50.92.0.0/16 -k 50.93.0.0/17 -k 50.98.0.0/15 -k 64.114.0.0/16 -k 64.180.0.0/16 -k 66.103.192.0/1
9 -k 66.110.128.0/19 -k 66.110.160.0/20 -k 66.183.0.0/16 -k 66.203.192.0/19 -k 66.222.128.0/17 -k 68.182.0
.0/16 -k 72.9.160.0/19 -k 72.25.192.0/18 -k 74.48.0.0/15 -k 75.152.0.0/13 -k 96.1.0.0/16 -k 99.199.0.0/16
-k 104.157.0.0/17 -k 104.205.0.0/16 -k 108.172.0.0/15 -k 108.180.0.0/15 -k 137.186.0.0/16 -k 142.59.0.0/17
 -k 142.59.128.0/19 -k 142.59.176.0/20 -k 142.59.192.0/18 -k 142.63.0.0/16 -k 142.168.0.0/15 -k 154.5.0.0/
16 -k 154.11.0.0/16 -k 154.20.0.0/16 -k 161.184.0.0/16 -k 162.156.0.0/15 -k 172.218.0.0/15 -k 173.180.0.0/
14 -k 192.197.168.0/21 -k 192.197.176.0/23 -k 198.53.0.0/16 -k 198.80.52.0/22 -k 198.161.14.0/23 -k 198.16
1.16.0/22 -k 198.161.148.0/22 -k 198.161.152.0/21 -k 198.161.160.0/22 -k 198.166.0.0/16 -k 199.84.240.0/23
 -k 199.84.242.0/24 -k 199.126.0.0/16 -k 199.212.152.0/21 -k 204.174.64.0/22 -k 204.174.68.0/23 -k 204.174
.120.0/22 -k 204.174.211.0/24 -k 204.174.212.0/22 -k 204.174.216.0/22 -k 204.174.220.0/23 -k 204.191.0.0/1
6 -k 204.209.192.0/20 -k 204.225.240.0/21 -k 205.138.98.0/23 -k 205.138.102.0/23 -k 205.206.0.0/16 -k 205.
236.24.0/23 -k 205.236.48.0/23 -k 205.250.0.0/16 -k 206.26.204.192/26 -k 206.75.0.0/16 -k 206.108.16.0/20
-k 206.108.64.0/19 -k 206.108.192.0/19 -k 206.116.0.0/16 -k 206.162.128.0/18 -k 207.6.0.0/16 -k 207.34.64.
0/18 -k 207.34.128.0/17 -k 207.81.0.0/16 -k 207.102.0.0/16 -k 207.134.0.0/16 -k 207.148.128.0/18 -k 207.16
7.192.0/18 -k 207.194.0.0/16 -k 207.216.0.0/16 -k 207.219.0.0/16 -k 207.228.64.0/18 -k 207.229.0.0/18 -k 2
08.38.0.0/18 -k 208.181.0.0/16 -k 209.20.0.0/18 -k 209.29.0.0/16 -k 209.52.0.0/15 -k 209.89.0.0/16 -k 209.
91.64.0/18 -k 209.104.64.0/18 -k 209.107.96.0/19 -k 209.115.128.0/17 -k 209.121.0.0/16 -k 209.162.160.0/20
 -k 209.171.0.0/16 -k 209.202.64.0/18 -k 216.7.192.0/19 -k 216.123.192.0/18 -k 216.198.128.0/19 -k 216.218
.0.0/18 -k 216.226.32.0/19 -k 216.232.0.0/16
2018-04-06 10:48:31 [error] ERROR attr->community is already set
2018-04-06 10:48:31 [warn] process_one_attr failed, stopping attribute processing
2018-04-06 10:48:31 [error] process_attributes failed
@digizeph

This comment has been minimized.

Contributor

digizeph commented Apr 6, 2018

@sclintow thank you for providing the feedback. We will investigate this issue and get back to you soon.

@alistairking

This comment has been minimized.

Member

alistairking commented Apr 9, 2018

Yeah, that ERROR attr->community is already set error is expected with the data from route-views.eqix. For some reason there are some records where the community path attribute is set twice, which is not allowed according to the standard. The patches in the bgpdump-fixes branch only allow BGPStream detect the "corruption" without crashing, they don't allow processing to continue.

I'm hesitant to spend much time improving the parser (based on libbgpdump) in v1 because we have a completely new parser implemented for v2.
If you really need the data from eqix, then please email bgpstream-info@caida.org and request access to the v2 beta.

@alistairking

This comment has been minimized.

Member

alistairking commented Apr 11, 2018

I'm going to merge those fixes into master and will close this issue. Feel free to reopen it if you have any further problems/questions.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment