bgpdump parsing gone wonky

[sraustein]

{{{ 2013-11-07 17:00:00 rtr-origin/bgpdump_convert[82433]: Reading 1383696018.ax 2013-11-07 17:00:23 rtr-origin/bgpdump_convert[82433]: DB serial now 1383696018 (2013-11-06T00:00:18Z) 2013-11-07 17:00:23 rtr-origin/bgpdump_convert[82433]: Reading /dfw1/ntt/storage/ibgp/ribs.201311/ribs.20131106.2000.bz2 2013-11-07 17:00:23 [info] logging to syslog Traceback (most recent call last): File "/home/sra/subvert-rpki.hactrn.net/trunk/rtr-origin/rtr-origin.py", line 1902, in main_dispatchmode File "/home/sra/subvert-rpki.hactrn.net/trunk/rtr-origin/rtr-origin.py", line 1661, in bgpdump_convert_main db.save_axfr() File "/home/sra/subvert-rpki.hactrn.net/trunk/rtr-origin/rtr-origin.py", line 825, in save_axfr f = open(self.filename(), "wb") File "/home/sra/subvert-rpki.hactrn.net/trunk/rtr-origin/rtr-origin.py", line 806, in filename return "%d.ax" % self.serial AttributeError: 'axfr_set' object has no attribute 'serial' Traceback (most recent call last): File "/home/sra/running-conversion.py", line 81, in subprocess.check_call(argv, env = os.environ) File "/usr/local/lib/python2.7/subprocess.py", line 542, in check_call raise CalledProcessError(retcode, cmd) subprocess.CalledProcessError: Command '['/usr/local/bin/python', '/home/sra/subvert-rpki.hactrn.net/trunk/rtr-origin/rtr-origin.py', '--bgpdump_convert', '1383696018.ax', '/dfw1/ntt/storage/ibgp/ribs.201311/ribs.20131106.2000.bz2']' returned non-zero exit status 1 }}}

This is a Python program running another Python program, hence the double backtrace. The outer is the wrapper that finds the latest bgpdump file from dfw0's RIB dump collection. The inner is rtr-origin.

This is now happening hourly, after working fine for months (years?).

Best guess at the moment is that .parse_bgpsec_rib_dump() is failing to parse any line in the file it's getting from bgpdump, with the result that it never gets even a single usable timestamp, hence leaving self.serial unset, thus triggering the exception.

We've had problems before with bgpdump drooling on the carpet, but usually it's just one or two lines, which the script logs then ignores.

I wonder if today's RIB dump is garbage?

_Trac ticket #653 component rtrorigin priority minor, owner randy, created by sra on 2013-11-07T17:15:25Z, last modified 2013-11-08T07:03:53Z

[sraustein]

In [changeset:5589]: {{{

!CommitTicketReference repository="" revision="5589"

Exit with comprehensible error code if we couldn't parse anything from RIB dump. See #653. }}}

Trac comment by sra on 2013-11-08T02:53:26Z

[sraustein]

Root cause does indeed appear to be something whacked with the RIB dumps: {{{ [sra@dfw0 ~/subvert-rpki.hactrn.net]$ date Fri Nov 8 03:02:59 UTC 2013

[sra@dfw0 ~/subvert-rpki.hactrn.net]$ ls -l /dfw1/ntt/storage/ibgp/ribs.201311/ | tail -6 -rw-r--r-- 1 backup backup 17819532 Nov 6 00:00 ribs.20131106.0000.bz2 -rw-r--r-- 1 backup backup 17709854 Nov 6 04:00 ribs.20131106.0400.bz2 -rw-r--r-- 1 backup backup 17596459 Nov 6 08:00 ribs.20131106.0800.bz2 -rw-r--r-- 1 backup backup 14 Nov 6 12:03 ribs.20131106.1203.bz2 -rw-r--r-- 1 backup backup 14 Nov 6 18:38 ribs.20131106.1838.bz2 -rw-r--r-- 1 backup backup 14 Nov 6 20:00 ribs.20131106.2000.bz2 }}}

Assigning to Randy until the RIB dump problem is fixed.

Trac comment by sra on 2013-11-08T03:05:17Z

[sraustein]

Apparently now fixed. Did you do something?

Trac comment by sra on 2013-11-08T07:03:53Z