Log POST payload in WFE. (#2772)

This allows us to look at logs in more detail.

Also, remove RequestNonce, ResponseNonce, and ClientAddr, which we don't use and
take up log space. And set "Errors" to "omitempty."

Fixes #2747.
This commit is contained in:
Jacob Hoffman-Andrews 2017-05-30 16:32:03 -07:00 committed by Roland Bracewell Shoemaker
parent fbd87b1757
commit dec0912c2c
3 changed files with 33 additions and 21 deletions

View File

@ -13,19 +13,19 @@ import (
) )
type requestEvent struct { type requestEvent struct {
ID string `json:",omitempty"` ID string `json:",omitempty"`
RealIP string `json:",omitempty"` RealIP string `json:",omitempty"`
ClientAddr string `json:",omitempty"` Endpoint string `json:",omitempty"`
Endpoint string `json:",omitempty"` Method string `json:",omitempty"`
Method string `json:",omitempty"` Errors []string `json:",omitempty"`
Errors []string Requester int64 `json:",omitempty"`
Requester int64 `json:",omitempty"` Contacts *[]string `json:",omitempty"`
Contacts *[]string `json:",omitempty"` RequestNonce string `json:",omitempty"`
RequestNonce string `json:",omitempty"` ResponseNonce string `json:",omitempty"`
ResponseNonce string `json:",omitempty"` UserAgent string `json:",omitempty"`
UserAgent string `json:",omitempty"`
Extra map[string]interface{} `json:",omitempty"`
Code int Code int
Payload string `json:",omitempty"`
Extra map[string]interface{} `json:",omitempty"`
} }
func (e *requestEvent) AddError(msg string, args ...interface{}) { func (e *requestEvent) AddError(msg string, args ...interface{}) {
@ -51,12 +51,11 @@ type topHandler struct {
func (th *topHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { func (th *topHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
logEvent := &requestEvent{ logEvent := &requestEvent{
ID: core.NewToken(), ID: core.NewToken(),
RealIP: r.Header.Get("X-Real-IP"), RealIP: r.Header.Get("X-Real-IP"),
ClientAddr: getClientAddr(r), Method: r.Method,
Method: r.Method, UserAgent: r.Header.Get("User-Agent"),
UserAgent: r.Header.Get("User-Agent"), Extra: make(map[string]interface{}, 0),
Extra: make(map[string]interface{}, 0),
} }
w.Header().Set("Boulder-Request-ID", logEvent.ID) w.Header().Set("Boulder-Request-ID", logEvent.ID)
defer th.logEvent(logEvent) defer th.logEvent(logEvent)

View File

@ -552,6 +552,7 @@ func (wfe *WebFrontEndImpl) verifyPOST(ctx context.Context, logEvent *requestEve
logEvent.AddError("verification of JWS with the JWK failed: %v; body: %s", err, body[:n]) logEvent.AddError("verification of JWS with the JWK failed: %v; body: %s", err, body[:n])
return nil, nil, reg, probs.Malformed("JWS verification error") return nil, nil, reg, probs.Malformed("JWS verification error")
} }
logEvent.Payload = string(payload)
// Check that the request has a known anti-replay nonce // Check that the request has a known anti-replay nonce
nonce := parsedJws.Signatures[0].Header.Nonce nonce := parsedJws.Signatures[0].Header.Nonce

View File

@ -1797,11 +1797,9 @@ func TestGetCertificate(t *testing.T) {
t, responseWriter.Header().Get("Link"), t, responseWriter.Header().Get("Link"),
`<https://localhost:4000/acme/issuer-cert>;rel="up"`) `<https://localhost:4000/acme/issuer-cert>;rel="up"`)
t.Logf("UGH %#v", mockLog.GetAll()[0])
reqlogs := mockLog.GetAllMatching(`Successful request`) reqlogs := mockLog.GetAllMatching(`Successful request`)
test.AssertEquals(t, len(reqlogs), 1) test.AssertEquals(t, len(reqlogs), 1)
test.AssertContains(t, reqlogs[0], `INFO: `) test.AssertContains(t, reqlogs[0], `INFO: `)
test.AssertContains(t, reqlogs[0], `"ClientAddr":"192.168.0.1"`)
// Unused serial, no cache // Unused serial, no cache
mockLog.Clear() mockLog.Clear()
@ -1817,7 +1815,6 @@ func TestGetCertificate(t *testing.T) {
reqlogs = mockLog.GetAllMatching(`Terminated request`) reqlogs = mockLog.GetAllMatching(`Terminated request`)
test.AssertEquals(t, len(reqlogs), 1) test.AssertEquals(t, len(reqlogs), 1)
test.AssertContains(t, reqlogs[0], `INFO: `) test.AssertContains(t, reqlogs[0], `INFO: `)
test.AssertContains(t, reqlogs[0], `"ClientAddr":"192.168.99.99,192.168.0.1"`)
// Invalid serial, no cache // Invalid serial, no cache
responseWriter = httptest.NewRecorder() responseWriter = httptest.NewRecorder()
@ -1884,6 +1881,21 @@ type mockSADifferentStoredKey struct {
core.StorageGetter core.StorageGetter
} }
// TestLogPayload ensures that verifyPOST sets the Payload field of the logEvent
// it is passed.
func TestLogPayload(t *testing.T) {
wfe, _ := setupWFE(t)
event := newRequestEvent()
payload := `{"resource":"ima-payload"}`
_, _, _, err := wfe.verifyPOST(ctx, event, makePostRequest(signRequest(t,
payload, wfe.nonceService)), false, "ima-payload")
if err != nil {
t.Fatal(err)
}
test.AssertEquals(t, event.Payload, payload)
}
func (sa mockSADifferentStoredKey) GetRegistrationByKey(ctx context.Context, jwk *jose.JsonWebKey) (core.Registration, error) { func (sa mockSADifferentStoredKey) GetRegistrationByKey(ctx context.Context, jwk *jose.JsonWebKey) (core.Registration, error) {
keyJSON := []byte(test2KeyPublicJSON) keyJSON := []byte(test2KeyPublicJSON)
var parsedKey jose.JsonWebKey var parsedKey jose.JsonWebKey