Better logging.

Author: jasonish

decoders.go

@@ -58,9 +58,13 @@ type Event struct {
 	SourcePort uint16
 	DestAddr   string
 	DestPort   uint16
+
+	// The original event.
+	Original string
 }
 
 func (e *Event) ToPcapFilter() string {
+
 	return fmt.Sprintf(
 		"proto %s and ((host %s and port %d) and (host %s and port %d))",
 		e.Protocol,
@@ -69,6 +73,7 @@ func (e *Event) ToPcapFilter() string {
 }
 
 func DecodeSnortFastEventTimestamp(buf string) string {
+
 	matches := snortFastTimestampPattern.FindStringSubmatch(buf)
 	if matches == nil {
 		return ""
@@ -85,6 +90,7 @@ func DecodeSnortFastEventTimestamp(buf string) string {
 // DecodeSnortFastEvent will decode Snort and Suricata "fast" style
 // events.
 func DecodeSnortFastEvent(buf string) *Event {
+
 	eventMatches := snortFastEventRegexp.FindStringSubmatch(buf)
 	if eventMatches == nil {
 		if parsers_debug {
@@ -120,11 +126,13 @@ func DecodeSnortFastEvent(buf string) *Event {
 		SourcePort: (uint16)(sourcePort),
 		DestAddr:   eventMatches[4],
 		DestPort:   (uint16)(destPort),
+		Original:   buf,
 	}
 }
 
 // DecodeSuricataJsonEvent decodes a Suricata style JSON event.
 func DecodeSuricataJsonEvent(buf string) *Event {
+
 	suricataJsonEvent := SuricataJsonEvent{}
 
 	if err := json.Unmarshal(([]byte)(buf), &suricataJsonEvent); err != nil {
@@ -134,15 +142,14 @@ func DecodeSuricataJsonEvent(buf string) *Event {
 		return nil
 	}
 
-	log.Println(suricataJsonEvent)
-
 	return &Event{
 		Timestamp:  suricataJsonEvent.Timestamp,
 		Protocol:   suricataJsonEvent.Protocol,
 		SourceAddr: suricataJsonEvent.SourceAddr,
 		SourcePort: suricataJsonEvent.SourcePort,
 		DestAddr:   suricataJsonEvent.DestAddr,
 		DestPort:   suricataJsonEvent.DestPort,
+		Original:   buf,
 	}
 }
 
@@ -153,5 +160,5 @@ func DecodeEvent(buf string) (*Event, error) {
 	if event := DecodeSnortFastEvent(buf); event != nil {
 		return event, nil
 	}
-	return nil, fmt.Errorf("unable to decode event")
+	return nil, fmt.Errorf("error: event not recognized by any decoders")
 }

dumper.go dumper/dumper.godumper.go renamed to dumper/dumper.go

@@ -24,7 +24,7 @@
 // ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED
 // OF THE POSSIBILITY OF SUCH DAMAGE.
 
-package main
+package dumper
 
 import (
 	"flag"
@@ -37,6 +37,8 @@ import (
 	"dumpy/libpcap"
 )
 
+var verbose bool = false
+
 func getStartSeconds(filename string) (int64, error) {
 	var seconds int64
 	pcap, err := libpcap.OpenOffline(filename)
@@ -117,6 +119,7 @@ func DumperMain(args []string) {
 		"start time in unix time (seconds)")
 	flagset.Int64Var(&duration, "duration", 0, "duration of capture (seconds)")
 	flagset.StringVar(&filter, "filter", "", "bpf filter expression")
+	flagset.BoolVar(&verbose, "verbose", false, "be more verbose")
 	flagset.Parse(args)
 
 	if directory == "" || prefix == "" {
@@ -135,7 +138,9 @@ func DumperMain(args []string) {
 	var dumper *libpcap.Dumper
 
 	for _, file := range files {
-		log.Printf("opening file %s", file.Name())
+		if verbose {
+			log.Printf("opening file %s", file.Name())
+		}
 		pcap, err := libpcap.OpenOffline(path.Join(directory, file.Name()))
 		if err != nil {
 			log.Fatal(err)

logger.go

@@ -0,0 +1,67 @@
+// Copyright (c) 2014 Jason Ish. All rights reserved.
+//
+// Redistribution and use in source and binary forms, with or without
+// modification, are permitted provided that the following conditions
+// are met:
+//
+// 1. Redistributions of source code must retain the above copyright
+//    notice, this list of conditions and the following disclaimer.
+//
+// 2. Redistributions in binary form must reproduce the above
+//    copyright notice, this list of conditions and the following
+//    disclaimer in the documentation and/or other materials provided
+//    with the distribution.
+//
+// THIS SOFTWARE IS PROVIDED ``AS IS'' AND ANY EXPRESS OR IMPLIED
+// WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
+// OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
+// DISCLAIMED. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR ANY DIRECT,
+// INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES
+// (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR
+// SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
+// HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT,
+// STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
+// ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED
+// OF THE POSSIBILITY OF SUCH DAMAGE.
+
+package main
+
+import (
+	"fmt"
+	"log"
+	"net/http"
+	"os"
+	"strings"
+
+	"github.com/gorilla/context"
+)
+
+// Logger is a wrapper around the standard logger that implements some
+// http.Request aware functions.
+type Logger struct {
+	*log.Logger
+}
+
+func NewLogger(prefix string) *Logger {
+	return &Logger{log.New(os.Stderr, prefix, log.Ldate|log.Ltime)}
+}
+
+func (l *Logger) PrintfWithRequest(r *http.Request, format string, v ...interface{}) {
+	l.Printf("[%s@%s] %s",
+		context.Get(r, "username"),
+		l.getRemoteAddr(r),
+		fmt.Sprintf(format, v...))
+}
+
+func (l *Logger) PrintWithRequest(r *http.Request, v ...interface{}) {
+	l.Printf("[%s@%s] %s",
+		context.Get(r, "username"),
+		l.getRemoteAddr(r),
+		fmt.Sprint(v...))
+}
+
+// getRemoteAddr gets the remote address of the request without the
+// port information.
+func (l *Logger) getRemoteAddr(r *http.Request) string {
+	return strings.Split(r.RemoteAddr, ":")[0]
+}

main.go

@@ -27,11 +27,15 @@
 package main
 
 import (
+	"dumpy/dumper"
 	"flag"
 	"fmt"
 	"os"
 )
 
+// Global logger.
+var logger = NewLogger("")
+
 func Usage() {
 	fmt.Printf(`
 Usage: dumpy [options] <command>
@@ -64,7 +68,7 @@ func main() {
 		case "version":
 			fmt.Println(VERSION)
 		case "dump":
-			DumperMain(os.Args[2:])
+			dumper.DumperMain(os.Args[2:])
 		case "config":
 			ConfigMain(NewConfig(configFilename), os.Args[2:])
 		case "start":

web-authenticator.go

@@ -31,6 +31,7 @@ import (
 	"log"
 	"net/http"
 	"strings"
+	"github.com/gorilla/context"
 
 	"code.google.com/p/go.crypto/bcrypt"
 )
@@ -54,6 +55,13 @@ type Authenticator struct {
 	users map[string]string
 }
 
+func NewAuthenticator(config *Config) *Authenticator {
+	if len(config.Users) == 0 {
+		logger.Printf("WARNING: No users configuration. Authentication disabled.")
+	}
+	return &Authenticator{config.Users}
+}
+
 func (a *Authenticator) GetUsernameAndPassword(authHeader string) (string, string) {
 	parts := strings.SplitN(authHeader, " ", 2)
 	if len(parts) == 2 {
@@ -85,11 +93,16 @@ func (a *Authenticator) CheckUsernameAndPassword(username string, password strin
 }
 
 func (a *Authenticator) authenticate(request *http.Request) bool {
+	if len(a.users) == 0 {
+		context.Set(request, "username", "<anonymous>")
+		return true
+	}
 	authHeader := request.Header.Get("authorization")
 	if authHeader != "" {
 		username, password := a.GetUsernameAndPassword(authHeader)
 		if username != "" {
 			if a.CheckUsernameAndPassword(username, password) {
+				context.Set(request, "username", username)
 				return true
 			}
 		}

web-fetch-handler.go

@@ -29,7 +29,7 @@ package main
 import (
 	"bufio"
 	"fmt"
-	"log"
+	"io"
 	"net/http"
 	"os"
 	"os/exec"
@@ -66,20 +66,26 @@ type FetchHandler struct {
 }
 
 func (h *FetchHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
-	if r.FormValue("event") != "" {
-		h.HandleEventRequest(w, r)
-	} else if r.FormValue("filter") != "" {
+
+	queryType := r.FormValue("query-type")
+
+	switch queryType {
+	case "pcap-filter":
 		h.HandleFilterRequest(w, r)
-	} else {
-		http.Error(w, "Missing fetch request type (filter or event)",
-			http.StatusBadRequest)
+	case "event":
+		h.HandleEventRequest(w, r)
+	case "":
+		HttpErrorAndLog(w, r, http.StatusBadRequest,
+			"Missing query-type parameter.")
+	default:
+		HttpErrorAndLog(w, r, http.StatusBadRequest,
+			"Unknown query-type: %s", queryType)
 	}
 }
 
 func (h *FetchHandler) HandleFilterRequest(w http.ResponseWriter, r *http.Request) {
 
 	filter := r.FormValue("filter")
-
 	argStartTime := r.FormValue("start-time")
 	argDuration := r.FormValue("duration")
 	argSpool := r.FormValue("spool")
@@ -115,6 +121,13 @@ func (h *FetchHandler) HandleFilterRequest(w http.ResponseWriter, r *http.Reques
 		return
 	}
 
+	logger.PrintfWithRequest(r, "Preparing dumper request: %s",
+		map[string]string{
+			"start-time":  startTime.String(),
+			"duration":    duration.String(),
+			"pcap-filter": filter,
+		})
+
 	dumperArgs := []string{
 		"-directory", spool.Directory,
 		"-prefix", spool.Prefix,
@@ -127,9 +140,9 @@ func (h *FetchHandler) HandleFilterRequest(w http.ResponseWriter, r *http.Reques
 
 func (h *FetchHandler) HandleEventRequest(w http.ResponseWriter, r *http.Request) {
 
-	event, _ := DecodeEvent(r.FormValue("event"))
-	if event == nil {
-		http.Error(w, "failed to decode event", http.StatusBadRequest)
+	event, err := DecodeEvent(r.FormValue("event"))
+	if err != nil {
+		HttpErrorAndLog(w, r, http.StatusBadRequest, err.Error())
 		return
 	}
 
@@ -168,6 +181,14 @@ func (h *FetchHandler) HandleEventRequest(w http.ResponseWriter, r *http.Request
 		return
 	}
 
+	logger.PrintfWithRequest(r, "Preparing dumper request: %s",
+		map[string]string{
+			"start-time":  startTime.String(),
+			"duration":    duration.String(),
+			"pcap-filter": event.ToPcapFilter(),
+			"event":       event.Original,
+		})
+
 	dumperArgs := []string{
 		"-directory", spool.Directory,
 		"-prefix", spool.Prefix,
@@ -204,23 +225,27 @@ func (h *FetchHandler) RunDumper(w http.ResponseWriter, r *http.Request, args []
 			if err != nil {
 				break
 			}
-			log.Printf("dumpy dumper (stderr): %s", line)
+			logger.Printf("dumpy dumper [%d] (stderr) %s", dumper.Process.Pid, line)
 		}
 	}()
 
 	err = dumper.Start()
 	if err != nil {
-		http.Error(w, "failed to execute dumper: "+err.Error(),
-			http.StatusInternalServerError)
+		HttpErrorAndLog(w, r, http.StatusInternalServerError,
+			"failed to execute dumper: %s", err)
 		return
 	}
+	logger.PrintfWithRequest(r, "dumper with pid %d started: %s",
+		dumper.Process.Pid, dumper.Args)
 
 	bytesWritten := 0
 	for {
 		buf := make([]byte, 8192)
 		n, err := stdout.Read(buf)
 		if err != nil {
-			log.Print(err)
+			if err != io.EOF {
+				logger.PrintfWithRequest(r, "unexpected dump error: %s", err)
+			}
 			break
 		}
 
@@ -231,13 +256,17 @@ func (h *FetchHandler) RunDumper(w http.ResponseWriter, r *http.Request, args []
 		}
 		n, err = w.Write(buf[0:n])
 		if err != nil {
-			log.Printf("write to client failed: %s", err)
+			logger.PrintfWithRequest(r,
+				"Write failed; client may have disconnected: %s", err)
 			break
 		}
 		bytesWritten += n
 	}
 
 	if bytesWritten == 0 {
 		http.Error(w, "No packets found.", http.StatusNotFound)
+	} else {
+		logger.PrintfWithRequest(r, "Wrote %d bytes of packet data",
+			bytesWritten)
 	}
 }