Closed sraustein closed 12 years ago
The same issue appears to affect the calls to generate_crl()
Trac comment by melkins on 2012-02-22T15:51:26Z
For some reason adding a .save()
call directly after .avow()
does not seem to be working. I'm still seeing the old expiration date on the certificate.
Trac comment by melkins on 2012-02-22T16:00:47Z
False alarm. I got bit by the issue where I need to run transaction.commit()
to see the udpated values.
Trac comment by melkins on 2012-02-22T16:06:48Z
In [4357]: {{{
invoke .save() after calling .avow() or .generate_crl() to ensure the newly generated objects are saved to the db. closes #200 }}}
Trac comment by melkins on 2012-02-22T16:08:05Z
rpkid now seems to be unhappy after running update_bpki
:
{{{
(web_portal)sbin$ ./rpkic synchronize
2012-02-22 16:10:10 rpkic[4585]:
Trac comment by melkins on 2012-02-22T16:11:11Z
Check rpkid's log to see if there are more details on what it dislikes here.
UnexpectedCMSCertificates is raised in one of two places, one for trusted EE certificates (eg, left-right protocol), one for untrusted EE certificates (eg, up-down protocol). The backtrace looks like a left-right call, so presumably this is the trusted case.
If we can't figure out what's really going on here it would probably be safe to relax the restriction (not throw this exception), as in this case the entire thing is a matter within our own CA, and OpenSSL will ignore the extraneous certificate. It would, however, be better to know how an unexpected certificate is getting into the message in the first place (or, alternatively, whether the logic that attempts to check for that is broken...).
Trac comment by sra on 2012-02-22T16:44:51Z
Trivial test was not able to reproduce the bad behavior. Test I tried:
{{{
cd $top/rpkid/tests make yamltest }}}
Leave that running until it says "Done initializing daemons", then, in another window:
{{{
cd $top/rpkid/tests/yamltest.dir/R0 ../../../rpkic update_bpki synchronize }}}
I see no errors in any log from this.
Backtrace a couple of updates ago does not appear to have been from work0. Where was it?
Trac comment by sra on 2012-02-22T17:07:29Z
I was testing on the server I run the SPARTA instance on. Here's the rpkid.log excerpt:
{{{
2012-02-22 17:22:04 rpkid[4392]: Scheduling next cron run at 2012-02-22T17:24:04Z
2012-02-22 17:22:04 rpkid[4392]: Self SPARTA[1] polling parents
2012-02-22 17:22:04 rpkid[4392]: Sending "list" request to parent arin
2012-02-22 17:22:11 rpkid[4392]: Parent arin and I agree that I have SKI j-yin7SQr-c2TjFmqpm6qFAnY40 in resource class 1
2012-02-22 17:22:11 rpkid[4392]: Self SPARTA[1] updating children
2012-02-22 17:22:11 rpkid[4392]: Self SPARTA[1] updating ROAs
2012-02-22 17:22:11 rpkid[4392]:
Trac comment by melkins on 2012-02-22T17:25:35Z
Looks like yamltest is somehow picking up the main irdbd database: {{{ Running daemons for Bob Running /home/melkins/tk161/rpkid/irdbd -d -c /home/melkins/tk161/rpkid/tests/yamltest.dir/Bob/rpki.conf for Bob: pid 11079 process <subprocess.Popen object at 0x3809bd0> Running /home/melkins/tk161/rpkid/rpkid -d -c /home/melkins/tk161/rpkid/tests/yamltest.dir/Bob/rpki.conf for Bob: pid 11080 process <subprocess.Popen object at 0x3809850> Giving Bob daemons time to start up
Running "/home/melkins/tk161/rpkid/rpkic -i Bob -c /home/melkins/tk161/rpkid/tests/yamltest.dir/Bob/rpki.conf synchronize"
2012-02-22 17:41:43 rpkic[11083]:
Trac comment by melkins on 2012-02-22T17:43:12Z
It appears yamltest can't be run while the main daemons are running since they use the same ports.
Trac comment by melkins on 2012-02-22T17:51:06Z
It appears yamltest can't be run while the main daemons are running since they use the same ports.
That's all configurable. yamltest starts with examples/rpki.conf and edits to suit its needs, most of the default values come out of examples/rpki.conf, the rest are configurable in yamltest.conf.
Trac comment by sra on 2012-02-22T18:03:40Z
That's all configurable. yamltest starts with examples/rpki.conf and edits to suit its needs, most of the default values come out of examples/rpki.conf, the rest are configurable in yamltest.conf.
The base port is hardcoded to 4400 at $top/rpkid/tests/yamltest.py line 162.
Trac comment by melkins on 2012-02-22T18:05:48Z
I see no errors in any log from this.
Confirmed that I also see no errors when running yamltest. I will try to restart the daemons and see if I still have the problem.
Trac comment by melkins on 2012-02-22T18:10:49Z
Restarted the servers and I still see the same issue:
{{{
2012-02-22 18:12:43 rpkid[13002]: Scheduling next cron run at 2012-02-22T18:14:43Z
2012-02-22 18:12:43 rpkid[13002]: Self SPARTA[1] polling parents
2012-02-22 18:12:43 rpkid[13002]: Sending "list" request to parent arin
2012-02-22 18:12:51 rpkid[13002]: Parent arin and I agree that I have SKI j-yin7SQr-c2TjFmqpm6qFAnY40 in resource class 1
2012-02-22 18:12:51 rpkid[13002]: Self SPARTA[1] updating children
2012-02-22 18:12:51 rpkid[13002]: Self SPARTA[1] updating ROAs
2012-02-22 18:12:51 rpkid[13002]:
Trac comment by melkins on 2012-02-22T18:13:18Z
does Zookeeper.write_bpki_files() need to be called after update_bpki() ? Wondering if irdbd is using an out of date certificate...
Trac comment by melkins on 2012-02-22T18:16:56Z
Sorry, that should have been the [yamltest] section of rpki.conf (it used to be yamltest.conf, but that changed a while ago).
Patch to fix hardwired base port testing now.
Trac comment by sra on 2012-02-22T18:18:18Z
Yes, if update_bpki() generated new a new certificate for rpkid or pubd, that certificate needs to be written out.
Trac comment by sra on 2012-02-22T18:19:36Z
In [4358]: {{{
Make base_port configurable in [yamltest] section of rpki.conf. See #200. }}}
Trac comment by sra on 2012-02-22T18:21:05Z
I assumed that restarting the daemons would have updated the certificate file on disk. What exactly is rpkid doing when it starts up?
{{{ 2012-02-22 18:11:58 rpkid[13002]: Updating /usr/local/etc/rpki/SPARTA/bpki/servers/ca.cer, timestamp 2012-02-02T23:21:47Z 2012-02-22 18:11:58 rpkid[13002]: Updating /usr/local/etc/rpki/SPARTA/bpki/servers/irdbd.cer, timestamp 2012-02-02T23:21:47Z 2012-02-22 18:11:58 rpkid[13002]: Updating /usr/local/etc/rpki/SPARTA/bpki/servers/irbe.cer, timestamp 2012-02-02T23:21:47Z 2012-02-22 18:11:58 rpkid[13002]: Updating /usr/local/etc/rpki/SPARTA/bpki/servers/rpkid.cer, timestamp 2012-02-02T23:21:47Z 2012-02-22 18:11:58 rpkid[13002]: Updating /usr/local/etc/rpki/SPARTA/bpki/servers/rpkid.key, timestamp 2012-02-02T23:21:47Z 2012-02-22 18:11:58 rpkid[13002]: Scheduling initial cron pass at 2012-02-22T18:12:43Z }}}
Now I'm wondering how the yamltest works since the daemons don't need to be restarted?
Trac comment by melkins on 2012-02-22T18:22:38Z
I assumed that restarting the daemons would have updated the certificate file on disk. What exactly is rpkid doing when it starts up?
rpkid and pubd only read certificate files from disk, they do not write them. Those certificates are provided by the back end, ie, from the IRDB.
The back end programs read certificates directly from the IRDB, but rpkid and pubd are both stand-alone and public-facing, so they might be on a different machine, other side of a firewall, .... Whole architecture assumes that they don't have direct access to IRDB.
Hence answer to your previous question: if something changes the data rpkid and pubd get from the IRDB via via static files, something has to write out new versions of those files. Which is what Zookeeper.write_bpki_files() does.
It looks like rpki.rpkic.main.do_update_bpki() is missing a call to self.zoo.write_bpki_files(). I can add that or you can try it to see if it fixes this.
Now I'm wondering how the yamltest works since the daemons don't need to be restarted?
yamltest writes all that stuff out before it starts the daemons, and it's been years now since we left a yamltest configuration running for long enough to outlive the initial certificate lifetime.
Trac comment by sra on 2012-02-22T18:30:06Z
I was able to fix the problem by running:
{{{ rpkic initialize # cause the server certificates to writtern out rpki-start-servers
On Wed, Feb 22, 2012 at 06:30:06PM -0000, Trac Ticket System wrote:
Hence answer to your previous question: if something changes the data rpkid and pubd get from the IRDB via via static files, something has to write out new versions of those files. Which is what Zookeeper.write_bpki_files() does.
Do rpkid and irdbd check to see if the server certificate file has changed on disk and re-read? Or do they need to be restarted?
Trac comment by melkins on 2012-02-22T18:34:23Z
I was able to fix the problem by running:
{{{ rpkic initialize # cause the server certificates to writtern out rpki-start-servers
rpki-start-servers }}}
That's a much larger hammer than should be necessary. The daemons which read keys and certificates from disk files check the timestamps on those files and re-read those files if the timestamps change.
Can we still re-create the basic problem or are we now at the point where we have to do this just by thinking clearly? :)/2
One possible approach to re-creating in the lab would be to fix #201 then configure ridiculously short lifetimes to force expiration.
Trac comment by sra on 2012-02-22T18:37:26Z
Can we still re-create the basic problem or are we now at the point where we have to do this just by thinking clearly? :)/2
One possible approach to re-creating in the lab would be to fix #201 then configure ridiculously short lifetimes to force expiration.
I think you correct that this only happens when update_bpki() is run to replace an expired certificate. If the cert is not yet expired, there is no problem.
Trac comment by melkins on 2012-02-22T18:44:25Z
In [4359]: {{{
rpki.rpkic.main.do_update_bpki() wasn't writing updated BPKI object to disk; see #200. Make BPKI certificate lifetimes and CRL intervals configurable; closes #201. }}}
Trac comment by sra on 2012-02-22T19:43:21Z
[4360] is a related fix to preserve the Subject Name of the reissued CA certificates.
Trac comment by melkins on 2012-02-22T23:15:36Z
Milestone Apricot 2012 deleted
Trac comment by sra on 2012-04-16T21:27:19Z
Closed with resolution fixed
Randy noticed that the ''scratchmonkey'' resource handle was getting a "CMS cert expired" error in the rpkid.log. I noted that the
ResourceHolderCA
certificate had expired, so I ranrpkic update_bpki
but the error still persisted. After poking around a bit, I determined that the problem was thatCA.avow()
updates the certificate attributed on the object, but the CA object is not saved to the DB. Thus the newly generated certificates are discarded when exiting the.update_bpki()
call.Trac ticket #200 component rpkid priority major, owner sra, created by melkins on 2012-02-22T15:49:57Z, last modified 2012-04-16T21:27:19Z