Log actual remote IP, in addition to X-Forwarded-For header, in request log and csrLog

This commit is contained in:
Tom Clegg 2015-10-05 23:17:47 -07:00
parent 86835575ec
commit 01b40466a4
2 changed files with 62 additions and 41 deletions

View File

@ -113,7 +113,7 @@ func statusCodeFromError(err interface{}) int {
type requestEvent struct {
ID string `json:",omitempty"`
RealIP string `json:",omitempty"`
ForwardedFor string `json:",omitempty"`
ClientAddr string `json:",omitempty"`
Endpoint string `json:",omitempty"`
Method string `json:",omitempty"`
RequestTime time.Time `json:",omitempty"`
@ -730,13 +730,13 @@ func (wfe *WebFrontEndImpl) RevokeCertificate(response http.ResponseWriter, requ
}
}
func (wfe *WebFrontEndImpl) logCsr(remoteAddr string, cr core.CertificateRequest, registration core.Registration) {
func (wfe *WebFrontEndImpl) logCsr(request *http.Request, cr core.CertificateRequest, registration core.Registration) {
var csrLog = struct {
RemoteAddr string
ClientAddr string
CsrBase64 []byte
Registration core.Registration
}{
RemoteAddr: remoteAddr,
ClientAddr: getClientAddr(request),
CsrBase64: cr.Bytes,
Registration: registration,
}
@ -778,7 +778,7 @@ func (wfe *WebFrontEndImpl) NewCertificate(response http.ResponseWriter, request
wfe.sendError(response, "Error unmarshaling certificate request", err, http.StatusBadRequest)
return
}
wfe.logCsr(request.RemoteAddr, certificateRequest, reg)
wfe.logCsr(request, certificateRequest, reg)
// Check that the key in the CSR is good. This will also be checked in the CA
// component, but we want to discard CSRs with bad keys as early as possible
// because (a) it's an easy check and we can save unnecessary requests and
@ -1298,15 +1298,26 @@ func (wfe *WebFrontEndImpl) logRequestDetails(logEvent *requestEvent) {
func (wfe *WebFrontEndImpl) populateRequestEvent(request *http.Request) (logEvent requestEvent) {
logEvent = requestEvent{
ID: core.NewToken(),
RealIP: request.Header.Get("X-Real-IP"),
ForwardedFor: request.Header.Get("X-Forwarded-For"),
Method: request.Method,
RequestTime: time.Now(),
Extra: make(map[string]interface{}, 0),
ID: core.NewToken(),
RealIP: request.Header.Get("X-Real-IP"),
ClientAddr: getClientAddr(request),
Method: request.Method,
RequestTime: time.Now(),
Extra: make(map[string]interface{}, 0),
}
if request.URL != nil {
logEvent.Endpoint = request.URL.String()
}
return
}
// Comma-separated list of HTTP clients involved in making this
// request, starting with the original requestor and ending with the
// remote end of our TCP connection (which is typically our own
// proxy).
func getClientAddr(r *http.Request) string {
if xff := r.Header.Get("X-Forwarded-For"); xff != "" {
return xff + "," + r.RemoteAddr
}
return r.RemoteAddr
}

View File

@ -1235,46 +1235,51 @@ func TestGetCertificate(t *testing.T) {
responseWriter := httptest.NewRecorder()
mockLog := wfe.log.SyslogWriter.(*mocks.MockSyslogWriter)
mockLog.Clear()
// Valid serial, cached
path, _ := url.Parse("/acme/cert/0000000000000000000000000000000000b2")
wfe.Certificate(responseWriter, &http.Request{
Method: "GET",
URL: path,
})
req, _ := http.NewRequest("GET", "/acme/cert/0000000000000000000000000000000000b2", nil)
req.RemoteAddr = "192.168.0.1"
wfe.Certificate(responseWriter, req)
test.AssertEquals(t, responseWriter.Code, 200)
test.AssertEquals(t, responseWriter.Header().Get("Cache-Control"), "public, max-age=10")
test.AssertEquals(t, responseWriter.Header().Get("Content-Type"), "application/pkix-cert")
test.Assert(t, bytes.Compare(responseWriter.Body.Bytes(), certBlock.Bytes) == 0, "Certificates don't match")
reqlogs := mockLog.GetAllMatching(`Successful request`)
test.AssertEquals(t, len(reqlogs), 1)
test.AssertEquals(t, reqlogs[0].Priority, syslog.LOG_INFO)
test.AssertContains(t, reqlogs[0].Message, `"ClientAddr":"192.168.0.1"`)
// Unused serial, no cache
mockLog.Clear()
responseWriter = httptest.NewRecorder()
path, _ = url.Parse("/acme/cert/0000000000000000000000000000000000ff")
wfe.Certificate(responseWriter, &http.Request{
Method: "GET",
URL: path,
})
req, _ = http.NewRequest("GET", "/acme/cert/0000000000000000000000000000000000ff", nil)
req.RemoteAddr = "192.168.0.1"
req.Header.Set("X-Forwarded-For", "192.168.99.99")
wfe.Certificate(responseWriter, req)
test.AssertEquals(t, responseWriter.Code, 404)
test.AssertEquals(t, responseWriter.Header().Get("Cache-Control"), "public, max-age=0, no-cache")
test.AssertEquals(t, responseWriter.Body.String(), `{"type":"urn:acme:error:malformed","detail":"Certificate not found"}`)
reqlogs = mockLog.GetAllMatching(`Terminated request`)
test.AssertEquals(t, len(reqlogs), 1)
test.AssertEquals(t, reqlogs[0].Priority, syslog.LOG_INFO)
test.AssertContains(t, reqlogs[0].Message, `"ClientAddr":"192.168.99.99,192.168.0.1"`)
// Invalid serial, no cache
responseWriter = httptest.NewRecorder()
req, _ = http.NewRequest("GET", "/acme/cert/nothex", nil)
wfe.Certificate(responseWriter, req)
test.AssertEquals(t, responseWriter.Code, 404)
test.AssertEquals(t, responseWriter.Header().Get("Cache-Control"), "public, max-age=0, no-cache")
test.AssertEquals(t, responseWriter.Body.String(), `{"type":"urn:acme:error:malformed","detail":"Certificate not found"}`)
// Invalid serial, no cache
responseWriter = httptest.NewRecorder()
path, _ = url.Parse("/acme/cert/nothex")
wfe.Certificate(responseWriter, &http.Request{
Method: "GET",
URL: path,
})
test.AssertEquals(t, responseWriter.Code, 404)
test.AssertEquals(t, responseWriter.Header().Get("Cache-Control"), "public, max-age=0, no-cache")
test.AssertEquals(t, responseWriter.Body.String(), `{"type":"urn:acme:error:malformed","detail":"Certificate not found"}`)
// Invalid serial, no cache
responseWriter = httptest.NewRecorder()
path, _ = url.Parse("/acme/cert/00000000000000")
wfe.Certificate(responseWriter, &http.Request{
Method: "GET",
URL: path,
})
req, _ = http.NewRequest("GET", "/acme/cert/00000000000000", nil)
wfe.Certificate(responseWriter, req)
test.AssertEquals(t, responseWriter.Code, 404)
test.AssertEquals(t, responseWriter.Header().Get("Cache-Control"), "public, max-age=0, no-cache")
test.AssertEquals(t, responseWriter.Body.String(), `{"type":"urn:acme:error:malformed","detail":"Certificate not found"}`)
@ -1301,16 +1306,21 @@ func TestLogCsrPem(t *testing.T) {
reg, err := mockSA.GetRegistration(789)
test.AssertNotError(t, err, "Unable to get registration")
remoteAddr := "12.34.98.76"
wfe.logCsr(remoteAddr, certificateRequest, reg)
req, err := http.NewRequest("GET", "http://[::1]/", nil)
test.AssertNotError(t, err, "NewRequest failed")
req.RemoteAddr = "12.34.98.76"
req.Header.Set("X-Forwarded-For", "10.0.0.1,172.16.0.1")
mockLog := wfe.log.SyslogWriter.(*mocks.MockSyslogWriter)
mockLog.Clear()
wfe.logCsr(req, certificateRequest, reg)
matches := mockLog.GetAllMatching("Certificate request")
test.Assert(t, len(matches) == 1,
"Incorrect number of certificate request log entries")
test.AssertEquals(t, matches[0].Priority, syslog.LOG_NOTICE)
test.AssertEquals(t, matches[0].Message, `[AUDIT] Certificate request JSON={"RemoteAddr":"12.34.98.76","CsrBase64":"MIICWTCCAUECAQAwFDESMBAGA1UEAwwJbG9jYWxob3N0MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAycX3ca+fViOuRWF38mssORISFxbJvspDfhPGRBZDxJ63NIqQzupB+6dp48xkcX7Z/KDaRJStcpJT2S0u33moNT4FHLklQBETLhExDk66cmlz6Xibp3LGZAwhWuec7wJoEwIgY8oq4rxihIyGq7HVIJoq9DqZGrUgfZMDeEJqbphukQOaXGEop7mD+eeu8+z5EVkB1LiJ6Yej6R8MAhVPHzG5fyOu6YVo6vY6QgwjRLfZHNj5XthxgPIEETZlUbiSoI6J19GYHvLURBTy5Ys54lYAPIGfNwcIBAH4gtH9FrYcDY68R22rp4iuxdvkf03ZWiT0F2W1y7/C9B2jayTzvQIDAQABoAAwDQYJKoZIhvcNAQELBQADggEBAHd6Do9DIZ2hvdt1GwBXYjsqprZidT/DYOMfYcK17KlvdkFT58XrBH88ulLZ72NXEpiFMeTyzfs3XEyGq/Bbe7TBGVYZabUEh+LOskYwhgcOuThVN7tHnH5rhN+gb7cEdysjTb1QL+vOUwYgV75CB6PE5JVYK+cQsMIVvo0Kz4TpNgjJnWzbcH7h0mtvub+fCv92vBPjvYq8gUDLNrok6rbg05tdOJkXsF2G/W+Q6sf2Fvx0bK5JeH4an7P7cXF9VG9nd4sRt5zd+L3IcyvHVKxNhIJXZVH0AOqh/1YrKI9R0QKQiZCEy0xN1okPlcaIVaFhb7IKAHPxTI3r5f72LXY=","Registration":{"id":789,"key":{"kty":"RSA","n":"yNWVhtYEKJR21y9xsHV-PD_bYwbXSeNuFal46xYxVfRL5mqha7vttvjB_vc7Xg2RvgCxHPCqoxgMPTzHrZT75LjCwIW2K_klBYN8oYvTwwmeSkAz6ut7ZxPv-nZaT5TJhGk0NT2kh_zSpdriEJ_3vW-mqxYbbBmpvHqsa1_zx9fSuHYctAZJWzxzUZXykbWMWQZpEiE0J4ajj51fInEzVn7VxV-mzfMyboQjujPh7aNJxAWSq4oQEJJDgWwSh9leyoJoPpONHxh5nEE5AjE01FkGICSxjpZsF-w8hOTI3XXohUdu29Se26k2B0PolDSuj0GIQU6-W9TdLXSjBb2SpQ","e":"AQAB"},"agreement":"http://example.invalid/terms"}}`)
test.AssertEquals(t, matches[0].Message, `[AUDIT] Certificate request JSON={"ClientAddr":"10.0.0.1,172.16.0.1,12.34.98.76","CsrBase64":"MIICWTCCAUECAQAwFDESMBAGA1UEAwwJbG9jYWxob3N0MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAycX3ca+fViOuRWF38mssORISFxbJvspDfhPGRBZDxJ63NIqQzupB+6dp48xkcX7Z/KDaRJStcpJT2S0u33moNT4FHLklQBETLhExDk66cmlz6Xibp3LGZAwhWuec7wJoEwIgY8oq4rxihIyGq7HVIJoq9DqZGrUgfZMDeEJqbphukQOaXGEop7mD+eeu8+z5EVkB1LiJ6Yej6R8MAhVPHzG5fyOu6YVo6vY6QgwjRLfZHNj5XthxgPIEETZlUbiSoI6J19GYHvLURBTy5Ys54lYAPIGfNwcIBAH4gtH9FrYcDY68R22rp4iuxdvkf03ZWiT0F2W1y7/C9B2jayTzvQIDAQABoAAwDQYJKoZIhvcNAQELBQADggEBAHd6Do9DIZ2hvdt1GwBXYjsqprZidT/DYOMfYcK17KlvdkFT58XrBH88ulLZ72NXEpiFMeTyzfs3XEyGq/Bbe7TBGVYZabUEh+LOskYwhgcOuThVN7tHnH5rhN+gb7cEdysjTb1QL+vOUwYgV75CB6PE5JVYK+cQsMIVvo0Kz4TpNgjJnWzbcH7h0mtvub+fCv92vBPjvYq8gUDLNrok6rbg05tdOJkXsF2G/W+Q6sf2Fvx0bK5JeH4an7P7cXF9VG9nd4sRt5zd+L3IcyvHVKxNhIJXZVH0AOqh/1YrKI9R0QKQiZCEy0xN1okPlcaIVaFhb7IKAHPxTI3r5f72LXY=","Registration":{"id":789,"key":{"kty":"RSA","n":"yNWVhtYEKJR21y9xsHV-PD_bYwbXSeNuFal46xYxVfRL5mqha7vttvjB_vc7Xg2RvgCxHPCqoxgMPTzHrZT75LjCwIW2K_klBYN8oYvTwwmeSkAz6ut7ZxPv-nZaT5TJhGk0NT2kh_zSpdriEJ_3vW-mqxYbbBmpvHqsa1_zx9fSuHYctAZJWzxzUZXykbWMWQZpEiE0J4ajj51fInEzVn7VxV-mzfMyboQjujPh7aNJxAWSq4oQEJJDgWwSh9leyoJoPpONHxh5nEE5AjE01FkGICSxjpZsF-w8hOTI3XXohUdu29Se26k2B0PolDSuj0GIQU6-W9TdLXSjBb2SpQ","e":"AQAB"},"agreement":"http://example.invalid/terms"}}`)
}
func TestLengthRequired(t *testing.T) {