Merge branch 'master' into longserial

This commit is contained in:
Jeff Hodges 2015-09-22 15:01:47 -07:00
commit a645430a23
22 changed files with 478 additions and 241 deletions

View File

@ -12,15 +12,14 @@ package main
import (
"fmt"
"os"
"time"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cactus/go-statsd-client/statsd"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/streadway/amqp"
"github.com/letsencrypt/boulder/rpc"
"github.com/letsencrypt/boulder/analysis"
"github.com/letsencrypt/boulder/cmd"
blog "github.com/letsencrypt/boulder/log"
"github.com/letsencrypt/boulder/rpc"
)
// Constants for AMQP
@ -39,30 +38,6 @@ const (
AmqpImmediate = false
)
var openCalls int64
func timeDelivery(d amqp.Delivery, stats statsd.Statter, deliveryTimings map[string]time.Time) {
// If d is a call add to deliveryTimings and increment openCalls, if it is a
// response then get time.Since original call from deliveryTiming, send timing metric, and
// decrement openCalls, in both cases send the gauges RpcCallsOpen and RpcBodySize
if d.ReplyTo != "" {
openCalls++
deliveryTimings[fmt.Sprintf("%s:%s", d.CorrelationId, d.ReplyTo)] = time.Now()
} else {
openCalls--
rpcSent := deliveryTimings[fmt.Sprintf("%s:%s", d.CorrelationId, d.RoutingKey)]
if rpcSent != *new(time.Time) {
respTime := time.Since(rpcSent)
delete(deliveryTimings, fmt.Sprintf("%s:%s", d.CorrelationId, d.RoutingKey))
stats.TimingDuration(fmt.Sprintf("RpcCallTime.%s", d.Type), respTime, 1.0)
}
}
stats.Gauge("RpcCallsOpen", openCalls, 1.0)
stats.Gauge("RpcBodySize", int64(len(d.Body)), 1.0)
}
func startMonitor(rpcCh *amqp.Channel, logger *blog.AuditLogger, stats statsd.Statter) {
ae := analysisengine.NewLoggingAnalysisEngine()
@ -120,12 +95,8 @@ func startMonitor(rpcCh *amqp.Channel, logger *blog.AuditLogger, stats statsd.St
cmd.FailOnError(err, "Could not subscribe to queue")
}
deliveryTimings := make(map[string]time.Time)
// Run forever.
for d := range deliveries {
timeDelivery(d, stats, deliveryTimings)
// Pass each message to the Analysis Engine
err = ae.ProcessMessage(d)
if err != nil {

View File

@ -51,7 +51,7 @@ func setupContext(context *cli.Context) (rpc.RegistrationAuthorityClient, *blog.
ch, err := rpc.AmqpChannel(c)
cmd.FailOnError(err, "Could not connect to AMQP")
raRPC, err := rpc.NewAmqpRPCClient("revoker->RA", c.AMQP.RA.Server, ch)
raRPC, err := rpc.NewAmqpRPCClient("revoker->RA", c.AMQP.RA.Server, ch, stats)
cmd.FailOnError(err, "Unable to create RPC client")
rac, err := rpc.NewRegistrationAuthorityClient(raRPC)
@ -60,7 +60,7 @@ func setupContext(context *cli.Context) (rpc.RegistrationAuthorityClient, *blog.
dbMap, err := sa.NewDbMap(c.Revoker.DBConnect)
cmd.FailOnError(err, "Couldn't setup database connection")
saRPC, err := rpc.NewAmqpRPCClient("AdminRevoker->SA", c.AMQP.SA.Server, ch)
saRPC, err := rpc.NewAmqpRPCClient("AdminRevoker->SA", c.AMQP.SA.Server, ch, stats)
cmd.FailOnError(err, "Unable to create RPC client")
sac, err := rpc.NewStorageAuthorityClient(saRPC)

View File

@ -51,13 +51,13 @@ func main() {
go cmd.ProfileCmd("CA", stats)
connectionHandler := func(srv *rpc.AmqpRPCServer) {
saRPC, err := rpc.NewAmqpRPCClient("CA->SA", c.AMQP.SA.Server, srv.Channel)
saRPC, err := rpc.NewAmqpRPCClient("CA->SA", c.AMQP.SA.Server, srv.Channel, stats)
cmd.FailOnError(err, "Unable to create RPC client")
sac, err := rpc.NewStorageAuthorityClient(saRPC)
cmd.FailOnError(err, "Failed to create SA client")
pubRPC, err := rpc.NewAmqpRPCClient("CA->Publisher", c.AMQP.Publisher.Server, srv.Channel)
pubRPC, err := rpc.NewAmqpRPCClient("CA->Publisher", c.AMQP.Publisher.Server, srv.Channel, stats)
cmd.FailOnError(err, "Unable to create RPC client")
pubc, err := rpc.NewPublisherClient(pubRPC)

View File

@ -36,7 +36,7 @@ func main() {
go cmd.ProfileCmd("Publisher", stats)
connectionHandler := func(srv *rpc.AmqpRPCServer) {
saRPC, err := rpc.NewAmqpRPCClient("Publisher->SA", c.AMQP.SA.Server, srv.Channel)
saRPC, err := rpc.NewAmqpRPCClient("Publisher->SA", c.AMQP.SA.Server, srv.Channel, stats)
cmd.FailOnError(err, "Unable to create SA RPC client")
sac, err := rpc.NewStorageAuthorityClient(saRPC)

View File

@ -42,7 +42,7 @@ func main() {
pa, err := policy.NewPolicyAuthorityImpl(paDbMap, c.PA.EnforcePolicyWhitelist)
cmd.FailOnError(err, "Couldn't create PA")
rai := ra.NewRegistrationAuthorityImpl(clock.Default(), auditlogger)
rai := ra.NewRegistrationAuthorityImpl(clock.Default(), auditlogger, stats)
rai.PA = pa
raDNSTimeout, err := time.ParseDuration(c.Common.DNSTimeout)
cmd.FailOnError(err, "Couldn't parse RA DNS timeout")
@ -55,13 +55,13 @@ func main() {
go cmd.ProfileCmd("RA", stats)
connectionHandler := func(srv *rpc.AmqpRPCServer) {
vaRPC, err := rpc.NewAmqpRPCClient("RA->VA", c.AMQP.VA.Server, srv.Channel)
vaRPC, err := rpc.NewAmqpRPCClient("RA->VA", c.AMQP.VA.Server, srv.Channel, stats)
cmd.FailOnError(err, "Unable to create RPC client")
caRPC, err := rpc.NewAmqpRPCClient("RA->CA", c.AMQP.CA.Server, srv.Channel)
caRPC, err := rpc.NewAmqpRPCClient("RA->CA", c.AMQP.CA.Server, srv.Channel, stats)
cmd.FailOnError(err, "Unable to create RPC client")
saRPC, err := rpc.NewAmqpRPCClient("RA->SA", c.AMQP.SA.Server, srv.Channel)
saRPC, err := rpc.NewAmqpRPCClient("RA->SA", c.AMQP.SA.Server, srv.Channel, stats)
cmd.FailOnError(err, "Unable to create RPC client")
vac, err := rpc.NewValidationAuthorityClient(vaRPC)

View File

@ -8,6 +8,7 @@ package main
import (
"time"
"github.com/jmhodges/clock"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cactus/go-statsd-client/statsd"
"github.com/letsencrypt/boulder/cmd"
@ -50,7 +51,7 @@ func main() {
if c.VA.PortConfig.DVSNIPort != 0 {
pc.DVSNIPort = c.VA.PortConfig.DVSNIPort
}
vai := va.NewValidationAuthorityImpl(pc)
vai := va.NewValidationAuthorityImpl(pc, stats, clock.Default())
dnsTimeout, err := time.ParseDuration(c.Common.DNSTimeout)
cmd.FailOnError(err, "Couldn't parse DNS timeout")
if !c.Common.DNSAllowLoopbackAddresses {
@ -61,7 +62,7 @@ func main() {
vai.UserAgent = c.VA.UserAgent
connectionHandler := func(srv *rpc.AmqpRPCServer) {
raRPC, err := rpc.NewAmqpRPCClient("VA->RA", c.AMQP.RA.Server, srv.Channel)
raRPC, err := rpc.NewAmqpRPCClient("VA->RA", c.AMQP.RA.Server, srv.Channel, stats)
cmd.FailOnError(err, "Unable to create RPC client")
rac, err := rpc.NewRegistrationAuthorityClient(raRPC)

View File

@ -17,21 +17,22 @@ import (
"github.com/letsencrypt/boulder/cmd"
blog "github.com/letsencrypt/boulder/log"
"github.com/letsencrypt/boulder/metrics"
"github.com/letsencrypt/boulder/rpc"
"github.com/letsencrypt/boulder/wfe"
)
func setupWFE(c cmd.Config, logger *blog.AuditLogger) (rpc.RegistrationAuthorityClient, rpc.StorageAuthorityClient, chan *amqp.Error) {
func setupWFE(c cmd.Config, logger *blog.AuditLogger, stats statsd.Statter) (rpc.RegistrationAuthorityClient, rpc.StorageAuthorityClient, chan *amqp.Error) {
ch, err := rpc.AmqpChannel(c)
cmd.FailOnError(err, "Could not connect to AMQP")
logger.Info(" [!] Connected to AMQP")
closeChan := ch.NotifyClose(make(chan *amqp.Error, 1))
raRPC, err := rpc.NewAmqpRPCClient("WFE->RA", c.AMQP.RA.Server, ch)
raRPC, err := rpc.NewAmqpRPCClient("WFE->RA", c.AMQP.RA.Server, ch, stats)
cmd.FailOnError(err, "Unable to create RPC client")
saRPC, err := rpc.NewAmqpRPCClient("WFE->SA", c.AMQP.SA.Server, ch)
saRPC, err := rpc.NewAmqpRPCClient("WFE->SA", c.AMQP.SA.Server, ch, stats)
cmd.FailOnError(err, "Unable to create RPC client")
rac, err := rpc.NewRegistrationAuthorityClient(raRPC)
@ -43,38 +44,6 @@ func setupWFE(c cmd.Config, logger *blog.AuditLogger) (rpc.RegistrationAuthority
return rac, sac, closeChan
}
type timedHandler struct {
f func(w http.ResponseWriter, r *http.Request)
stats statsd.Statter
}
var openConnections int64
// HandlerTimer monitors HTTP performance and sends the details to StatsD.
func HandlerTimer(handler http.Handler, stats statsd.Statter) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
cStart := time.Now()
openConnections++
stats.Gauge("HttpConnectionsOpen", openConnections, 1.0)
handler.ServeHTTP(w, r)
openConnections--
stats.Gauge("HttpConnectionsOpen", openConnections, 1.0)
// (FIX: this doesn't seem to really work at catching errors...)
state := "Success"
for _, h := range w.Header()["Content-Type"] {
if h == "application/problem+json" {
state = "Error"
break
}
}
// set resp timing key based on success / failure
stats.TimingDuration(fmt.Sprintf("HttpResponseTime.%s.%s", r.URL, state), time.Since(cStart), 1.0)
})
}
func main() {
app := cmd.NewAppShell("boulder-wfe", "Handles HTTP API requests")
addrFlag := cli.StringFlag{
@ -105,12 +74,11 @@ func main() {
go cmd.DebugServer(c.WFE.DebugAddr)
wfe, err := wfe.NewWebFrontEndImpl()
wfe, err := wfe.NewWebFrontEndImpl(stats)
cmd.FailOnError(err, "Unable to create WFE")
rac, sac, closeChan := setupWFE(c, auditlogger)
rac, sac, closeChan := setupWFE(c, auditlogger, stats)
wfe.RA = &rac
wfe.SA = &sac
wfe.Stats = stats
wfe.SubscriberAgreementURL = c.SubscriberAgreementURL
wfe.CertCacheDuration, err = time.ParseDuration(c.WFE.CertCacheDuration)
@ -140,7 +108,7 @@ func main() {
for err := range closeChan {
auditlogger.Warning(fmt.Sprintf(" [!] AMQP Channel closed, will reconnect in 5 seconds: [%s]", err))
time.Sleep(time.Second * 5)
rac, sac, closeChan = setupWFE(c, auditlogger)
rac, sac, closeChan = setupWFE(c, auditlogger, stats)
wfe.RA = &rac
wfe.SA = &sac
}
@ -154,10 +122,15 @@ func main() {
auditlogger.Info(app.VersionString())
httpMonitor := metrics.NewHTTPMonitor(stats, h, "WFE")
auditlogger.Info(fmt.Sprintf("Server running, listening on %s...\n", c.WFE.ListenAddress))
srv := &http.Server{
Addr: c.WFE.ListenAddress,
Handler: HandlerTimer(h, stats),
Addr: c.WFE.ListenAddress,
ConnState: httpMonitor.ConnectionMonitor,
Handler: httpMonitor.Handle(),
}
hd := &httpdown.HTTP{
StopTimeout: wfe.ShutdownStopTimeout,
KillTimeout: wfe.ShutdownKillTimeout,

View File

@ -75,7 +75,7 @@ func (m *mailer) sendNags(parsedCert *x509.Certificate, contacts []*core.AcmeURL
m.stats.Inc("Mailer.Expiration.Errors.SendingNag.SendFailure", 1, 1.0)
return err
}
m.stats.TimingDuration("Mailer.Expiration.Sending", time.Since(startSending), 1.0)
m.stats.TimingDuration("Mailer.Expiration.SendLatency", time.Since(startSending), 1.0)
m.stats.Inc("Mailer.Expiration.Sent", int64(len(emails)), 1.0)
}
return nil
@ -135,7 +135,6 @@ func (m *mailer) processCerts(certs []core.Certificate) {
err = m.sendNags(parsedCert, reg.Contact)
if err != nil {
m.log.Err(fmt.Sprintf("Error sending nag emails: %s", err))
m.stats.Inc("Mailer.Expiration.Errors.SendingNags", 1, 1.0)
continue
}
err = m.updateCertStatus(cert.Serial)
@ -186,7 +185,7 @@ func (m *mailer) findExpiringCertificates() error {
if len(certs) > 0 {
processingStarted := m.clk.Now()
m.processCerts(certs)
m.stats.TimingDuration("Mailer.Expiration.ProcessingCertificates", time.Since(processingStarted), 1.0)
m.stats.TimingDuration("Mailer.Expiration.ProcessingCertificatesLatency", time.Since(processingStarted), 1.0)
}
}
@ -248,7 +247,7 @@ func main() {
ch, err := rpc.AmqpChannel(c)
cmd.FailOnError(err, "Could not connect to AMQP")
saRPC, err := rpc.NewAmqpRPCClient("ExpirationMailer->SA", c.AMQP.SA.Server, ch)
saRPC, err := rpc.NewAmqpRPCClient("ExpirationMailer->SA", c.AMQP.SA.Server, ch, stats)
cmd.FailOnError(err, "Unable to create RPC client")
sac, err := rpc.NewStorageAuthorityClient(saRPC)

View File

@ -57,8 +57,8 @@ func addCerts(csvFilename string, dbMap *gorp.DbMap, stats statsd.Statter, stats
importStart := time.Now()
err = dbMap.Insert(&externalCert)
stats.TimingDuration("ExistingCert.CertImportTime", time.Since(importStart), statsRate)
stats.Inc("ExistingCert.CertsImported", 1, statsRate)
stats.TimingDuration("ExistingCert.Certs.ImportLatency", time.Since(importStart), statsRate)
stats.Inc("ExistingCert.Certs.Imported", 1, statsRate)
}
}
@ -83,8 +83,8 @@ func addIdentifiers(csvFilename string, dbMap *gorp.DbMap, stats statsd.Statter,
importStart := time.Now()
err = dbMap.Insert(&identifierData)
stats.TimingDuration("ExistingCert.DomainImportTime", time.Since(importStart), statsRate)
stats.Inc("ExistingCert.DomainsImported", 1, statsRate)
stats.TimingDuration("ExistingCert.Domains.ImportLatency", time.Since(importStart), statsRate)
stats.Inc("ExistingCert.Domains.Imported", 1, statsRate)
}
}
@ -111,10 +111,10 @@ func removeInvalidCerts(csvFilename string, dbMap *gorp.DbMap, stats statsd.Stat
deleteStart := time.Now()
_, err = dbMap.Delete(&identifierData)
stats.TimingDuration("ExistingCert.DomainDeleteTime", time.Since(deleteStart), statsRate)
stats.TimingDuration("ExistingCert.Domains.DeleteLatency", time.Since(deleteStart), statsRate)
_, err = dbMap.Delete(&externalCert)
stats.TimingDuration("ExistingCert.CertDeleteTime", time.Since(deleteStart), statsRate)
stats.Inc("ExistingCert.CertsDeleted", 1, statsRate)
stats.TimingDuration("ExistingCert.Certs.DeleteLatency", time.Since(deleteStart), statsRate)
stats.Inc("ExistingCert.Removed", 1, statsRate)
}
}
@ -135,7 +135,7 @@ func main() {
Usage: "The CSV file Containing now invalid certs which should be removed.",
}, cli.Float64Flag{
Name: "statsd-rate",
Value: 0.1,
Value: 1.0,
Usage: "A floating point number between 0 and 1 representing the rate at which the statsd client will send data.",
})

View File

@ -18,6 +18,7 @@ import (
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/facebookgo/httpdown"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/golang.org/x/crypto/ocsp"
gorp "github.com/letsencrypt/boulder/Godeps/_workspace/src/gopkg.in/gorp.v1"
"github.com/letsencrypt/boulder/metrics"
"github.com/letsencrypt/boulder/cmd"
"github.com/letsencrypt/boulder/core"
@ -25,38 +26,6 @@ import (
"github.com/letsencrypt/boulder/sa"
)
type timedHandler struct {
f func(w http.ResponseWriter, r *http.Request)
stats statsd.Statter
}
var openConnections int64
// HandlerTimer monitors HTTP performance and sends the details to StatsD.
func HandlerTimer(handler http.Handler, stats statsd.Statter) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
cStart := time.Now()
openConnections++
stats.Gauge("HttpConnectionsOpen", openConnections, 1.0)
handler.ServeHTTP(w, r)
openConnections--
stats.Gauge("HttpConnectionsOpen", openConnections, 1.0)
// (FIX: this doesn't seem to really work at catching errors...)
state := "Success"
for _, h := range w.Header()["Content-Type"] {
if h == "application/problem+json" {
state = "Error"
break
}
}
// set resp timing key based on success / failure
stats.TimingDuration(fmt.Sprintf("HttpResponseTime.%s.%s", r.URL, state), time.Since(cStart), 1.0)
})
}
/*
DBSource maps a given Database schema to a CA Key Hash, so we can pick
from among them when presented with OCSP requests for different certs.
@ -156,19 +125,22 @@ func main() {
src, err := NewSourceFromDatabase(dbMap, caCert.SubjectKeyId)
cmd.FailOnError(err, "Could not connect to OCSP database")
// Configure HTTP
m := http.NewServeMux()
m.Handle(c.OCSPResponder.Path, cfocsp.Responder{Source: src})
stopTimeout, err := time.ParseDuration(c.OCSPResponder.ShutdownStopTimeout)
cmd.FailOnError(err, "Couldn't parse shutdown stop timeout")
killTimeout, err := time.ParseDuration(c.OCSPResponder.ShutdownKillTimeout)
cmd.FailOnError(err, "Couldn't parse shutdown kill timeout")
// Configure HTTP
m := http.NewServeMux()
m.Handle(c.OCSPResponder.Path, cfocsp.Responder{Source: src})
httpMonitor := metrics.NewHTTPMonitor(stats, m, "OCSP")
srv := &http.Server{
Addr: c.OCSPResponder.ListenAddress,
Handler: HandlerTimer(m, stats),
Addr: c.OCSPResponder.ListenAddress,
ConnState: httpMonitor.ConnectionMonitor,
Handler: httpMonitor.Handle(),
}
hd := &httpdown.HTTP{
StopTimeout: stopTimeout,
KillTimeout: killTimeout,

View File

@ -36,13 +36,13 @@ type OCSPUpdater struct {
dbMap *gorp.DbMap
}
func setupClients(c cmd.Config) (rpc.CertificateAuthorityClient, chan *amqp.Error) {
func setupClients(c cmd.Config, stats statsd.Statter) (rpc.CertificateAuthorityClient, chan *amqp.Error) {
ch, err := rpc.AmqpChannel(c)
cmd.FailOnError(err, "Could not connect to AMQP")
closeChan := ch.NotifyClose(make(chan *amqp.Error, 1))
caRPC, err := rpc.NewAmqpRPCClient("OCSP->CA", c.AMQP.CA.Server, ch)
caRPC, err := rpc.NewAmqpRPCClient("OCSP->CA", c.AMQP.CA.Server, ch, stats)
cmd.FailOnError(err, "Unable to create RPC client")
cac, err := rpc.NewCertificateAuthorityClient(caRPC)
@ -119,7 +119,7 @@ func (updater *OCSPUpdater) updateOneSerial(serial string) error {
tx, err := updater.dbMap.Begin()
if err != nil {
updater.log.Err(fmt.Sprintf("OCSP %s: Error starting transaction, aborting: %s", serial, err))
updater.stats.Inc("OCSP.UpdatesFailed", 1, 1.0)
updater.stats.Inc("OCSP.Updates.Failed", 1, 1.0)
tx.Rollback()
// Failure to begin transaction is a fatal error.
return FatalError(err.Error())
@ -127,7 +127,7 @@ func (updater *OCSPUpdater) updateOneSerial(serial string) error {
if err := updater.processResponse(tx, serial); err != nil {
updater.log.Err(fmt.Sprintf("OCSP %s: Could not process OCSP Response, skipping: %s", serial, err))
updater.stats.Inc("OCSP.UpdatesFailed", 1, 1.0)
updater.stats.Inc("OCSP.Updates.Failed", 1, 1.0)
tx.Rollback()
return err
}
@ -135,14 +135,14 @@ func (updater *OCSPUpdater) updateOneSerial(serial string) error {
err = tx.Commit()
if err != nil {
updater.log.Err(fmt.Sprintf("OCSP %s: Error committing transaction, skipping: %s", serial, err))
updater.stats.Inc("OCSP.UpdatesFailed", 1, 1.0)
updater.stats.Inc("OCSP.Updates.Failed", 1, 1.0)
tx.Rollback()
return err
}
updater.log.Info(fmt.Sprintf("OCSP %s: OK", serial))
updater.stats.Inc("OCSP.UpdatesProcessed", 1, 1.0)
updater.stats.TimingDuration("OCSP.UpdateTime", time.Since(innerStart), 1.0)
updater.stats.Inc("OCSP.Updates.Processed", 1, 1.0)
updater.stats.TimingDuration("OCSP.Updates.UpdateLatency", time.Since(innerStart), 1.0)
return nil
}
@ -176,8 +176,8 @@ func (updater *OCSPUpdater) findStaleResponses(oldestLastUpdatedTime time.Time,
}
}
updater.stats.TimingDuration("OCSP.BatchTime", time.Since(outerStart), 1.0)
updater.stats.Inc("OCSP.BatchesProcessed", 1, 1.0)
updater.stats.TimingDuration("OCSP.Updates.BatchLatency", time.Since(outerStart), 1.0)
updater.stats.Inc("OCSP.Updates.BatchesProcessed", 1, 1.0)
}
return err
@ -217,7 +217,7 @@ func main() {
dbMap, err := sa.NewDbMap(c.OCSPUpdater.DBConnect)
cmd.FailOnError(err, "Could not connect to database")
cac, closeChan := setupClients(c)
cac, closeChan := setupClients(c, stats)
go func() {
// Abort if we disconnect from AMQP

View File

@ -331,25 +331,27 @@ func FailOnError(err error, msg string) {
}
}
// ProfileCmd runs forever, sending Go statistics to StatsD.
// ProfileCmd runs forever, sending Go runtime statistics to StatsD.
func ProfileCmd(profileName string, stats statsd.Statter) {
for {
c := time.Tick(1 * time.Second)
for range c {
var memoryStats runtime.MemStats
runtime.ReadMemStats(&memoryStats)
stats.Gauge(fmt.Sprintf("Gostats.%s.Goroutines", profileName), int64(runtime.NumGoroutine()), 1.0)
stats.Gauge(fmt.Sprintf("%s.Gostats.Goroutines", profileName), int64(runtime.NumGoroutine()), 1.0)
stats.Gauge(fmt.Sprintf("Gostats.%s.Heap.Objects", profileName), int64(memoryStats.HeapObjects), 1.0)
stats.Gauge(fmt.Sprintf("Gostats.%s.Heap.Idle", profileName), int64(memoryStats.HeapIdle), 1.0)
stats.Gauge(fmt.Sprintf("Gostats.%s.Heap.InUse", profileName), int64(memoryStats.HeapInuse), 1.0)
stats.Gauge(fmt.Sprintf("Gostats.%s.Heap.Released", profileName), int64(memoryStats.HeapReleased), 1.0)
stats.Gauge(fmt.Sprintf("%s.Gostats.Heap.Alloc", profileName), int64(memoryStats.HeapAlloc), 1.0)
stats.Gauge(fmt.Sprintf("%s.Gostats.Heap.Objects", profileName), int64(memoryStats.HeapObjects), 1.0)
stats.Gauge(fmt.Sprintf("%s.Gostats.Heap.Idle", profileName), int64(memoryStats.HeapIdle), 1.0)
stats.Gauge(fmt.Sprintf("%s.Gostats.Heap.InUse", profileName), int64(memoryStats.HeapInuse), 1.0)
stats.Gauge(fmt.Sprintf("%s.Gostats.Heap.Released", profileName), int64(memoryStats.HeapReleased), 1.0)
gcPauseAvg := int64(memoryStats.PauseTotalNs) / int64(len(memoryStats.PauseNs))
stats.Timing(fmt.Sprintf("Gostats.%s.Gc.PauseAvg", profileName), gcPauseAvg, 1.0)
stats.Gauge(fmt.Sprintf("Gostats.%s.Gc.NextAt", profileName), int64(memoryStats.NextGC), 1.0)
time.Sleep(time.Second)
// Calculate average and last and convert from nanoseconds to milliseconds
gcPauseAvg := (int64(memoryStats.PauseTotalNs) / int64(len(memoryStats.PauseNs))) / 1000000
lastGC := int64(memoryStats.PauseNs[(memoryStats.NumGC+255)%256]) / 1000000
stats.Timing(fmt.Sprintf("%s.Gostats.Gc.PauseAvg", profileName), gcPauseAvg, 1.0)
stats.Gauge(fmt.Sprintf("%s.Gostats.Gc.LastPauseLatency", profileName), lastGC, 1.0)
stats.Gauge(fmt.Sprintf("%s.Gostats.Gc.NextAt", profileName), int64(memoryStats.NextGC), 1.0)
}
}

148
docs/metrics/README.md Normal file
View File

@ -0,0 +1,148 @@
Boulder can provide various activity and performance metrics using StatsD if a server address is provided in the Boulder configuration file. This configuration object should look something like:
```
"statsd": {
"server": "localhost:8125",
"prefix": "Boulder"
}
```
The prefix will be prepended to all sent metrics to differentiate different sets of Boulder instances submitting metrics to the same StatsD server.
## List of collected metrics
This list is split up into metric topics with the names of the clients that submit these metrics.
* Logging (`cmd/boulder-*` + `cmd/ocsp-responder` + `cmd/ocsp-updater` + `cmd/admin-revoker`
+ `cmd/activity-monitor` + `cmd/expiration-mailer` + `cmd/external-cert-importer`)
```
[counter] Boulder.Logging.Audit
[counter] Boulder.Logging.Alert
[counter] Boulder.Logging.Crit
[counter] Boulder.Logging.Debug
[counter] Boulder.Logging.Emerg
[counter] Boulder.Logging.Err
[counter] Boulder.Logging.Info
[counter] Boulder.Logging.Warning
```
* RPC activity (`cmd/activity-monitor`)
```
[counter] Boulder.RPC.Rate.Success
[counter] Boulder.RPC.Rate.Error
[counter] Boulder.RPC.Traffic
[counter] Boulder.RPC.Timeouts
[gauge] Boulder.RPC.CallsWaiting
[timing] Boulder.RPC.Latency.{RPC method name}
```
* HTTP activity (`cmd/boulder-wfe` + `cmd/ocsp-responder`)
```
[counter] Boulder.{WFE/OCSP}.HTTP.Rate
[gauge] Boulder.{WFE/OCSP}.HTTP.ConnectionsInFlight
[gauge] Boulder.{WFE/OCSP}.HTTP.OpenConnections
[timing] Boulder.{WFE/OCSP}.HTTP.ResponseTime.{http endpoint}
[timing] Boulder.{WFE/OCSP}.HTTP.ResponseTime.Failed
```
* HTTP errors (`cmd/boulder-wfe`)
```
[counter] Boulder.WFE.HTTP.ErrorCodes.{3 digit code}
[counter] Boulder.WFE.HTTP.ProblemTypes.{problem type}
```
* DNS activity (`cmd/boulder-va` + `cmd/boulder-ra`)
```
(VA)
[counter] Boulder.VA.DNS.Rate
[timing] Boulder.VA.DNS.RTT.A
[timing] Boulder.VA.DNS.RTT.CAA
[timing] Boulder.VA.DNS.RTT.CNAME
[timing] Boulder.VA.DNS.RTT.TXT
(RA)
[counter] Boulder.RA.DNS.Rate
[timing] Boulder.RA.DNS.RTT.MX
```
* Validation attempts (`cmd/boulder-va`)
```
[timing] Boulder.VA.Validations.{challenge type}.{challenge status}
```
* Registration authority activity (`cmd/boulder-ra`)
```
[counter] Boulder.RA.NewRegistrations
[counter] Boulder.RA.NewPendingAuthorizations
[counter] Boulder.RA.NewCertificates
[counter] Boulder.RA.UpdatedRegistrations
[counter] Boulder.RA.UpdatedPendingAuthorizations
[counter] Boulder.RA.RevokedCertificates
[counter] Boulder.RA.FinalizedAuthorizations
```
* Client performance profiling (`cmd/boulder-*`)
```
[gauge] Boulder.{cmd-name}.Gostats.Goroutines
[gauge] Boulder.{cmd-name}.Gostats.Heap.Alloc
[gauge] Boulder.{cmd-name}.Gostats.Heap.Objects
[gauge] Boulder.{cmd-name}.Gostats.Heap.Idle
[gauge] Boulder.{cmd-name}.Gostats.Heap.InUse
[gauge] Boulder.{cmd-name}.Gostats.Heap.Released
[gauge] Boulder.{cmd-name}.Gostats.Gc.NextAt
[gauge] Boulder.{cmd-name}.Gostats.Gc.LastPauseLatency
[timing] Boulder.{cmd-name}.Gostats.Gc.PauseAvg
```
* External certificate store loading (`cmd/external-cert-importer`)
```
[counter] Boulder.ExistingCert.Certs.Imported
[counter] Boulder.ExistingCert.Domains.Imported
[counter] Boulder.ExistingCert.Removed
[timing] Boulder.ExistingCert.Certs.ImportLatency
[timing] Boulder.ExistingCert.Domains.ImportLatency
[timing] Boulder.ExistingCert.Certs.DeleteLatency
[timing] Boulder.ExistingCert.Domains.DeleteLatency
```
* OCSP response updating (`cmd/ocsp-updater`)
```
[counter] Boulder.OCSP.Updates.Processed
[counter] Boulder.OCSP.Updates.Failed
[counter] Boulder.OCSP.Updates.BatchesProcessed
[timing] Boulder.OCSP.Updates.UpdateLatency
[timing] Boulder.OCSP.Updates.BatchLatency
```
* Certificate expiration mailing (`cmd/expiration-mailer`)
```
[counter] Boulder.Mailer.Expiration.Sent
[counter] Boulder.Mailer.Expiration.Errors.SendingNag.TemplateFailure
[counter] Boulder.Mailer.Expiration.Errors.SendingNag.SendFailure
[counter] Boulder.Mailer.Expiration.Errors.GetRegistration
[counter] Boulder.Mailer.Expiration.Errors.ParseCertificate
[counter] Boulder.Mailer.Expiration.Errors.UpdateCertificateStatus
[timing] Boulder.Mailer.Expiration.SendLatency
[timing] Boulder.Mailer.Expiration.ProcessingCertificatesLatency
```

87
metrics/metrics.go Normal file
View File

@ -0,0 +1,87 @@
// Copyright 2015 ISRG. All rights reserved
// This Source Code Form is subject to the terms of the Mozilla Public
// License, v. 2.0. If a copy of the MPL was not distributed with this
// file, You can obtain one at http://mozilla.org/MPL/2.0/.
package metrics
import (
"fmt"
"net"
"net/http"
"strings"
"sync/atomic"
"time"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cactus/go-statsd-client/statsd"
)
// HTTPMonitor stores some server state
type HTTPMonitor struct {
stats statsd.Statter
statsPrefix string
handler http.Handler
connectionsInFlight int64
openConnections int64
}
// NewHTTPMonitor returns a new initialized HTTPMonitor
func NewHTTPMonitor(stats statsd.Statter, handler http.Handler, prefix string) HTTPMonitor {
return HTTPMonitor{
stats: stats,
handler: handler,
statsPrefix: prefix,
connectionsInFlight: 0,
openConnections: 0,
}
}
// ConnectionMonitor provides states on open connection state
func (h *HTTPMonitor) ConnectionMonitor(_ net.Conn, state http.ConnState) {
var open int64
switch state {
case http.StateNew:
open = atomic.AddInt64(&h.openConnections, 1)
case http.StateHijacked:
fallthrough
case http.StateClosed:
open = atomic.AddInt64(&h.openConnections, -1)
default:
return
}
h.stats.Gauge(fmt.Sprintf("%s.HTTP.OpenConnections", h.statsPrefix), open, 1.0)
}
// Handle wraps handlers and records various metrics about requests to these handlers
// and sends them to StatsD
func (h *HTTPMonitor) Handle() http.Handler {
return http.HandlerFunc(h.watchAndServe)
}
func (h *HTTPMonitor) watchAndServe(w http.ResponseWriter, r *http.Request) {
h.stats.Inc(fmt.Sprintf("%s.HTTP.Rate", h.statsPrefix), 1, 1.0)
inFlight := atomic.AddInt64(&h.connectionsInFlight, 1)
h.stats.Gauge(fmt.Sprintf("%s.HTTP.OpenConnections", h.statsPrefix), inFlight, 1.0)
cOpened := time.Now()
h.handler.ServeHTTP(w, r)
cClosed := time.Since(cOpened)
inFlight = atomic.AddInt64(&h.connectionsInFlight, -1)
h.stats.Gauge(fmt.Sprintf("%s.HTTP.ConnectionsInFlight", h.statsPrefix), inFlight, 1.0)
endpoint := ""
// If request fails don't record the endpoint as an attacker could use this to
// eat up all our memory by just hitting 404s all day
if w.Header().Get("Content-Type") == "application/problem+json" {
endpoint = "Failed"
} else {
// If r.URL has more than two segments throw the rest away to simplify metrics
segments := strings.Split(r.URL.Path, "/")
if len(segments) > 3 {
segments = segments[:3]
}
endpoint = strings.Join(segments, "/")
}
h.stats.TimingDuration(fmt.Sprintf("%s.HTTP.ResponseTime.%s", h.statsPrefix, endpoint), cClosed, 1.0)
}

6
metrics/metrics_test.go Normal file
View File

@ -0,0 +1,6 @@
// Copyright 2015 ISRG. All rights reserved
// This Source Code Form is subject to the terms of the Mozilla Public
// License, v. 2.0. If a copy of the MPL was not distributed with this
// file, You can obtain one at http://mozilla.org/MPL/2.0/.
package metrics

View File

@ -15,6 +15,8 @@ import (
"strings"
"time"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cactus/go-statsd-client/statsd"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/jmhodges/clock"
"github.com/letsencrypt/boulder/core"
blog "github.com/letsencrypt/boulder/log"
@ -35,6 +37,7 @@ type RegistrationAuthorityImpl struct {
VA core.ValidationAuthority
SA core.StorageAuthority
PA core.PolicyAuthority
stats statsd.Statter
DNSResolver core.DNSResolver
clk clock.Clock
log *blog.AuditLogger
@ -43,16 +46,17 @@ type RegistrationAuthorityImpl struct {
}
// NewRegistrationAuthorityImpl constructs a new RA object.
func NewRegistrationAuthorityImpl(clk clock.Clock, logger *blog.AuditLogger) RegistrationAuthorityImpl {
func NewRegistrationAuthorityImpl(clk clock.Clock, logger *blog.AuditLogger, stats statsd.Statter) RegistrationAuthorityImpl {
ra := RegistrationAuthorityImpl{
clk: clk,
log: logger,
stats: stats,
clk: clk,
log: logger,
authorizationLifetime: DefaultAuthorizationLifetime,
}
return ra
}
func validateEmail(address string, resolver core.DNSResolver) (err error) {
func validateEmail(address string, resolver core.DNSResolver) (rtt time.Duration, err error) {
_, err = mail.ParseAddress(address)
if err != nil {
err = core.MalformedRequestError(fmt.Sprintf("%s is not a valid e-mail address", address))
@ -61,29 +65,11 @@ func validateEmail(address string, resolver core.DNSResolver) (err error) {
splitEmail := strings.SplitN(address, "@", -1)
domain := strings.ToLower(splitEmail[len(splitEmail)-1])
var mx []string
mx, _, err = resolver.LookupMX(domain)
mx, rtt, err = resolver.LookupMX(domain)
if err != nil || len(mx) == 0 {
err = core.MalformedRequestError(fmt.Sprintf("No MX record for domain %s", domain))
return
}
return
}
func validateContacts(contacts []*core.AcmeURL, resolver core.DNSResolver) (err error) {
for _, contact := range contacts {
switch contact.Scheme {
case "tel":
continue
case "mailto":
err = validateEmail(contact.Opaque, resolver)
if err != nil {
return
}
default:
err = core.MalformedRequestError(fmt.Sprintf("Contact method %s is not supported", contact.Scheme))
return
}
}
return
}
@ -114,7 +100,7 @@ func (ra *RegistrationAuthorityImpl) NewRegistration(init core.Registration) (re
}
reg.MergeUpdate(init)
err = validateContacts(reg.Contact, ra.DNSResolver)
err = validateContacts(reg.Contact, ra.DNSResolver, ra.stats)
if err != nil {
return
}
@ -127,6 +113,28 @@ func (ra *RegistrationAuthorityImpl) NewRegistration(init core.Registration) (re
err = core.InternalServerError(err.Error())
}
ra.stats.Inc("RA.NewRegistrations", 1, 1.0)
return
}
func validateContacts(contacts []*core.AcmeURL, resolver core.DNSResolver, stats statsd.Statter) (err error) {
for _, contact := range contacts {
switch contact.Scheme {
case "tel":
continue
case "mailto":
rtt, err := validateEmail(contact.Opaque, resolver)
stats.TimingDuration("RA.DNS.RTT.MX", rtt, 1.0)
stats.Inc("RA.DNS.Rate", 1, 1.0)
if err != nil {
return err
}
default:
err = core.MalformedRequestError(fmt.Sprintf("Contact method %s is not supported", contact.Scheme))
return
}
}
return
}
@ -161,7 +169,7 @@ func (ra *RegistrationAuthorityImpl) NewAuthorization(request core.Authorization
// Create validations, but we have to update them with URIs later
challenges, combinations := ra.PA.ChallengesFor(identifier)
for i, _ := range challenges {
for i := range challenges {
// Add the account key used to generate the challenge
challenges[i].AccountKey = &reg.Key
}
@ -408,6 +416,8 @@ func (ra *RegistrationAuthorityImpl) NewCertificate(req core.CertificateRequest,
logEvent.ResponseTime = ra.clk.Now()
logEventResult = "successful"
ra.stats.Inc("RA.NewCertificates", 1, 1.0)
return cert, nil
}
@ -415,7 +425,7 @@ func (ra *RegistrationAuthorityImpl) NewCertificate(req core.CertificateRequest,
func (ra *RegistrationAuthorityImpl) UpdateRegistration(base core.Registration, update core.Registration) (reg core.Registration, err error) {
base.MergeUpdate(update)
err = validateContacts(base.Contact, ra.DNSResolver)
err = validateContacts(base.Contact, ra.DNSResolver, ra.stats)
if err != nil {
return
}
@ -427,6 +437,8 @@ func (ra *RegistrationAuthorityImpl) UpdateRegistration(base core.Registration,
// passed to the SA.
err = core.InternalServerError(fmt.Sprintf("Could not update registration: %s", err))
}
ra.stats.Inc("RA.UpdatedRegistrations", 1, 1.0)
return
}
@ -447,6 +459,7 @@ func (ra *RegistrationAuthorityImpl) UpdateAuthorization(base core.Authorization
err = core.MalformedRequestError("Challenge data was corrupted")
return
}
ra.stats.Inc("RA.NewPendingAuthorizations", 1, 1.0)
// Look up the account key for this authorization
reg, err := ra.SA.GetRegistration(authz.RegistrationID)
@ -465,6 +478,7 @@ func (ra *RegistrationAuthorityImpl) UpdateAuthorization(base core.Authorization
// Dispatch to the VA for service
ra.VA.UpdateValidations(authz, challengeIndex)
ra.stats.Inc("RA.UpdatedPendingAuthorizations", 1, 1.0)
return
}
@ -540,6 +554,7 @@ func (ra *RegistrationAuthorityImpl) AdministrativelyRevokeCertificate(cert x509
}
state = "Success"
ra.stats.Inc("RA.RevokedCertificates", 1, 1.0)
return nil
}
@ -575,6 +590,12 @@ func (ra *RegistrationAuthorityImpl) OnValidationUpdate(authz core.Authorization
authz.Expires = &exp
}
// Finalize the authorization (error ignored)
return ra.SA.FinalizeAuthorization(authz)
// Finalize the authorization
err := ra.SA.FinalizeAuthorization(authz)
if err != nil {
return err
}
ra.stats.Inc("RA.FinalizedAuthorizations", 1, 1.0)
return nil
}

View File

@ -17,6 +17,7 @@ import (
"testing"
"time"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cactus/go-statsd-client/statsd"
cfsslConfig "github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cloudflare/cfssl/config"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cloudflare/cfssl/ocsp"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cloudflare/cfssl/signer/local"
@ -209,7 +210,8 @@ func initAuthorities(t *testing.T) (*DummyValidationAuthority, *sa.SQLStorageAut
Registration, _ = ssa.NewRegistration(core.Registration{Key: AccountKeyA})
ra := NewRegistrationAuthorityImpl(fc, blog.GetAuditLogger())
stats, _ := statsd.NewNoopClient()
ra := NewRegistrationAuthorityImpl(fc, blog.GetAuditLogger(), stats)
ra.SA = ssa
ra.VA = va
ra.CA = &ca
@ -271,38 +273,40 @@ func TestValidateContacts(t *testing.T) {
invalidEmail, _ := core.ParseAcmeURL("mailto:admin@example.com")
malformedEmail, _ := core.ParseAcmeURL("mailto:admin.com")
err := validateContacts([]*core.AcmeURL{}, &mocks.MockDNS{})
nStats, _ := statsd.NewNoopClient()
err := validateContacts([]*core.AcmeURL{}, &mocks.MockDNS{}, nStats)
test.AssertNotError(t, err, "No Contacts")
err = validateContacts([]*core.AcmeURL{tel}, &mocks.MockDNS{})
err = validateContacts([]*core.AcmeURL{tel}, &mocks.MockDNS{}, nStats)
test.AssertNotError(t, err, "Simple Telephone")
err = validateContacts([]*core.AcmeURL{validEmail}, &mocks.MockDNS{})
err = validateContacts([]*core.AcmeURL{validEmail}, &mocks.MockDNS{}, nStats)
test.AssertNotError(t, err, "Valid Email")
err = validateContacts([]*core.AcmeURL{invalidEmail}, &mocks.MockDNS{})
err = validateContacts([]*core.AcmeURL{invalidEmail}, &mocks.MockDNS{}, nStats)
test.AssertError(t, err, "Invalid Email")
err = validateContacts([]*core.AcmeURL{malformedEmail}, &mocks.MockDNS{})
err = validateContacts([]*core.AcmeURL{malformedEmail}, &mocks.MockDNS{}, nStats)
test.AssertError(t, err, "Malformed Email")
err = validateContacts([]*core.AcmeURL{ansible}, &mocks.MockDNS{})
err = validateContacts([]*core.AcmeURL{ansible}, &mocks.MockDNS{}, nStats)
test.AssertError(t, err, "Unknown scehme")
}
func TestValidateEmail(t *testing.T) {
err := validateEmail("an email`", &mocks.MockDNS{})
_, err := validateEmail("an email`", &mocks.MockDNS{})
test.AssertError(t, err, "Malformed")
err = validateEmail("a@not.a.domain", &mocks.MockDNS{})
_, err = validateEmail("a@not.a.domain", &mocks.MockDNS{})
test.AssertError(t, err, "Cannot resolve")
t.Logf("No Resolve: %s", err)
err = validateEmail("a@example.com", &mocks.MockDNS{})
_, err = validateEmail("a@example.com", &mocks.MockDNS{})
test.AssertError(t, err, "No MX Record")
t.Logf("No MX: %s", err)
err = validateEmail("a@email.com", &mocks.MockDNS{})
_, err = validateEmail("a@email.com", &mocks.MockDNS{})
test.AssertNotError(t, err, "Valid")
}

View File

@ -20,7 +20,9 @@ import (
"syscall"
"time"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cactus/go-statsd-client/statsd"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/streadway/amqp"
"github.com/letsencrypt/boulder/cmd"
"github.com/letsencrypt/boulder/core"
blog "github.com/letsencrypt/boulder/log"
@ -478,10 +480,12 @@ type AmqpRPCCLient struct {
mu sync.RWMutex
pending map[string]chan []byte
stats statsd.Statter
}
// NewAmqpRPCClient constructs an RPC client using AMQP
func NewAmqpRPCClient(clientQueuePrefix, serverQueue string, channel *amqp.Channel) (rpc *AmqpRPCCLient, err error) {
func NewAmqpRPCClient(clientQueuePrefix, serverQueue string, channel *amqp.Channel, stats statsd.Statter) (rpc *AmqpRPCCLient, err error) {
hostname, err := os.Hostname()
if err != nil {
return nil, err
@ -501,6 +505,7 @@ func NewAmqpRPCClient(clientQueuePrefix, serverQueue string, channel *amqp.Chann
pending: make(map[string]chan []byte),
timeout: 10 * time.Second,
log: blog.GetAuditLogger(),
stats: stats,
}
// Subscribe to the response queue and dispatch
@ -572,6 +577,11 @@ func (rpc *AmqpRPCCLient) Dispatch(method string, body []byte) chan []byte {
// DispatchSync sends a body to the destination, and blocks waiting on a response.
func (rpc *AmqpRPCCLient) DispatchSync(method string, body []byte) (response []byte, err error) {
rpc.stats.Inc(fmt.Sprintf("RPC.Rate.%s", method), 1, 1.0)
rpc.stats.Inc("RPC.Traffic", int64(len(body)), 1.0)
rpc.stats.GaugeDelta("RPC.CallsWaiting", 1, 1.0)
defer rpc.stats.GaugeDelta("RPC.CallsWaiting", -1, 1.0)
callStarted := time.Now()
select {
case jsonResponse := <-rpc.Dispatch(method, body):
var rpcResponse RPCResponse
@ -581,11 +591,16 @@ func (rpc *AmqpRPCCLient) DispatchSync(method string, body []byte) (response []b
}
err = unwrapError(rpcResponse.Error)
if err != nil {
rpc.stats.Inc(fmt.Sprintf("RPC.Latency.%s.Error", method), 1, 1.0)
return
}
rpc.stats.Inc("RPC.Rate.Success", 1, 1.0)
rpc.stats.TimingDuration(fmt.Sprintf("RPC.Latency.%s.Success", method), time.Since(callStarted), 1.0)
response = rpcResponse.ReturnVal
return
case <-time.After(rpc.timeout):
rpc.stats.TimingDuration(fmt.Sprintf("RPC.Latency.%s.Timeout", method), time.Since(callStarted), 1.0)
rpc.stats.Inc("RPC.Rate.Timeouts", 1, 1.0)
rpc.log.Warning(fmt.Sprintf(" [c!][%s] AMQP-RPC timeout [%s]", rpc.clientQueue, method))
err = errors.New("AMQP-RPC timeout")
return

View File

@ -21,6 +21,8 @@ import (
"strings"
"time"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cactus/go-statsd-client/statsd"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/jmhodges/clock"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/letsencrypt/go-jose"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/miekg/dns"
@ -48,6 +50,8 @@ type ValidationAuthorityImpl struct {
simpleHTTPSPort int
dvsniPort int
UserAgent string
stats statsd.Statter
clk clock.Clock
}
// PortConfig specifies what ports the VA should call to on the remote
@ -59,7 +63,7 @@ type PortConfig struct {
}
// NewValidationAuthorityImpl constructs a new VA
func NewValidationAuthorityImpl(pc *PortConfig) *ValidationAuthorityImpl {
func NewValidationAuthorityImpl(pc *PortConfig, stats statsd.Statter, clk clock.Clock) *ValidationAuthorityImpl {
logger := blog.GetAuditLogger()
logger.Notice("Validation Authority Starting")
return &ValidationAuthorityImpl{
@ -67,6 +71,8 @@ func NewValidationAuthorityImpl(pc *PortConfig) *ValidationAuthorityImpl {
simpleHTTPPort: pc.SimpleHTTPPort,
simpleHTTPSPort: pc.SimpleHTTPSPort,
dvsniPort: pc.DVSNIPort,
stats: stats,
clk: clk,
}
}
@ -138,13 +144,16 @@ func problemDetailsFromDNSError(err error) *core.ProblemDetails {
// This is the same choice made by the Go internal resolution library used by
// net/http, except we only send A queries and accept IPv4 addresses.
// TODO(#593): Add IPv6 support
func (va *ValidationAuthorityImpl) getAddr(hostname string) (addr net.IP, addrs []net.IP, problem *core.ProblemDetails) {
addrs, _, err := va.DNSResolver.LookupHost(hostname)
func (va ValidationAuthorityImpl) getAddr(hostname string) (addr net.IP, addrs []net.IP, problem *core.ProblemDetails) {
addrs, rtt, err := va.DNSResolver.LookupHost(hostname)
if err != nil {
problem = problemDetailsFromDNSError(err)
va.log.Debug(fmt.Sprintf("%s DNS failure: %s", hostname, err))
return
}
va.stats.TimingDuration("VA.DNS.RTT.A", rtt, 1.0)
va.stats.Inc("VA.DNS.Rate", 1, 1.0)
if len(addrs) == 0 {
problem = &core.ProblemDetails{
Type: core.UnknownHostProblem,
@ -527,7 +536,9 @@ func (va *ValidationAuthorityImpl) validateDNS(identifier core.AcmeIdentifier, i
// Look for the required record in the DNS
challengeSubdomain := fmt.Sprintf("%s.%s", core.DNSPrefix, identifier.Value)
txts, _, err := va.DNSResolver.LookupTXT(challengeSubdomain)
txts, rtt, err := va.DNSResolver.LookupTXT(challengeSubdomain)
va.stats.TimingDuration("VA.DNS.RTT.TXT", rtt, 1.0)
va.stats.Inc("VA.DNS.Rate", 1, 1.0)
if err != nil {
challenge.Status = core.StatusInvalid
@ -557,7 +568,7 @@ func (va *ValidationAuthorityImpl) validate(authz core.Authorization, challengeI
logEvent := verificationRequestEvent{
ID: authz.ID,
Requester: authz.RegistrationID,
RequestTime: time.Now(),
RequestTime: va.clk.Now(),
}
if !authz.Challenges[challengeIndex].IsSane(true) {
chall := &authz.Challenges[challengeIndex]
@ -569,6 +580,7 @@ func (va *ValidationAuthorityImpl) validate(authz core.Authorization, challengeI
} else {
var err error
vStart := va.clk.Now()
switch authz.Challenges[challengeIndex].Type {
case core.ChallengeTypeSimpleHTTP:
authz.Challenges[challengeIndex], err = va.validateSimpleHTTP(authz.Identifier, authz.Challenges[challengeIndex])
@ -577,6 +589,7 @@ func (va *ValidationAuthorityImpl) validate(authz core.Authorization, challengeI
case core.ChallengeTypeDNS:
authz.Challenges[challengeIndex], err = va.validateDNS(authz.Identifier, authz.Challenges[challengeIndex])
}
va.stats.TimingDuration(fmt.Sprintf("VA.Validations.%s.%s", authz.Challenges[challengeIndex].Type, authz.Challenges[challengeIndex].Status), time.Since(vStart), 1.0)
if err != nil {
logEvent.Error = err.Error()
@ -659,21 +672,27 @@ func (va *ValidationAuthorityImpl) getCAASet(hostname string) (*CAASet, error) {
if _, present := policy.PublicSuffixList[label]; present {
break
}
CAAs, _, err := va.DNSResolver.LookupCAA(label)
CAAs, caaRtt, err := va.DNSResolver.LookupCAA(label)
if err != nil {
return nil, err
}
va.stats.TimingDuration("VA.DNS.RTT.CAA", caaRtt, 1.0)
va.stats.Inc("VA.DNS.Rate", 1, 1.0)
if len(CAAs) > 0 {
return newCAASet(CAAs), nil
}
cname, _, err := va.DNSResolver.LookupCNAME(label)
cname, cnameRtt, err := va.DNSResolver.LookupCNAME(label)
if err != nil {
return nil, err
}
dname, _, err := va.DNSResolver.LookupDNAME(label)
va.stats.TimingDuration("VA.DNS.RTT.CNAME", cnameRtt, 1.0)
va.stats.Inc("VA.DNS.Rate", 1, 1.0)
dname, dnameRtt, err := va.DNSResolver.LookupDNAME(label)
if err != nil {
return nil, err
}
va.stats.TimingDuration("VA.DNS.RTT.DNAME", dnameRtt, 1.0)
va.stats.Inc("VA.DNS.Rate", 1, 1.0)
if cname == "" && dname == "" {
// Try parent domain (note we confirmed
// earlier that label contains '.')

View File

@ -27,6 +27,8 @@ import (
"testing"
"time"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/cactus/go-statsd-client/statsd"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/jmhodges/clock"
"github.com/letsencrypt/boulder/Godeps/_workspace/src/github.com/letsencrypt/go-jose"
"github.com/letsencrypt/boulder/core"
@ -243,7 +245,8 @@ func TestSimpleHttpTLS(t *testing.T) {
port, err := getPort(hs)
test.AssertNotError(t, err, "failed to get test server port")
va := NewValidationAuthorityImpl(&PortConfig{SimpleHTTPSPort: port})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{SimpleHTTPSPort: port}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
log.Clear()
@ -284,7 +287,8 @@ func TestSimpleHttp(t *testing.T) {
if badPort == 65536 {
badPort = goodPort - 1
}
va := NewValidationAuthorityImpl(&PortConfig{SimpleHTTPPort: badPort})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{SimpleHTTPPort: badPort}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
invalidChall, err := va.validateSimpleHTTP(ident, chall)
@ -292,7 +296,7 @@ func TestSimpleHttp(t *testing.T) {
test.AssertError(t, err, "Server's down; expected refusal. Where did we connect?")
test.AssertEquals(t, invalidChall.Error.Type, core.ConnectionProblem)
va = NewValidationAuthorityImpl(&PortConfig{SimpleHTTPPort: goodPort})
va = NewValidationAuthorityImpl(&PortConfig{SimpleHTTPPort: goodPort}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
log.Clear()
finChall, err := va.validateSimpleHTTP(ident, chall)
@ -369,7 +373,8 @@ func TestSimpleHttpRedirectLookup(t *testing.T) {
defer hs.Close()
port, err := getPort(hs)
test.AssertNotError(t, err, "failed to get test server port")
va := NewValidationAuthorityImpl(&PortConfig{SimpleHTTPPort: port})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{SimpleHTTPPort: port}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
log.Clear()
@ -429,7 +434,8 @@ func TestSimpleHttpRedirectLoop(t *testing.T) {
defer hs.Close()
port, err := getPort(hs)
test.AssertNotError(t, err, "failed to get test server port")
va := NewValidationAuthorityImpl(&PortConfig{SimpleHTTPPort: port})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{SimpleHTTPPort: port}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
log.Clear()
@ -462,7 +468,8 @@ func TestDvsni(t *testing.T) {
port, err := getPort(hs)
test.AssertNotError(t, err, "failed to get test server port")
va := NewValidationAuthorityImpl(&PortConfig{DVSNIPort: port})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{DVSNIPort: port}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
@ -522,7 +529,8 @@ func TestTLSError(t *testing.T) {
port, err := getPort(hs)
test.AssertNotError(t, err, "failed to get test server port")
va := NewValidationAuthorityImpl(&PortConfig{DVSNIPort: port})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{DVSNIPort: port}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
invalidChall, err := va.validateDvsni(ident, chall)
@ -541,7 +549,8 @@ func TestValidateHTTP(t *testing.T) {
hs := simpleSrv(t, challHTTP.Token, tls)
port, err := getPort(hs)
test.AssertNotError(t, err, "failed to get test server port")
va := NewValidationAuthorityImpl(&PortConfig{SimpleHTTPPort: port})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{SimpleHTTPPort: port}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
mockRA := &MockRegistrationAuthority{}
va.RA = mockRA
@ -587,7 +596,8 @@ func TestValidateDvsni(t *testing.T) {
port, err := getPort(hs)
test.AssertNotError(t, err, "failed to get test server port")
va := NewValidationAuthorityImpl(&PortConfig{DVSNIPort: port})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{DVSNIPort: port}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
mockRA := &MockRegistrationAuthority{}
va.RA = mockRA
@ -604,7 +614,8 @@ func TestValidateDvsni(t *testing.T) {
}
func TestValidateDvsniNotSane(t *testing.T) {
va := NewValidationAuthorityImpl(&PortConfig{}) // no calls made
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{}, stats, clock.Default()) // no calls made
va.DNSResolver = &mocks.MockDNS{}
mockRA := &MockRegistrationAuthority{}
va.RA = mockRA
@ -625,7 +636,8 @@ func TestValidateDvsniNotSane(t *testing.T) {
}
func TestUpdateValidations(t *testing.T) {
va := NewValidationAuthorityImpl(&PortConfig{})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
mockRA := &MockRegistrationAuthority{}
va.RA = mockRA
@ -680,7 +692,8 @@ func TestCAAChecking(t *testing.T) {
// CNAME to critical
}
va := NewValidationAuthorityImpl(&PortConfig{})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
va.IssuerDomain = "letsencrypt.org"
for _, caaTest := range tests {
@ -712,7 +725,8 @@ func TestCAAChecking(t *testing.T) {
}
func TestDNSValidationFailure(t *testing.T) {
va := NewValidationAuthorityImpl(&PortConfig{})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
mockRA := &MockRegistrationAuthority{}
va.RA = mockRA
@ -748,7 +762,8 @@ func TestDNSValidationInvalid(t *testing.T) {
Challenges: []core.Challenge{chalDNS},
}
va := NewValidationAuthorityImpl(&PortConfig{})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
mockRA := &MockRegistrationAuthority{}
va.RA = mockRA
@ -761,7 +776,8 @@ func TestDNSValidationInvalid(t *testing.T) {
}
func TestDNSValidationNotSane(t *testing.T) {
va := NewValidationAuthorityImpl(&PortConfig{})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
mockRA := &MockRegistrationAuthority{}
va.RA = mockRA
@ -791,7 +807,8 @@ func TestDNSValidationNotSane(t *testing.T) {
}
func TestDNSValidationServFail(t *testing.T) {
va := NewValidationAuthorityImpl(&PortConfig{})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
mockRA := &MockRegistrationAuthority{}
va.RA = mockRA
@ -816,7 +833,8 @@ func TestDNSValidationServFail(t *testing.T) {
}
func TestDNSValidationNoServer(t *testing.T) {
va := NewValidationAuthorityImpl(&PortConfig{})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{}, stats, clock.Default())
va.DNSResolver = core.NewTestDNSResolverImpl(time.Second*5, []string{})
mockRA := &MockRegistrationAuthority{}
va.RA = mockRA
@ -840,7 +858,8 @@ func TestDNSValidationNoServer(t *testing.T) {
// the existance of some Internet resources. Because of that,
// it asserts nothing; it is intended for coverage.
func TestDNSValidationLive(t *testing.T) {
va := NewValidationAuthorityImpl(&PortConfig{})
stats, _ := statsd.NewNoopClient()
va := NewValidationAuthorityImpl(&PortConfig{}, stats, clock.Default())
va.DNSResolver = &mocks.MockDNS{}
mockRA := &MockRegistrationAuthority{}
va.RA = mockRA

View File

@ -43,7 +43,7 @@ const (
type WebFrontEndImpl struct {
RA core.RegistrationAuthority
SA core.StorageGetter
Stats statsd.Statter
stats statsd.Statter
log *blog.AuditLogger
// URL configuration parameters
@ -119,7 +119,7 @@ type requestEvent struct {
}
// NewWebFrontEndImpl constructs a web service for Boulder
func NewWebFrontEndImpl() (WebFrontEndImpl, error) {
func NewWebFrontEndImpl(stats statsd.Statter) (WebFrontEndImpl, error) {
logger := blog.GetAuditLogger()
logger.Notice("Web Front End Starting")
@ -131,6 +131,7 @@ func NewWebFrontEndImpl() (WebFrontEndImpl, error) {
return WebFrontEndImpl{
log: logger,
nonceService: nonceService,
stats: stats,
}, nil
}
@ -250,6 +251,7 @@ func (wfe *WebFrontEndImpl) Index(response http.ResponseWriter, request *http.Re
if request.URL.Path != "/" {
logEvent.Error = "Resource not found"
http.NotFound(response, request)
response.Header().Set("Content-Type", "application/problem+json")
return
}
@ -450,6 +452,12 @@ func (wfe *WebFrontEndImpl) sendError(response http.ResponseWriter, msg string,
response.Header().Set("Content-Type", "application/problem+json")
response.WriteHeader(code)
response.Write(problemDoc)
wfe.stats.Inc(fmt.Sprintf("WFE.HTTP.ErrorCodes.%d", code), 1, 1.0)
problemSegments := strings.Split(string(problem.Type), ":")
if len(problemSegments) > 0 {
wfe.stats.Inc(fmt.Sprintf("WFE.HTTP.ProblemTypes.%s", problemSegments[len(problemSegments)-1]), 1, 1.0)
}
}
func link(url, relation string) string {
@ -519,9 +527,6 @@ func (wfe *WebFrontEndImpl) NewRegistration(response http.ResponseWriter, reques
response.WriteHeader(http.StatusCreated)
response.Write(responseBody)
// incr reg stat
wfe.Stats.Inc("Registrations", 1, 1.0)
}
// NewAuthorization is used by clients to submit a new ID Authorization
@ -588,8 +593,6 @@ func (wfe *WebFrontEndImpl) NewAuthorization(response http.ResponseWriter, reque
logEvent.Error = err.Error()
wfe.log.Warning(fmt.Sprintf("Could not write response: %s", err))
}
// incr pending auth stat (?)
wfe.Stats.Inc("PendingAuthorizations", 1, 1.0)
}
// RevokeCertificate is used by clients to request the revocation of a cert.
@ -678,8 +681,6 @@ func (wfe *WebFrontEndImpl) RevokeCertificate(response http.ResponseWriter, requ
wfe.sendError(response, "Failed to revoke certificate", err, statusCodeFromError(err))
} else {
wfe.log.Debug(fmt.Sprintf("Revoked %v", serial))
// incr revoked cert stat
wfe.Stats.Inc("RevokedCertificates", 1, 1.0)
response.WriteHeader(http.StatusOK)
}
}
@ -785,8 +786,6 @@ func (wfe *WebFrontEndImpl) NewCertificate(response http.ResponseWriter, request
logEvent.Error = err.Error()
wfe.log.Warning(fmt.Sprintf("Could not write response: %s", err))
}
// incr cert stat
wfe.Stats.Inc("Certificates", 1, 1.0)
}
func (wfe *WebFrontEndImpl) Challenge(

View File

@ -198,7 +198,8 @@ func signRequest(t *testing.T, req string, nonceService *core.NonceService) stri
}
func setupWFE(t *testing.T) WebFrontEndImpl {
wfe, err := NewWebFrontEndImpl()
stats, _ := statsd.NewNoopClient()
wfe, err := NewWebFrontEndImpl(stats)
test.AssertNotError(t, err, "Unable to create WFE")
wfe.NewReg = wfe.BaseURL + NewRegPath
@ -213,7 +214,7 @@ func setupWFE(t *testing.T) WebFrontEndImpl {
wfe.RA = &MockRegistrationAuthority{}
wfe.SA = &mocks.MockSA{}
wfe.Stats, _ = statsd.NewNoopClient()
wfe.stats, _ = statsd.NewNoopClient()
wfe.SubscriberAgreementURL = agreementURL
return wfe
@ -434,13 +435,13 @@ func TestIssueCertificate(t *testing.T) {
// TODO: Use a mock RA so we can test various conditions of authorized, not
// authorized, etc.
ra := ra.NewRegistrationAuthorityImpl(fakeClock, wfe.log)
stats, _ := statsd.NewNoopClient(nil)
ra := ra.NewRegistrationAuthorityImpl(fakeClock, wfe.log, stats)
ra.SA = &mocks.MockSA{}
ra.CA = &MockCA{}
ra.PA = &MockPA{}
wfe.SA = &mocks.MockSA{}
wfe.RA = &ra
wfe.Stats, _ = statsd.NewNoopClient()
responseWriter := httptest.NewRecorder()
// GET instead of POST should be rejected
@ -595,7 +596,7 @@ func TestNewRegistration(t *testing.T) {
wfe.RA = &MockRegistrationAuthority{}
wfe.SA = &mocks.MockSA{}
wfe.Stats, _ = statsd.NewNoopClient()
wfe.stats, _ = statsd.NewNoopClient()
wfe.SubscriberAgreementURL = agreementURL
key, err := jose.LoadPrivateKey([]byte(test2KeyPrivatePEM))
@ -867,7 +868,7 @@ func TestRevokeCertificateAlreadyRevoked(t *testing.T) {
wfe.RA = &MockRegistrationAuthority{}
wfe.SA = &mocks.MockSA{}
wfe.Stats, _ = statsd.NewNoopClient()
wfe.stats, _ = statsd.NewNoopClient()
wfe.SubscriberAgreementURL = agreementURL
responseWriter := httptest.NewRecorder()
responseWriter.Body.Reset()
@ -888,7 +889,7 @@ func TestAuthorization(t *testing.T) {
wfe.RA = &MockRegistrationAuthority{}
wfe.SA = &mocks.MockSA{}
wfe.Stats, _ = statsd.NewNoopClient()
wfe.stats, _ = statsd.NewNoopClient()
responseWriter := httptest.NewRecorder()
// GET instead of POST should be rejected
@ -976,7 +977,7 @@ func TestRegistration(t *testing.T) {
wfe.RA = &MockRegistrationAuthority{}
wfe.SA = &mocks.MockSA{}
wfe.Stats, _ = statsd.NewNoopClient()
wfe.stats, _ = statsd.NewNoopClient()
wfe.SubscriberAgreementURL = agreementURL
responseWriter := httptest.NewRecorder()
@ -1067,7 +1068,7 @@ func TestTermsRedirect(t *testing.T) {
wfe.RA = &MockRegistrationAuthority{}
wfe.SA = &mocks.MockSA{}
wfe.Stats, _ = statsd.NewNoopClient()
wfe.stats, _ = statsd.NewNoopClient()
wfe.SubscriberAgreementURL = agreementURL
responseWriter := httptest.NewRecorder()