We had a problem where new clients couldn't get their keys signed properly by the puppetmaster. Both the client and the server were in perfect sync with our ntp server. date on both machines returned the expected results. We are running mongrel so I went down the wrong path of thinking apache was to blame for the time problem. It wasn't until I started going through the certificate_factory stuff that I found the problem.
We'd errors on the certs like this:
[root@puppet ~]# cd /var/lib/puppet/ssl
[root@puppet ssl]# openssl verify
> -CAfile ./certs/ca.pem ./certs/client.example.com.pem
> ./certs/client.example.com.pem: /CN= client.example.com
> error 9 at 1 depth lookup:certificate is not yet valid
Outputing the certificate showed that the cert was being signed for a future date, even though the time on the machines is correct.
[root@puppet ssl]# date
Fri Jan 29 11:31:32 EST 2010
[root@puppet ssl]# openssl x509 -text -in ca/signed/client.example.com.pem |grep -A2 Valid
Validity
Not Before: Feb 17 13:28:04 2010 GMT
Not After : Feb 16 13:28:04 2015 GMT
Going through the code I found that the date was being set in certificate_factory.rb
def set_ttl
# Make the certificate valid as of yesterday, because
# so many people's clocks are out of sync.
from = Time.now - (60*60*24)
@cert.not_before = from
@cert.not_after = from + ttl
end
Just for fun I ran the command through interactive ruby (irb) and discovered the source of the problem.
[root@puppet ~]# ntpdate time.example.com
29 Jan 09:02:45 ntpdate[9117]: step time server 192.168.0.1 offset -6377207.794727 sec
[root@puppet ~]# irb
irb(main):001:0> Time.now
=> Tue Apr 13 05:25:50 -0400 2010
irb(main):002:0> quit
[root@puppet ~]# date
Fri Jan 29 08:59:07 EST 2010
I still don't know why this happened, it's not a puppet bug, it's a ruby bug. date was returning the expected results. I checked Timezones, everything, all were good. It was time for a kernel upgrade, so I did the upgrade and rebooted. I haven't seen the problem since :-/ The machine in question is a kvm running on version 88, I know there are some clock skew problems with earlier kvm's but this is not really a skew, it's far in the future...and the date was still being show as correct. So ruby must've been calculating the date wrong somehow, it doesn't really make sense...comments welcome.
Anyway, if this happens to you, maybe try irb and see if ruby thinks the date is wrong.
