Audit all Challenges (success/failure) in VA for Issue #204

- Don't ignore entropy underruns in challenges.go
- Correct identity crisis in Policy Authority; hopefully it will remember.
- Add a method `AuditObject` in audit-logger and convert RA/VA to use it
- Fix json typo in registration-authority that caused empty audit logs
- Fix vet issue in WFE where RegID was being printed as a 32-bit int instead of 64-bit
- Unfix the issue in WFE where RegID isn't right, per PR #215
This commit is contained in:
J.C. Jones 2015-05-21 09:17:39 -07:00
parent a9a50d9f15
commit 1c9837ddf8
8 changed files with 201 additions and 86 deletions

View File

@ -8,6 +8,7 @@ package core
import (
"crypto/rand"
"encoding/hex"
blog "github.com/letsencrypt/boulder/log"
)
func SimpleHTTPSChallenge() Challenge {
@ -20,7 +21,14 @@ func SimpleHTTPSChallenge() Challenge {
func DvsniChallenge() Challenge {
nonce := make([]byte, 16)
_, _ = rand.Read(nonce) // NOTE: Ignoring errors
_, err := rand.Read(nonce)
if err != nil {
audit := blog.GetAuditLogger()
// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
audit.EmergencyExit(err.Error())
}
return Challenge{
Type: ChallengeTypeDVSNI,
Status: StatusPending,

View File

@ -6,6 +6,7 @@
package log
import (
"encoding/json"
"errors"
"fmt"
"log/syslog"
@ -203,11 +204,23 @@ func (log *AuditLogger) Notice(msg string) (err error) {
// Audit sends a NOTICE-severity message that is prefixed with the
// audit tag, for special handling at the upstream system logger.
// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
func (log *AuditLogger) Audit(msg string) (err error) {
return log.auditAtLevel("Logging.Notice", msg)
}
// AuditObject sends a NOTICE-severity JSON-serialized object message that is prefixed
// with the audit tag, for special handling at the upstream system logger.
func (log *AuditLogger) AuditObject(msg string, obj interface{}) (err error) {
jsonLogEvent, logErr := json.Marshal(obj)
if logErr != nil {
// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
log.auditAtLevel("Logging.Err", fmt.Sprintf("%s - logEvent could not be serialized. Raw: %+v", msg, obj))
return logErr
}
return log.auditAtLevel("Logging.Notice", fmt.Sprintf("%s - %s", msg, jsonLogEvent))
}
// AuditErr can format an error for auditing; it does so at ERR level.
// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
func (log *AuditLogger) AuditErr(msg error) (err error) {

View File

@ -139,6 +139,38 @@ func TestPanic(t *testing.T) {
// Can't assert anything here or golint gets angry
}
func TestAuditObject(t *testing.T) {
t.Parallel()
stats, _ := statsd.NewNoopClient(nil)
audit, _ := Dial("", "", "tag", stats)
// Test a simple object
err := audit.AuditObject("Prefix", "String")
test.AssertNotError(t, err, "Simple objects should be serializable")
// Test a system object
err = audit.AuditObject("Prefix", t)
test.AssertNotError(t, err, "System objects should be serializable")
// Test a complex object
type validObj struct {
A string
B string
}
var valid = validObj{A: "B", B: "C"}
err = audit.AuditObject("Prefix", valid)
test.AssertNotError(t, err, "Complex objects should be serializable")
type invalidObj struct {
A chan string
}
var invalid = invalidObj{A: make(chan string)}
err = audit.AuditObject("Prefix", invalid)
test.AssertError(t, err, "Invalid objects should fail serialization")
}
func TestEmergencyExit(t *testing.T) {
t.Parallel()
// Write all logs to UDP on a high port so as to not bother the system

View File

@ -24,7 +24,7 @@ type PolicyAuthorityImpl struct {
func NewPolicyAuthorityImpl() *PolicyAuthorityImpl {
logger := blog.GetAuditLogger()
logger.Notice("Registration Authority Starting")
logger.Notice("Policy Authority Starting")
pa := PolicyAuthorityImpl{log: logger}

View File

@ -7,7 +7,6 @@ package ra
import (
"crypto/x509"
"encoding/json"
"fmt"
"math/big"
"net/url"
@ -49,19 +48,19 @@ func lastPathSegment(url core.AcmeURL) string {
}
type certificateRequestEvent struct {
ID string `json:"omitempty"`
Requester int64 `json:"omitempty"`
SerialNumber *big.Int `json:"omitempty"`
RequestMethod string `json:"omitempty"`
VerificationMethods []string `json:"omitempty"`
VerifiedFields []string `json:"omitempty"`
CommonName string `json:"omitempty"`
Names []string `json:"omitempty"`
NotBefore time.Time `json:"omitempty"`
NotAfter time.Time `json:"omitempty"`
RequestTime time.Time `json:"omitempty"`
ResponseTime time.Time `json:"omitempty"`
Error string `json:"omitempty"`
ID string `json:",omitempty"`
Requester int64 `json:",omitempty"`
SerialNumber *big.Int `json:",omitempty"`
RequestMethod string `json:",omitempty"`
VerificationMethods []string `json:",omitempty"`
VerifiedFields []string `json:",omitempty"`
CommonName string `json:",omitempty"`
Names []string `json:",omitempty"`
NotBefore time.Time `json:",omitempty"`
NotAfter time.Time `json:",omitempty"`
RequestTime time.Time `json:",omitempty"`
ResponseTime time.Time `json:",omitempty"`
Error string `json:",omitempty"`
}
func (ra *RegistrationAuthorityImpl) NewRegistration(init core.Registration, key jose.JsonWebKey) (reg core.Registration, err error) {
@ -140,15 +139,8 @@ func (ra *RegistrationAuthorityImpl) NewCertificate(req core.CertificateRequest,
// No matter what, log the request
defer func() {
jsonLogEvent, logErr := json.Marshal(logEvent)
if logErr != nil {
// AUDIT[ Error Conditions ] 9cc4d537-8534-4970-8665-4b382abe82f3
ra.log.Audit(fmt.Sprintf("Certificate request logEvent could not be serialized. Raw: %+v", logEvent))
return
}
// AUDIT[ Certificate Requests ] 11917fa4-10ef-4e0d-9105-bacbe7836a3c
ra.log.Audit(fmt.Sprintf("Certificate request %s - %s", logEventResult, string(jsonLogEvent)))
ra.log.AuditObject(fmt.Sprintf("Certificate request - %s", logEventResult), logEvent)
}()
if regID <= 0 {

View File

@ -30,21 +30,31 @@ func NewValidationAuthorityImpl(tm bool) ValidationAuthorityImpl {
return ValidationAuthorityImpl{log: logger, TestMode: tm}
}
// Used for audit logging
type verificationRequestEvent struct {
ID string `json:",omitempty"`
Requester int64 `json:",omitempty"`
Challenge core.Challenge `json:",omitempty"`
RequestTime time.Time `json:",omitempty"`
ResponseTime time.Time `json:",omitempty"`
Error string `json:",omitempty"`
}
// Validation methods
func (va ValidationAuthorityImpl) validateSimpleHTTPS(identifier core.AcmeIdentifier, input core.Challenge) core.Challenge {
func (va ValidationAuthorityImpl) validateSimpleHTTPS(identifier core.AcmeIdentifier, input core.Challenge) (core.Challenge, error) {
challenge := input
if len(challenge.Path) == 0 {
challenge.Status = core.StatusInvalid
va.log.Debug("No path provided for SimpleHTTPS challenge.")
return challenge
err := fmt.Errorf("No path provided for SimpleHTTPS challenge.")
return challenge, err
}
if identifier.Type != core.IdentifierDNS {
challenge.Status = core.StatusInvalid
va.log.Debug("Identifier type for SimpleHTTPS was not DNS")
return challenge
err := fmt.Errorf("Identifier type for SimpleHTTPS was not DNS")
return challenge, err
}
hostName := identifier.Value
protocol := "https"
@ -55,12 +65,12 @@ func (va ValidationAuthorityImpl) validateSimpleHTTPS(identifier core.AcmeIdenti
url := fmt.Sprintf("%s://%s/.well-known/acme-challenge/%s", protocol, hostName, challenge.Path)
va.log.Notice(fmt.Sprintf("Attempting to validate SimpleHTTPS for %s %s", hostName, url))
// AUDIT[ Certificate Requests ] 11917fa4-10ef-4e0d-9105-bacbe7836a3c
va.log.Audit(fmt.Sprintf("Attempting to validate SimpleHTTPS for %s", url))
httpRequest, err := http.NewRequest("GET", url, nil)
if err != nil {
va.log.Notice(fmt.Sprintf("Error validating SimpleHTTPS for %s %s: %s", hostName, url, err))
challenge.Status = core.StatusInvalid
return challenge
return challenge, err
}
httpRequest.Host = hostName
@ -81,37 +91,36 @@ func (va ValidationAuthorityImpl) validateSimpleHTTPS(identifier core.AcmeIdenti
if err == nil && httpResponse.StatusCode == 200 {
// Read body & test
body, err := ioutil.ReadAll(httpResponse.Body)
if err != nil {
va.log.Notice(fmt.Sprintf("Error validating SimpleHTTPS for %s %s: %s", hostName, url, err))
body, readErr := ioutil.ReadAll(httpResponse.Body)
if readErr != nil {
challenge.Status = core.StatusInvalid
return challenge
return challenge, readErr
}
if subtle.ConstantTimeCompare(body, []byte(challenge.Token)) == 1 {
challenge.Status = core.StatusValid
} else {
va.log.Notice(fmt.Sprintf("Incorrect token validating SimpleHTTPS for %s %s", hostName, url))
err = fmt.Errorf("Incorrect token validating SimpleHTTPS for %s", url)
challenge.Status = core.StatusInvalid
}
} else if err != nil {
va.log.Notice(fmt.Sprintf("Error validating SimpleHTTPS for %s %s: %s", hostName, url, err))
va.log.Debug(fmt.Sprintf("Could not connect to %s: %s", url, err.Error()))
challenge.Status = core.StatusInvalid
} else {
va.log.Notice(fmt.Sprintf("Error validating SimpleHTTPS for %s %s: %d", hostName, url, httpResponse.StatusCode))
err = fmt.Errorf("Invalid response from %s: %d", url, httpResponse.StatusCode)
challenge.Status = core.StatusInvalid
}
return challenge
return challenge, err
}
func (va ValidationAuthorityImpl) validateDvsni(identifier core.AcmeIdentifier, input core.Challenge) core.Challenge {
func (va ValidationAuthorityImpl) validateDvsni(identifier core.AcmeIdentifier, input core.Challenge) (core.Challenge, error) {
challenge := input
if identifier.Type != "dns" {
va.log.Debug("Identifier type for DVSNI was not DNS")
err := fmt.Errorf("Identifier type for DVSNI was not DNS")
challenge.Status = core.StatusInvalid
return challenge
return challenge, err
}
const DVSNI_SUFFIX = ".acme.invalid"
@ -121,13 +130,13 @@ func (va ValidationAuthorityImpl) validateDvsni(identifier core.AcmeIdentifier,
if err != nil {
va.log.Debug("Failed to decode R value from DVSNI challenge")
challenge.Status = core.StatusInvalid
return challenge
return challenge, err
}
S, err := core.B64dec(challenge.S)
if err != nil {
va.log.Debug("Failed to decode S value from DVSNI challenge")
challenge.Status = core.StatusInvalid
return challenge
return challenge, err
}
RS := append(R, S...)
@ -150,52 +159,70 @@ func (va ValidationAuthorityImpl) validateDvsni(identifier core.AcmeIdentifier,
if err != nil {
va.log.Debug("Failed to connect to host for DVSNI challenge")
challenge.Status = core.StatusInvalid
return challenge
return challenge, err
}
defer conn.Close()
// Check that zName is a dNSName SAN in the server's certificate
certs := conn.ConnectionState().PeerCertificates
if len(certs) == 0 {
va.log.Debug("No certs presented for DVSNI challenge")
err = fmt.Errorf("No certs presented for DVSNI challenge")
challenge.Status = core.StatusInvalid
return challenge
return challenge, err
}
for _, name := range certs[0].DNSNames {
if subtle.ConstantTimeCompare([]byte(name), []byte(zName)) == 1 {
challenge.Status = core.StatusValid
return challenge
return challenge, nil
}
}
va.log.Debug("Correct zName not found for DVSNI challenge")
err = fmt.Errorf("Correct zName not found for DVSNI challenge")
challenge.Status = core.StatusInvalid
return challenge
return challenge, err
}
// Overall validation process
func (va ValidationAuthorityImpl) validate(authz core.Authorization) {
// Select the first supported validation method
// XXX: Remove the "break" lines to process all supported validations
for i, challenge := range authz.Challenges {
if !challenge.IsSane(true) {
va.log.Debug(fmt.Sprintf("Challenge not considered sane: %v", challenge))
challenge.Status = core.StatusInvalid
continue
logEvent := verificationRequestEvent{
ID: authz.ID,
Requester: authz.RegistrationID,
RequestTime: time.Now(),
}
switch challenge.Type {
case core.ChallengeTypeSimpleHTTPS:
authz.Challenges[i] = va.validateSimpleHTTPS(authz.Identifier, challenge)
break
case core.ChallengeTypeDVSNI:
authz.Challenges[i] = va.validateDvsni(authz.Identifier, challenge)
break
if !challenge.IsSane(true) {
challenge.Status = core.StatusInvalid
logEvent.Error = fmt.Sprintf("Challenge failed sanity check.")
logEvent.Challenge = challenge
} else {
var err error
switch challenge.Type {
case core.ChallengeTypeSimpleHTTPS:
authz.Challenges[i], err = va.validateSimpleHTTPS(authz.Identifier, challenge)
break
case core.ChallengeTypeDVSNI:
authz.Challenges[i], err = va.validateDvsni(authz.Identifier, challenge)
break
}
logEvent.Challenge = authz.Challenges[i]
if err != nil {
logEvent.Error = err.Error()
}
}
// AUDIT[ Certificate Requests ] 11917fa4-10ef-4e0d-9105-bacbe7836a3c
va.log.AuditObject("Validation result", logEvent)
}
va.log.Notice(fmt.Sprintf("Validations: %v", authz))
va.log.Notice(fmt.Sprintf("Validations: %+v", authz))
va.RA.OnValidationUpdate(authz)
}

View File

@ -51,14 +51,22 @@ var TheKey rsa.PrivateKey = rsa.PrivateKey{
var ident core.AcmeIdentifier = core.AcmeIdentifier{Type: core.IdentifierType("dns"), Value: "localhost"}
const expectedToken = "THETOKEN"
const pathWrongToken = "wrongtoken"
const path404 = "404"
func simpleSrv(t *testing.T, token string, stopChan, waitChan chan bool) {
http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
if strings.HasSuffix(r.URL.Path, "404") {
if strings.HasSuffix(r.URL.Path, path404) {
t.Logf("SIMPLESRV: Got a 404 req\n")
http.NotFound(w, r)
} else if strings.HasSuffix(r.URL.Path, "wrongtoken") {
} else if strings.HasSuffix(r.URL.Path, pathWrongToken) {
t.Logf("SIMPLESRV: Got a wrongtoken req\n")
fmt.Fprintf(w, "wrongtoken")
} else {
t.Logf("SIMPLESRV: Got a valid req\n")
fmt.Fprintf(w, "%s", token)
}
fmt.Fprintf(w, "%s", token)
})
httpsServer := &http.Server{Addr: "localhost:5001"}
@ -126,33 +134,39 @@ func dvsniSrv(t *testing.T, R, S []byte, waitChan chan bool) {
func TestSimpleHttps(t *testing.T) {
va := NewValidationAuthorityImpl(true)
chall := core.Challenge{Path: "test", Token: "THETOKEN"}
chall := core.Challenge{Path: "test", Token: expectedToken}
invalidChall := va.validateSimpleHTTPS(ident, chall)
invalidChall, err := va.validateSimpleHTTPS(ident, chall)
test.AssertEquals(t, invalidChall.Status, core.StatusInvalid)
test.AssertError(t, err, "Server's not up yet; expected refusal. Where did we connect?")
stopChan := make(chan bool, 1)
waitChan := make(chan bool, 1)
go simpleSrv(t, "THETOKEN", stopChan, waitChan)
go simpleSrv(t, expectedToken, stopChan, waitChan)
finChall := va.validateSimpleHTTPS(ident, chall)
finChall, err := va.validateSimpleHTTPS(ident, chall)
test.AssertEquals(t, finChall.Status, core.StatusValid)
test.AssertNotError(t, err, chall.Path)
chall.Path = "404"
invalidChall = va.validateSimpleHTTPS(ident, chall)
chall.Path = path404
invalidChall, err = va.validateSimpleHTTPS(ident, chall)
test.AssertEquals(t, invalidChall.Status, core.StatusInvalid)
test.AssertError(t, err, "Should have found a 404 for the challenge.")
chall.Path = "wrongtoken"
invalidChall = va.validateSimpleHTTPS(ident, chall)
chall.Path = pathWrongToken
invalidChall, err = va.validateSimpleHTTPS(ident, chall)
test.AssertEquals(t, invalidChall.Status, core.StatusInvalid)
test.AssertError(t, err, "The path should have given us the wrong token.")
chall.Path = ""
invalidChall = va.validateSimpleHTTPS(ident, chall)
invalidChall, err = va.validateSimpleHTTPS(ident, chall)
test.AssertEquals(t, invalidChall.Status, core.StatusInvalid)
test.AssertError(t, err, "Empty paths shouldn't work either.")
chall.Path = "validish"
invalidChall = va.validateSimpleHTTPS(core.AcmeIdentifier{Type: core.IdentifierType("ip"), Value: "127.0.0.1"}, chall)
invalidChall, err = va.validateSimpleHTTPS(core.AcmeIdentifier{Type: core.IdentifierType("ip"), Value: "127.0.0.1"}, chall)
test.AssertEquals(t, invalidChall.Status, core.StatusInvalid)
test.AssertError(t, err, "IdentifierType IP shouldn't have worked.")
stopChan <- true
}
@ -164,27 +178,55 @@ func TestDvsni(t *testing.T) {
ba := core.B64enc(a)
chall := core.Challenge{R: ba, S: ba}
invalidChall := va.validateDvsni(ident, chall)
invalidChall, err := va.validateDvsni(ident, chall)
test.AssertEquals(t, invalidChall.Status, core.StatusInvalid)
test.AssertError(t, err, "Server's not up yet; expected refusal. Where did we connect?")
waitChan := make(chan bool, 1)
go dvsniSrv(t, a, a, waitChan)
<-waitChan
finChall := va.validateDvsni(ident, chall)
finChall, err := va.validateDvsni(ident, chall)
test.AssertEquals(t, finChall.Status, core.StatusValid)
test.AssertNotError(t, err, "")
chall.R = ba[5:]
invalidChall = va.validateDvsni(ident, chall)
invalidChall, err = va.validateDvsni(ident, chall)
test.AssertEquals(t, invalidChall.Status, core.StatusInvalid)
test.AssertError(t, err, "R Should be illegal Base64")
invalidChall = va.validateSimpleHTTPS(core.AcmeIdentifier{Type: core.IdentifierType("ip"), Value: "127.0.0.1"}, chall)
invalidChall, err = va.validateSimpleHTTPS(core.AcmeIdentifier{Type: core.IdentifierType("ip"), Value: "127.0.0.1"}, chall)
test.AssertEquals(t, invalidChall.Status, core.StatusInvalid)
test.AssertError(t, err, "Forgot path; that should be an error.")
chall.R = ba
chall.S = "!@#"
invalidChall = va.validateDvsni(ident, chall)
invalidChall, err = va.validateDvsni(ident, chall)
test.AssertEquals(t, invalidChall.Status, core.StatusInvalid)
test.AssertError(t, err, "S Should be illegal Base64")
}
func TestValidate(t *testing.T) {
va := NewValidationAuthorityImpl(true)
va.RA = &MockRegistrationAuthority{}
challHTTPS := core.SimpleHTTPSChallenge()
challHTTPS.Path = "test"
challDvsni := core.DvsniChallenge()
challDvsni.S = challDvsni.R
var authz = core.Authorization{
ID: core.NewToken(),
RegistrationID: 1,
Identifier: ident,
Challenges: []core.Challenge{challHTTPS, challDvsni},
}
va.validate(authz)
// Disabled per Issue #217.
// for _, c := range(authz.Challenges) {
// test.AssertNotEquals(t, core.StatusInvalid, c.Status)
// }
}
type MockRegistrationAuthority struct{}
@ -193,11 +235,11 @@ func (ra *MockRegistrationAuthority) NewRegistration(reg core.Registration, jwk
return reg, nil
}
func (ra *MockRegistrationAuthority) NewAuthorization(authz core.Authorization, jwk jose.JsonWebKey) (core.Authorization, error) {
func (ra *MockRegistrationAuthority) NewAuthorization(authz core.Authorization, regID int64) (core.Authorization, error) {
return authz, nil
}
func (ra *MockRegistrationAuthority) NewCertificate(req core.CertificateRequest, jwk jose.JsonWebKey) (core.Certificate, error) {
func (ra *MockRegistrationAuthority) NewCertificate(req core.CertificateRequest, regID int64) (core.Certificate, error) {
return core.Certificate{}, nil
}
@ -213,5 +255,6 @@ func (ra *MockRegistrationAuthority) RevokeCertificate(cert x509.Certificate) er
return nil
}
func (ra *MockRegistrationAuthority) OnValidationUpdate(authz core.Authorization) {
func (ra *MockRegistrationAuthority) OnValidationUpdate(authz core.Authorization) error {
return nil
}

View File

@ -268,7 +268,7 @@ func (wfe *WebFrontEndImpl) NewRegistration(response http.ResponseWriter, reques
return
}
regURL := fmt.Sprintf("%s%d", wfe.RegBase, reg.ID)
regURL := fmt.Sprintf("%s%s", wfe.RegBase, string(reg.ID))
responseBody, err := json.Marshal(reg)
if err != nil {
wfe.sendError(response, "Error marshaling authz", err, http.StatusInternalServerError)