Response time logging and filtering (#433)

* Added response time reporting and filtering

* Update to use the http config context

* Added changelog and contributor info

* Round time output in stdout to nearest millisecond

* Change stdout duration rounding to use Milliseconds()

* Go back to Round() for timing output

* Changed stdout to display millisecond durations

Co-authored-by: Joona Hoikkala <joohoi@users.noreply.github.com>

CHANGELOG.md

@@ -1,7 +1,9 @@
 ## Changelog
 - master
   - New
+    - Added response time logging and filtering
     - Added a CLI flag to specify TLS SNI value
+
   - Changed
     - Fixed an issue where output file was created regardless of `-or`
     - Fixed an issue where output (often a lot of it) would be printed after entering interactive mode

CONTRIBUTORS.md

@@ -10,6 +10,7 @@
 * [Damian89](https://github.com/Damian89)
 * [Daviey](https://github.com/Daviey)
 * [delic](https://github.com/delic)
+* [denandz](https://github.com/denandz)
 * [erbbysam](https://github.com/erbbysam)
 * [eur0pa](https://github.com/eur0pa)
 * [fabiobauer](https://github.com/fabiobauer)

README.md

@@ -199,6 +199,7 @@ MATCHER OPTIONS:
   -ml                 Match amount of lines in response
   -mr                 Match regexp
   -ms                 Match HTTP response size
+  -mt                 Match how many milliseconds to the first response byte, either greater or less than. EG: >100 or <100
   -mw                 Match amount of words in response
 
 FILTER OPTIONS:
@@ -206,6 +207,7 @@ FILTER OPTIONS:
   -fl                 Filter by amount of lines in response. Comma separated list of line counts and ranges
   -fr                 Filter regexp
   -fs                 Filter HTTP response size. Comma separated list of sizes and ranges
+  -ft                 Filter by number of milliseconds to the first response byte, either greater or less than. EG: >100 or <100
   -fw                 Filter by amount of words in response. Comma separated list of word counts and ranges
 
 INPUT OPTIONS:

ffufrc.example

@@ -69,6 +69,7 @@
     regexp = ""
     size = ""
     status = ""
+    time = ""
     words = ""
 
 [matcher]
@@ -76,4 +77,5 @@
     regexp = ""
     size = ""
     status = "200,204,301,302,307,401,403,405"
+    time = ""
     words = ""

help.go

@@ -75,14 +75,14 @@ func Usage() {
 		Description:   "Matchers for the response filtering.",
 		Flags:         make([]UsageFlag, 0),
 		Hidden:        false,
-		ExpectedFlags: []string{"mc", "ml", "mr", "ms", "mw"},
+		ExpectedFlags: []string{"mc", "ml", "mr", "ms", "mt", "mw"},
 	}
 	u_filter := UsageSection{
 		Name:          "FILTER OPTIONS",
 		Description:   "Filters for the response filtering.",
 		Flags:         make([]UsageFlag, 0),
 		Hidden:        false,
-		ExpectedFlags: []string{"fc", "fl", "fr", "fs", "fw"},
+		ExpectedFlags: []string{"fc", "fl", "fr", "fs", "ft", "fw"},
 	}
 	u_input := UsageSection{
 		Name:          "INPUT OPTIONS",

main.go

@@ -86,6 +86,7 @@ func ParseFlags(opts *ffuf.ConfigOptions) *ffuf.ConfigOptions {
 	flag.StringVar(&opts.Filter.Regexp, "fr", opts.Filter.Regexp, "Filter regexp")
 	flag.StringVar(&opts.Filter.Size, "fs", opts.Filter.Size, "Filter HTTP response size. Comma separated list of sizes and ranges")
 	flag.StringVar(&opts.Filter.Status, "fc", opts.Filter.Status, "Filter HTTP status codes from response. Comma separated list of codes and ranges")
+	flag.StringVar(&opts.Filter.Time, "ft", opts.Filter.Time, "Filter by number of milliseconds to the first response byte, either greater or less than. EG: >100 or <100")
 	flag.StringVar(&opts.Filter.Words, "fw", opts.Filter.Words, "Filter by amount of words in response. Comma separated list of word counts and ranges")
 	flag.StringVar(&opts.General.Delay, "p", opts.General.Delay, "Seconds of `delay` between requests, or a range of random delay. For example \"0.1\" or \"0.1-2.0\"")
 	flag.StringVar(&opts.HTTP.Data, "d", opts.HTTP.Data, "POST data")
@@ -107,6 +108,7 @@ func ParseFlags(opts *ffuf.ConfigOptions) *ffuf.ConfigOptions {
 	flag.StringVar(&opts.Matcher.Regexp, "mr", opts.Matcher.Regexp, "Match regexp")
 	flag.StringVar(&opts.Matcher.Size, "ms", opts.Matcher.Size, "Match HTTP response size")
 	flag.StringVar(&opts.Matcher.Status, "mc", opts.Matcher.Status, "Match HTTP status codes, or \"all\" for everything.")
+	flag.StringVar(&opts.Matcher.Time, "mt", opts.Matcher.Time, "Match how many milliseconds to the first response byte, either greater or less than. EG: >100 or <100")
 	flag.StringVar(&opts.Matcher.Words, "mw", opts.Matcher.Words, "Match amount of words in response")
 	flag.StringVar(&opts.Output.DebugLog, "debug-log", opts.Output.DebugLog, "Write all of the internal logging to the specified file.")
 	flag.StringVar(&opts.Output.OutputDirectory, "od", opts.Output.OutputDirectory, "Directory path to store matched results to.")

pkg/ffuf/interfaces.go

@@ -1,5 +1,7 @@
 package ffuf
 
+import "time"
+
 //FilterProvider is a generic interface for both Matchers and Filters
 type FilterProvider interface {
 	Filter(response *Response) (bool, error)
@@ -62,6 +64,7 @@ type Result struct {
 	ContentType      string            `json:"content-type"`
 	RedirectLocation string            `json:"redirectlocation"`
 	Url              string            `json:"url"`
+	Duration         time.Duration     `json:"duration"`
 	ResultFile       string            `json:"resultfile"`
 	Host             string            `json:"host"`
 	HTMLColor        string            `json:"-"`

pkg/ffuf/optionsparser.go

@@ -87,6 +87,7 @@ type FilterOptions struct {
 	Regexp string
 	Size   string
 	Status string
+	Time   string
 	Words  string
 }
 
@@ -95,6 +96,7 @@ type MatcherOptions struct {
 	Regexp string
 	Size   string
 	Status string
+	Time   string
 	Words  string
 }
 
@@ -105,6 +107,7 @@ func NewConfigOptions() *ConfigOptions {
 	c.Filter.Regexp = ""
 	c.Filter.Size = ""
 	c.Filter.Status = ""
+	c.Filter.Time = ""
 	c.Filter.Words = ""
 	c.General.AutoCalibration = false
 	c.General.Colors = false
@@ -143,6 +146,7 @@ func NewConfigOptions() *ConfigOptions {
 	c.Matcher.Regexp = ""
 	c.Matcher.Size = ""
 	c.Matcher.Status = "200,204,301,302,307,401,403,405"
+	c.Matcher.Time = ""
 	c.Matcher.Words = ""
 	c.Output.DebugLog = ""
 	c.Output.OutputDirectory = ""

pkg/ffuf/response.go

@@ -3,6 +3,7 @@ package ffuf
 import (
 	"net/http"
 	"net/url"
+	"time"
 )
 
 // Response struct holds the meaningful data returned from request and is meant for passing to filters
@@ -18,6 +19,7 @@ type Response struct {
 	Request       *Request
 	Raw           string
 	ResultFile    string
+	Time          time.Duration
 }
 
 // GetRedirectLocation returns the redirect location for a 3xx redirect HTTP response

pkg/filter/filter.go

@@ -25,6 +25,9 @@ func NewFilterByName(name string, value string) (ffuf.FilterProvider, error) {
 	if name == "regexp" {
 		return NewRegexpFilter(value)
 	}
+	if name == "time" {
+		return NewTimeFilter(value)
+	}
 	return nil, fmt.Errorf("Could not create filter with name %s", name)
 }
 
@@ -143,6 +146,9 @@ func SetupFilters(parseOpts *ffuf.ConfigOptions, conf *ffuf.Config) error {
 		if f.Name == "mr" {
 			matcherSet = true
 		}
+		if f.Name == "mt" {
+			matcherSet = true
+		}
 		if f.Name == "mw" {
 			matcherSet = true
 			warningIgnoreBody = true
@@ -182,6 +188,11 @@ func SetupFilters(parseOpts *ffuf.ConfigOptions, conf *ffuf.Config) error {
 			errs.Add(err)
 		}
 	}
+	if parseOpts.Filter.Time != "" {
+		if err := AddFilter(conf, "time", parseOpts.Filter.Time); err != nil {
+			errs.Add(err)
+		}
+	}
 	if parseOpts.Matcher.Size != "" {
 		if err := AddMatcher(conf, "size", parseOpts.Matcher.Size); err != nil {
 			errs.Add(err)
@@ -202,6 +213,11 @@ func SetupFilters(parseOpts *ffuf.ConfigOptions, conf *ffuf.Config) error {
 			errs.Add(err)
 		}
 	}
+	if parseOpts.Matcher.Time != "" {
+		if err := AddFilter(conf, "time", parseOpts.Matcher.Time); err != nil {
+			errs.Add(err)
+		}
+	}
 	if conf.IgnoreBody && warningIgnoreBody {
 		fmt.Printf("*** Warning: possible undesired combination of -ignore-body and the response options: fl,fs,fw,ml,ms and mw.\n")
 	}

pkg/filter/filter_test.go

@@ -29,6 +29,11 @@ func TestNewFilterByName(t *testing.T) {
 	if _, ok := ref.(*RegexpFilter); !ok {
 		t.Errorf("Was expecting regexpfilter")
 	}
+
+	tf, _ := NewFilterByName("time", "200")
+	if _, ok := tf.(*TimeFilter); !ok {
+		t.Errorf("Was expecting timefilter")
+	}
 }
 
 func TestNewFilterByNameError(t *testing.T) {

pkg/filter/time.go

@@ -0,0 +1,66 @@
+package filter
+
+import (
+	"encoding/json"
+	"fmt"
+	"strconv"
+	"strings"
+
+	"github.com/ffuf/ffuf/pkg/ffuf"
+)
+
+type TimeFilter struct {
+	ms       int64 // milliseconds since first response byte
+	gt       bool  // filter if response time is greater than
+	lt       bool  // filter if response time is less than
+	valueRaw string
+}
+
+func NewTimeFilter(value string) (ffuf.FilterProvider, error) {
+	var milliseconds int64
+	gt, lt := false, false
+
+	gt = strings.HasPrefix(value, ">")
+	lt = strings.HasPrefix(value, "<")
+
+	if (!lt && !gt) || (lt && gt) {
+		return &TimeFilter{}, fmt.Errorf("Time filter or matcher (-ft / -mt): invalid value: %s", value)
+	}
+
+	milliseconds, err := strconv.ParseInt(value[1:], 10, 64)
+	if err != nil {
+		return &TimeFilter{}, fmt.Errorf("Time filter or matcher (-ft / -mt): invalid value: %s", value)
+	}
+	return &TimeFilter{ms: milliseconds, gt: gt, lt: lt, valueRaw: value}, nil
+}
+
+func (f *TimeFilter) MarshalJSON() ([]byte, error) {
+	return json.Marshal(&struct {
+		Value string `json:"value"`
+	}{
+		Value: f.valueRaw,
+	})
+}
+
+func (f *TimeFilter) Filter(response *ffuf.Response) (bool, error) {
+	if f.gt {
+		if response.Time.Milliseconds() > f.ms {
+			return true, nil
+		}
+
+	} else if f.lt {
+		if response.Time.Milliseconds() < f.ms {
+			return true, nil
+		}
+	}
+
+	return false, nil
+}
+
+func (f *TimeFilter) Repr() string {
+	return f.valueRaw
+}
+
+func (f *TimeFilter) ReprVerbose() string {
+	return fmt.Sprintf("Response time: %s", f.Repr())
+}

pkg/filter/time_test.go

@@ -0,0 +1,54 @@
+package filter
+
+import (
+	"testing"
+	"time"
+
+	"github.com/ffuf/ffuf/pkg/ffuf"
+)
+
+func TestNewTimeFilter(t *testing.T) {
+	fp, _ := NewTimeFilter(">100")
+
+	f := fp.(*TimeFilter)
+
+	if !f.gt || f.lt {
+		t.Errorf("Time filter was expected to have greater-than")
+	}
+
+	if f.ms != 100 {
+		t.Errorf("Time filter was expected to have ms == 100")
+	}
+}
+
+func TestNewTimeFilterError(t *testing.T) {
+	_, err := NewTimeFilter("100>")
+	if err == nil {
+		t.Errorf("Was expecting an error from errenous input data")
+	}
+}
+
+func TestTimeFiltering(t *testing.T) {
+	f, _ := NewTimeFilter(">100")
+
+	for i, test := range []struct {
+		input  int64
+		output bool
+	}{
+		{1342, true},
+		{2000, true},
+		{35000, true},
+		{1458700, true},
+		{99, false},
+		{2, false},
+	} {
+		resp := ffuf.Response{
+			Data: []byte("dahhhhhtaaaaa"),
+			Time: time.Duration(test.input * int64(time.Millisecond)),
+		}
+		filterReturn, _ := f.Filter(&resp)
+		if filterReturn != test.output {
+			t.Errorf("Filter test %d: Was expecing filter return value of %t but got %t", i, test.output, filterReturn)
+		}
+	}
+}

pkg/interactive/termhandler.go

@@ -3,11 +3,12 @@ package interactive
 import (
 	"bufio"
 	"fmt"
-	"github.com/ffuf/ffuf/pkg/ffuf"
-	"github.com/ffuf/ffuf/pkg/filter"
 	"strconv"
 	"strings"
 	"time"
+
+	"github.com/ffuf/ffuf/pkg/ffuf"
+	"github.com/ffuf/ffuf/pkg/filter"
 )
 
 type interactive struct {
@@ -110,6 +111,15 @@ func (i *interactive) handleInput(in []byte) {
 				i.updateFilter("size", args[1])
 				i.Job.Output.Info("New response size filter value set")
 			}
+		case "ft":
+			if len(args) < 2 {
+				i.Job.Output.Error("Please define a value for response time filter, or \"none\" for removing it")
+			} else if len(args) > 2 {
+				i.Job.Output.Error("Too many arguments for \"ft\"")
+			} else {
+				i.updateFilter("time", args[1])
+				i.Job.Output.Info("New response time filter value set")
+			}
 		case "queueshow":
 			i.printQueue()
 		case "queuedel":
@@ -205,7 +215,7 @@ func (i *interactive) printPrompt() {
 }
 
 func (i *interactive) printHelp() {
-	var fc, fl, fs, fw string
+	var fc, fl, fs, ft, fw string
 	for name, filter := range i.Job.Config.Filters {
 		switch name {
 		case "status":
@@ -216,6 +226,8 @@ func (i *interactive) printHelp() {
 			fw = "(active: " + filter.Repr() + ")"
 		case "size":
 			fs = "(active: " + filter.Repr() + ")"
+		case "time":
+			ft = "(active: " + filter.Repr() + ")"
 		}
 	}
 	help := `
@@ -224,6 +236,7 @@ available commands:
  fl [value]             - (re)configure line count filter %s
  fw [value]             - (re)configure word count filter %s
  fs [value]             - (re)configure size filter %s
+ ft [value]				- (re)configure time filter %s
  queueshow              - show recursive job queue
  queuedel [number]      - delete a recursion job in the queue
  queueskip              - advance to the next queued recursion job
@@ -233,5 +246,5 @@ available commands:
  savejson [filename]    - save current matches to a file
  help                   - you are looking at it
 `
-	i.Job.Output.Raw(fmt.Sprintf(help, fc, fl, fw, fs))
+	i.Job.Output.Raw(fmt.Sprintf(help, fc, fl, fw, fs, ft))
 }

pkg/output/file_csv.go

@@ -9,7 +9,7 @@ import (
 	"github.com/ffuf/ffuf/pkg/ffuf"
 )
 
-var staticheaders = []string{"url", "redirectlocation", "position", "status_code", "content_length", "content_words", "content_lines", "content_type", "resultfile"}
+var staticheaders = []string{"url", "redirectlocation", "position", "status_code", "content_length", "content_words", "content_lines", "content_type", "duration", "resultfile"}
 
 func writeCSV(filename string, config *ffuf.Config, res []ffuf.Result, encode bool) error {
 	header := make([]string, 0)
@@ -64,6 +64,7 @@ func toCSV(r ffuf.Result) []string {
 	res = append(res, strconv.FormatInt(r.ContentWords, 10))
 	res = append(res, strconv.FormatInt(r.ContentLines, 10))
 	res = append(res, r.ContentType)
+	res = append(res, r.Duration.String())
 	res = append(res, r.ResultFile)
 	return res
 }

pkg/output/file_html.go

@@ -78,6 +78,7 @@ const (
               <th>Words</th>
 			  <th>Lines</th>
 			  <th>Type</th>
+        <th>Duration</th>
 			  <th>Resultfile</th>
           </tr>
         </thead>
@@ -99,6 +100,7 @@ const (
                     <td>{{ $result.ContentWords }}</td>
 					<td>{{ $result.ContentLines }}</td>
 					<td>{{ $result.ContentType }}</td>
+          <td>{{ $result.Duration }}</td>
                     <td>{{ $result.ResultFile }}</td>
                 </tr>
             {{ end }}

pkg/output/file_json.go

@@ -24,6 +24,7 @@ type JsonResult struct {
 	ContentLines     int64             `json:"lines"`
 	ContentType      string            `json:"content-type"`
 	RedirectLocation string            `json:"redirectlocation"`
+	Duration         time.Duration     `json:"duration"`
 	ResultFile       string            `json:"resultfile"`
 	Url              string            `json:"url"`
 	Host             string            `json:"host"`
@@ -72,6 +73,7 @@ func writeJSON(filename string, config *ffuf.Config, res []ffuf.Result) error {
 			ContentLines:     r.ContentLines,
 			ContentType:      r.ContentType,
 			RedirectLocation: r.RedirectLocation,
+			Duration:         r.Duration,
 			ResultFile:       r.ResultFile,
 			Url:              r.Url,
 			Host:             r.Host,

pkg/output/file_md.go

@@ -14,9 +14,9 @@ const (
   Command line : ` + "`{{.CommandLine}}`" + `
   Time: ` + "{{ .Time }}" + `
 
-  {{ range .Keys }}| {{ . }} {{ end }}| URL | Redirectlocation | Position | Status Code | Content Length | Content Words | Content Lines | Content Type | ResultFile |
+  {{ range .Keys }}| {{ . }} {{ end }}| URL | Redirectlocation | Position | Status Code | Content Length | Content Words | Content Lines | Content Type | Duration | ResultFile |
   {{ range .Keys }}| :- {{ end }}| :-- | :--------------- | :---- | :------- | :---------- | :------------- | :------------ | :--------- | :----------- |
-  {{range .Results}}{{ range $keyword, $value := .Input }}| {{ $value | printf "%s" }} {{ end }}| {{ .Url }} | {{ .RedirectLocation }} | {{ .Position }} | {{ .StatusCode }} | {{ .ContentLength }} | {{ .ContentWords }} | {{ .ContentLines }} | {{ .ContentType }} | {{ .ResultFile }} |
+  {{range .Results}}{{ range $keyword, $value := .Input }}| {{ $value | printf "%s" }} {{ end }}| {{ .Url }} | {{ .RedirectLocation }} | {{ .Position }} | {{ .StatusCode }} | {{ .ContentLength }} | {{ .ContentWords }} | {{ .ContentLines }} | {{ .ContentType }} | {{ .Duration}} | {{ .ResultFile }} |
   {{end}}` // The template format is not pretty but follows the markdown guide
 )
 

pkg/output/stdout.go

@@ -324,6 +324,7 @@ func (s *Stdoutput) Result(resp ffuf.Response) {
 		ContentType:      resp.ContentType,
 		RedirectLocation: resp.GetRedirectLocation(false),
 		Url:              resp.Request.Url,
+		Duration:         resp.Time,
 		ResultFile:       resp.ResultFile,
 		Host:             resp.Request.Host,
 	}
@@ -401,7 +402,7 @@ func (s *Stdoutput) resultQuiet(res ffuf.Result) {
 func (s *Stdoutput) resultMultiline(res ffuf.Result) {
 	var res_hdr, res_str string
 	res_str = "%s%s    * %s: %s\n"
-	res_hdr = fmt.Sprintf("%s[Status: %d, Size: %d, Words: %d, Lines: %d]", TERMINAL_CLEAR_LINE, res.StatusCode, res.ContentLength, res.ContentWords, res.ContentLines)
+	res_hdr = fmt.Sprintf("%s[Status: %d, Size: %d, Words: %d, Lines: %d, Duration: %dms]", TERMINAL_CLEAR_LINE, res.StatusCode, res.ContentLength, res.ContentWords, res.ContentLines, res.Duration.Milliseconds())
 	res_hdr = s.colorize(res_hdr, res.StatusCode)
 	reslines := ""
 	if s.config.Verbose {
@@ -427,7 +428,7 @@ func (s *Stdoutput) resultMultiline(res ffuf.Result) {
 }
 
 func (s *Stdoutput) resultNormal(res ffuf.Result) {
-	resnormal := fmt.Sprintf("%s%-23s [Status: %s, Size: %d, Words: %d, Lines: %d]", TERMINAL_CLEAR_LINE, s.prepareInputsOneLine(res), s.colorize(fmt.Sprintf("%d", res.StatusCode), res.StatusCode), res.ContentLength, res.ContentWords, res.ContentLines)
+	resnormal := fmt.Sprintf("%s%-23s [Status: %s, Size: %d, Words: %d, Lines: %d, Duration: %dms]", TERMINAL_CLEAR_LINE, s.prepareInputsOneLine(res), s.colorize(fmt.Sprintf("%d", res.StatusCode), res.StatusCode), res.ContentLength, res.ContentWords, res.ContentLines, res.Duration.Milliseconds())
 	fmt.Println(resnormal)
 }
 

pkg/runner/simple.go

@@ -7,6 +7,7 @@ import (
 	"io/ioutil"
 	"net"
 	"net/http"
+	"net/http/httptrace"
 	"net/http/httputil"
 	"net/textproto"
 	"net/url"
@@ -97,7 +98,21 @@ func (r *SimpleRunner) Execute(req *ffuf.Request) (ffuf.Response, error) {
 	var err error
 	var rawreq []byte
 	data := bytes.NewReader(req.Data)
+
+	var start time.Time
+	var firstByteTime time.Duration
+
+	trace := &httptrace.ClientTrace{
+		WroteRequest: func(wri httptrace.WroteRequestInfo) {
+			start = time.Now() // begin the timer after the request is fully written
+		},
+		GotFirstResponseByte: func() {
+			firstByteTime = time.Since(start) // record when the first byte of the response was received
+		},
+	}
+
 	httpreq, err = http.NewRequestWithContext(r.config.Context, req.Method, req.Url, data)
+
 	if err != nil {
 		return ffuf.Response{}, err
 	}
@@ -113,7 +128,7 @@ func (r *SimpleRunner) Execute(req *ffuf.Request) (ffuf.Response, error) {
 	}
 
 	req.Host = httpreq.Host
-	httpreq = httpreq.WithContext(r.config.Context)
+	httpreq = httpreq.WithContext(httptrace.WithClientTrace(r.config.Context, trace))
 	for k, v := range req.Headers {
 		httpreq.Header.Set(k, v)
 	}
@@ -155,6 +170,7 @@ func (r *SimpleRunner) Execute(req *ffuf.Request) (ffuf.Response, error) {
 	linesSize := len(strings.Split(string(resp.Data), "\n"))
 	resp.ContentWords = int64(wordsSize)
 	resp.ContentLines = int64(linesSize)
+	resp.Time = firstByteTime
 
 	return resp, nil
 }