go-packages/iris
1
0
Fork 0
mirror of https://github.com/kataras/iris.git synced 2025-01-23 02:31:04 +01:00
Code Issues Actions Packages Projects Releases Wiki Activity

accesslog: add CSV format

Browse Source 
relative to: https://github.com/kataras/iris/issues/1601
This commit is contained in:
Gerasimos (Makis) Maropoulos 2020-09-12 12:34:59 +03:00
parent a30bbb61f7
commit 2b342a5122
No known key found for this signature in database
GPG Key ID: 5DBE766BD26A54E7
11 changed files with 448 additions and 133 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
_examples/README.md
View File

@ -74,6 +74,7 @@
* [Request Logger](logging/request-logger/main.go)
* [AccessLog: log request & response and more](logging/request-logger/accesslog)
* [AccessLog: custom fields and template](logging/request-logger/accesslog-template/main.go)
* [AccessLog: CSV Format](logging/request-logger/accesslog-csv/main.go)
* [AccessLog: listen to logs and render them](logging/request-logger/accesslog-broker/main.go)
* [Log Requests to a JSON File](logging/request-logger/request-logger-file-json/main.go)
* [Application File Logger](logging/file-logger/main.go)

5
_examples/logging/request-logger/accesslog-csv/access_log.csv.sample Normal file
View File

@ -0,0 +1,5 @@
Timestamp,Latency,Code,Method,Path,IP,Req Values,In,Out,Request,Response
1599900695933,0s,200,GET,/,::1,sleep=35ms,575,81,,Index
1599900696207,0s,404,GET,/notfound,::1,,572,92,,Not Found
1599900696693,0s,200,GET,/,::1,,564,81,,Index
1599900697988,1s,200,GET,/,::1,sleep=1s,573,81,,Index

34
_examples/logging/request-logger/accesslog-csv/main.go Normal file
View File

@ -0,0 +1,34 @@
package main
import (
"time"
"github.com/kataras/iris/v12"
"github.com/kataras/iris/v12/middleware/accesslog"
)
func main() {
app := iris.New()
ac := accesslog.File("access_log.csv")
ac.SetFormatter(&accesslog.CSV{
AutoFlush: true,
Header: true,
// DateScript: "FROM_UNIX",
LatencyRound: time.Second,
})
app.UseRouter(ac.Handler)
app.Get("/", index)
app.Listen(":8080")
}
func index(ctx iris.Context) {
if sleepDur := ctx.URLParam("sleep"); sleepDur != "" {
if d, err := time.ParseDuration(sleepDur); err == nil {
time.Sleep(d)
}
}
ctx.WriteString("Index")
}

10
go.mod
View File

@ -25,22 +25,22 @@ require (
github.com/kataras/pio v0.0.10
github.com/kataras/sitemap v0.0.5
github.com/kataras/tunnel v0.0.1
github.com/klauspost/compress v1.10.11
github.com/klauspost/compress v1.11.0
github.com/mediocregopher/radix/v3 v3.5.2
github.com/microcosm-cc/bluemonday v1.0.4
github.com/russross/blackfriday/v2 v2.0.1
github.com/schollz/closestmatch v2.1.0+incompatible
github.com/square/go-jose/v3 v3.0.0-20200630053402-0a67ce9b0693
github.com/tdewolff/minify/v2 v2.9.2
github.com/tdewolff/minify/v2 v2.9.4
github.com/vmihailenco/msgpack/v5 v5.0.0-beta.1
github.com/yosssi/ace v0.0.5
go.etcd.io/bbolt v1.3.5
golang.org/x/crypto v0.0.0-20200820211705-5c72a883971a
golang.org/x/net v0.0.0-20200822124328-c89045814202
golang.org/x/sys v0.0.0-20200831180312-196b9ba8737a
golang.org/x/net v0.0.0-20200904194848-62affa334b73
golang.org/x/sys v0.0.0-20200909081042-eff7692f9009
golang.org/x/text v0.3.3
golang.org/x/time v0.0.0-20200630173020-3af7569d3a1e
google.golang.org/protobuf v1.25.0
gopkg.in/ini.v1 v1.60.2
gopkg.in/ini.v1 v1.61.0
gopkg.in/yaml.v3 v3.0.0-20200615113413-eeeca48fe776
)

33
middleware/accesslog/accesslog.go
View File

@ -140,7 +140,7 @@ type AccessLog struct {
// Defaults to '|'.
Delim rune
// The time format for current time on log print.
// Defaults to ""2006-01-02 15:04:05" on `New` function.
// Defaults to "2006-01-02 15:04:05" on `New` function.
// Set it to empty to inherit the Iris Application's TimeFormat.
TimeFormat string
// IP displays the remote address.
@ -249,7 +249,9 @@ func New(w io.Writer) *AccessLog {
//
// It panics on error.
func File(path string) *AccessLog {
f, err := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666)
// Note: we add os.RDWR in order to be able to read from it,
// some formatters (e.g. CSV) needs that.
f, err := os.OpenFile(path, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0666)
if err != nil {
panic(err)
}
@ -347,7 +349,13 @@ func (ac *AccessLog) SetFormatter(f Formatter) *AccessLog {
panic("accesslog: SetFormatter called with nil Writer")
}
f.SetOutput(ac.Writer) // inject the writer here.
// Inject the writer (AccessLog) here, the writer
// It is a protected with mutex writer to the final output
// when LockWriter field was set to true
// or when the given destination was os.File or bytes.Buffer
// (otherwise we assume it's locked by the end-developer).
f.SetOutput(ac)
ac.formatter = f
return ac
}
@ -363,6 +371,8 @@ func (ac *AccessLog) AddFields(setters ...FieldSetter) *AccessLog {
// Close calls each registered Closer's Close method.
// Exits when all close methods have been executed.
func (ac *AccessLog) Close() (err error) {
ac.flushFormatter()
for _, closer := range ac.Closers {
cErr := closer.Close()
if cErr != nil {
@ -377,6 +387,14 @@ func (ac *AccessLog) Close() (err error) {
return
}
func (ac *AccessLog) flushFormatter() {
if ac.formatter != nil {
if flusher, ok := ac.formatter.(Flusher); ok {
flusher.Flush()
}
}
}
func (ac *AccessLog) shouldReadRequestBody() bool {
return ac.RequestBody || ac.BytesReceived
@ -564,7 +582,7 @@ func (ac *AccessLog) after(ctx *context.Context, lat time.Duration, method, path
ip,
requestBody, responseBody,
bytesReceived, bytesSent,
ctx.Params(), ctx.URLParamsSorted(), *fields,
ctx.Params().Store, ctx.URLParamsSorted(), *fields,
); err != nil {
ctx.Application().Logger().Errorf("accesslog: %v", err)
}
@ -574,7 +592,7 @@ const defaultDelim = '|'
// Print writes a log manually.
// The `Handler` method calls it.
func (ac *AccessLog) Print(ctx *context.Context, latency time.Duration, timeFormat string, code int, method, path, ip, reqBody, respBody string, bytesReceived, bytesSent int, params *context.RequestParams, query []memstore.StringEntry, fields []memstore.Entry) (err error) {
func (ac *AccessLog) Print(ctx *context.Context, latency time.Duration, timeFormat string, code int, method, path, ip, reqBody, respBody string, bytesReceived, bytesSent int, params memstore.Store, query []memstore.StringEntry, fields []memstore.Entry) (err error) {
now := ac.Clock.Now()
if hasFormatter, hasBroker := ac.formatter != nil, ac.broker != nil; hasFormatter || hasBroker {
@ -589,7 +607,7 @@ func (ac *AccessLog) Print(ctx *context.Context, latency time.Duration, timeForm
log.Path = path
log.IP = ip
log.Query = query
log.PathParams = params.Store
log.PathParams = params
log.Fields = fields
log.BytesReceived = bytesReceived
log.BytesSent = bytesSent
@ -624,6 +642,7 @@ func (ac *AccessLog) Print(ctx *context.Context, latency time.Duration, timeForm
// the number of separators are the same, in order to be easier
// for 3rd-party programs to read the result log file.
builder := ac.bufPool.Get().(*bytes.Buffer)
builder.WriteString(now.Format(timeFormat))
builder.WriteRune(ac.Delim)
@ -670,6 +689,8 @@ var lineBreaksReplacer = strings.NewReplacer("\n\r", " ", "\n", " ")
func (ac *AccessLog) getErrorText(err error) (text string) { // caller checks for nil.
if errPanic, ok := context.IsErrPanicRecovery(err); ok {
ac.flushFormatter() // flush any buffered formatter's contents to be written to the output.
switch ac.PanicLog {
case LogHandler:
text = errPanic.CurrentHandler

14
middleware/accesslog/accesslog_test.go
View File

@ -52,13 +52,13 @@ func TestAccessLogPrint_Simple(t *testing.T) {
"Outcoming",
0,
0,
&context.RequestParams{
Store: []memstore.Entry{
{Key: "path_param", ValueRaw: "path_param_value"},
},
}, []memstore.StringEntry{
memstore.Store{
{Key: "path_param", ValueRaw: "path_param_value"},
},
[]memstore.StringEntry{
{Key: "url_query", Value: "url_query_value"},
}, []memstore.Entry{
},
[]memstore.Entry{
{Key: "custom", ValueRaw: "custom_value"},
})
}()
@ -126,7 +126,7 @@ func TestAccessLogBroker(t *testing.T) {
"",
0,
0,
&context.RequestParams{},
nil,
nil,
nil,
)

167
middleware/accesslog/csv.go Normal file
View File

@ -0,0 +1,167 @@
package accesslog
import (
"encoding/csv"
"io"
"strconv"
"time"
)
// CSV is a Formatter type for csv encoded logs.
type CSV struct {
writer *csv.Writer
ac *AccessLog
// Add header fields to the first line if it's not exist.
// Note that the destination should be a compatible io.Reader
// with access to write.
Header bool
// Google Spreadsheet's Script to wrap the Timestamp field
// in order to convert it into a readable date.
// Example: "FROM_UNIX" when
// function FROM_UNIX(epoch_in_millis) {
// return new Date(epoch_in_millis);
// }
DateScript string
// Latency Round base, e.g. time.Second.
LatencyRound time.Duration
// Writes immediately every record.
AutoFlush bool
// TODO: Fields []string // field name, position?
}
// SetOutput initializes the csv writer.
// It uses the "dest" as AccessLog to
// write the first csv record which
// contains the names of the future log values.
func (f *CSV) SetOutput(dest io.Writer) {
ac, ok := dest.(*AccessLog)
if !ok {
panic("SetOutput with invalid type. Report it as bug.")
}
w := csv.NewWriter(dest)
f.writer = w
f.ac = ac
if !f.Header {
return
}
{
// If the destination is not a reader
// we can't detect if the header already inserted
// so we exit, we dont want to malform the contents.
destReader, ok := ac.Writer.(io.Reader)
if !ok {
return
}
r := csv.NewReader(destReader)
if header, err := r.Read(); err == nil && len(header) > 0 && header[0] == "Timestamp" {
// we assume header already exists, exit.
return
}
}
// Write the header.
keys := []string{"Timestamp", "Latency", "Code", "Method", "Path"}
if ac.IP {
keys = append(keys, "IP")
}
// keys = append(keys, []string{"Params", "Query"}...)
keys = append(keys, "Req Values")
/*
if len(ac.FieldSetters) > 0 {
keys = append(keys, "Fields")
} // Make fields their own headers?
*/
if ac.BytesReceived {
keys = append(keys, "In")
}
if ac.BytesSent {
keys = append(keys, "Out")
}
if ac.RequestBody {
keys = append(keys, "Request")
}
if ac.ResponseBody {
keys = append(keys, "Response")
}
w.Write(keys)
w.Flush()
}
// Format writes an incoming log using CSV encoding.
func (f *CSV) Format(log *Log) (bool, error) {
// Timestamp, Latency, Code, Method, Path, IP, Path Params Query Fields
//|Bytes Received|Bytes Sent|Request|Response|
timestamp := strconv.FormatInt(log.Timestamp, 10)
if f.DateScript != "" {
timestamp = "=" + f.DateScript + "(" + timestamp + ")"
}
lat := ""
if f.LatencyRound > 0 {
lat = log.Latency.Round(f.LatencyRound).String()
} else {
lat = log.Latency.String()
}
values := []string{
timestamp,
lat,
strconv.Itoa(log.Code),
log.Method,
log.Path,
}
if f.ac.IP {
values = append(values, log.IP)
}
parseRequestValues(log.Code, log.PathParams, log.Query, log.Fields)
values = append(values, log.RequestValuesLine())
if f.ac.BytesReceived {
values = append(values, strconv.Itoa(log.BytesReceived))
}
if f.ac.BytesSent {
values = append(values, strconv.Itoa(log.BytesSent))
}
if f.ac.RequestBody {
values = append(values, log.Request)
}
if f.ac.ResponseBody {
values = append(values, log.Response)
}
f.writer.Write(values)
if f.AutoFlush {
return true, f.Flush()
}
return true, nil
}
// Flush implements the Fluster interface.
// Flushes any buffered csv records to the destination.
func (f *CSV) Flush() error {
f.writer.Flush()
return f.writer.Error()
}

54
middleware/accesslog/csv_test.go Normal file
View File

@ -0,0 +1,54 @@
package accesslog
import (
"bytes"
"testing"
"time"
"github.com/kataras/iris/v12/core/memstore"
)
func TestCSV(t *testing.T) {
buf := new(bytes.Buffer)
ac := New(buf)
staticNow, _ := time.Parse(defaultTimeFormat, "1993-01-01 05:00:00")
ac.Clock = TClock(staticNow)
ac.SetFormatter(&CSV{
Header: true,
LatencyRound: time.Second,
AutoFlush: true,
})
lat, _ := time.ParseDuration("1s")
print := func() {
ac.Print(
nil,
lat,
"",
200,
"GET",
"/",
"::1",
"",
"Index",
573,
81,
nil,
[]memstore.StringEntry{{Key: "sleep", Value: "1s"}},
nil)
}
// print twice, the header should only be written once.
print()
print()
expected := `Timestamp,Latency,Code,Method,Path,IP,Req Values,In,Out,Request,Response
725864400000,1s,200,GET,/,::1,sleep=1s,573,81,,Index
725864400000,1s,200,GET,/,::1,sleep=1s,573,81,,Index
`
if got := buf.String(); expected != got {
t.Fatalf("expected:\n%s\n\nbut got:\n%s", expected, got)
}
}

54
middleware/accesslog/json.go Normal file
View File

@ -0,0 +1,54 @@
package accesslog
import (
"encoding/json"
"io"
"sync"
)
// JSON is a Formatter type for JSON logs.
type JSON struct {
Prefix, Indent string
EscapeHTML bool
enc *json.Encoder
mu sync.Mutex
lockEncoder bool
}
// SetOutput creates the json encoder writes to the "dest".
// It's called automatically by the middleware when this Formatter is used.
func (f *JSON) SetOutput(dest io.Writer) {
if dest == nil {
return
}
// All logs share the same accesslog's writer and it cannot change during serve-time.
enc := json.NewEncoder(dest)
enc.SetEscapeHTML(f.EscapeHTML)
enc.SetIndent(f.Prefix, f.Indent)
f.lockEncoder = f.Prefix != "" || f.Indent != ""
f.enc = enc
}
// Format prints the logs in JSON format.
// Writes to the destination directly,
// locks on each Format call.
func (f *JSON) Format(log *Log) (bool, error) {
// f.mu.Lock()
// ^ This lock is not required as the writer is
// protected with mutex if necessary or configurated to do so.
// However, if we navigate through the
// internal encoding's source code we'll see that it
// uses a field for its indent buffer,
// therefore it's only useful when Prefix or Indent was not empty.
if f.lockEncoder {
f.mu.Lock()
}
err := f.enc.Encode(log)
if f.lockEncoder {
f.mu.Unlock()
}
return true, err
}

144
middleware/accesslog/log.go
View File

@ -1,12 +1,9 @@
package accesslog
import (
"encoding/json"
"fmt"
"io"
"strings"
"sync"
"text/template"
"time"
"github.com/kataras/iris/v12/context"
@ -67,7 +64,7 @@ func (l *Log) Clone() Log {
// RequestValuesLine returns a string line which
// combines the path parameters, query and custom fields.
func (l *Log) RequestValuesLine() string {
return parseRequestValues(l.Code, l.Ctx.Params(), l.Ctx.URLParamsSorted(), l.Fields)
return parseRequestValues(l.Code, l.PathParams, l.Query, l.Fields)
}
// BytesReceivedLine returns the formatted bytes received length.
@ -98,17 +95,17 @@ func formatBytes(b int) string {
float64(b)/float64(div), "KMGTPE"[exp])
}
func parseRequestValues(code int, pathParams *context.RequestParams, query []memstore.StringEntry, fields memstore.Store) (requestValues string) {
func parseRequestValues(code int, pathParams memstore.Store, query []memstore.StringEntry, fields memstore.Store) (requestValues string) {
var buf strings.Builder
if !context.StatusCodeNotSuccessful(code) {
// collect path parameters on a successful request-response only.
pathParams.Visit(func(key, value string) {
buf.WriteString(key)
for _, entry := range pathParams {
buf.WriteString(entry.Key)
buf.WriteByte('=')
buf.WriteString(value)
buf.WriteString(fmt.Sprintf("%v", entry.ValueRaw))
buf.WriteByte(' ')
})
}
}
for _, entry := range query {
@ -132,114 +129,31 @@ func parseRequestValues(code int, pathParams *context.RequestParams, query []mem
return
}
// Formatter is responsible to print a Log to the accesslog's writer.
type Formatter interface {
// SetOutput should inject the accesslog's direct output,
// if this "dest" is used then the Formatter
// should manually control its concurrent use.
SetOutput(dest io.Writer)
// Format should print the Log.
// Returns nil error on handle successfully,
// otherwise the log will be printed using the default formatter
// and the error will be printed to the Iris Application's error log level.
// Should return true if this handled the logging, otherwise false to
// continue with the default print format.
Format(log *Log) (bool, error)
}
type (
// Formatter is responsible to print a Log to the accesslog's writer.
Formatter interface {
// SetOutput should inject the accesslog's direct output,
// if this "dest" is used then the Formatter
// should manually control its concurrent use.
SetOutput(dest io.Writer)
// Format should print the Log.
// Returns nil error on handle successfully,
// otherwise the log will be printed using the default formatter
// and the error will be printed to the Iris Application's error log level.
// Should return true if this handled the logging, otherwise false to
// continue with the default print format.
Format(log *Log) (bool, error)
}
// Flusher can be implemented by a Formatter
// to call its Flush method on AccessLog.Close
// and on panic errors.
Flusher interface{ Flush() error }
)
var (
_ Formatter = (*JSON)(nil)
_ Formatter = (*Template)(nil)
_ Formatter = (*CSV)(nil)
_ Flusher = (*CSV)(nil)
)
// JSON is a Formatter type for JSON logs.
type JSON struct {
Prefix, Indent string
EscapeHTML bool
enc *json.Encoder
mu sync.Mutex
}
// SetOutput creates the json encoder writes to the "dest".
// It's called automatically by the middleware when this Formatter is used.
func (f *JSON) SetOutput(dest io.Writer) {
if dest == nil {
return
}
// All logs share the same accesslog's writer and it cannot change during serve-time.
enc := json.NewEncoder(dest)
enc.SetEscapeHTML(f.EscapeHTML)
enc.SetIndent(f.Prefix, f.Indent)
f.enc = enc
}
// Format prints the logs in JSON format.
// Writes to the destination directly,
// locks on each Format call.
func (f *JSON) Format(log *Log) (bool, error) {
f.mu.Lock()
err := f.enc.Encode(log)
f.mu.Unlock()
return true, err
}
// Template is a Formatter.
// It's used to print the Log in a text/template way.
// The caller has full control over the printable result;
// certain fields can be ignored, change the display order and e.t.c.
type Template struct {
// Custom template source.
// Use this or `Tmpl/TmplName` fields.
Text string
// Custom template funcs to used when `Text` is not empty.
Funcs template.FuncMap
// Custom template to use, overrides the `Text` and `Funcs` fields.
Tmpl *template.Template
// If not empty then this named template/block renders the log line.
TmplName string
dest io.Writer
mu sync.Mutex
}
// SetOutput creates the default template if missing
// when this formatter is registered.
func (f *Template) SetOutput(dest io.Writer) {
if f.Tmpl == nil {
tmpl := template.New("")
text := f.Text
if text != "" {
tmpl.Funcs(f.Funcs)
} else {
text = defaultTmplText
}
f.Tmpl = template.Must(tmpl.Parse(text))
}
f.dest = dest
}
const defaultTmplText = "{{.Now.Format .TimeFormat}}|{{.Latency}}|{{.Code}}|{{.Method}}|{{.Path}}|{{.IP}}|{{.RequestValuesLine}}|{{.BytesReceivedLine}}|{{.BytesSentLine}}|{{.Request}}|{{.Response}}|\n"
// Format prints the logs in text/template format.
func (f *Template) Format(log *Log) (bool, error) {
var err error
// A template may be executed safely in parallel, although if parallel
// executions share a Writer the output may be interleaved.
f.mu.Lock()
if f.TmplName != "" {
err = f.Tmpl.ExecuteTemplate(f.dest, f.TmplName, log)
} else {
err = f.Tmpl.Execute(f.dest, log)
}
f.mu.Unlock()
return true, err
}

65
middleware/accesslog/template.go Normal file
View File

@ -0,0 +1,65 @@
package accesslog
import (
"io"
"sync"
"text/template"
)
// Template is a Formatter.
// It's used to print the Log in a text/template way.
// The caller has full control over the printable result;
// certain fields can be ignored, change the display order and e.t.c.
type Template struct {
// Custom template source.
// Use this or `Tmpl/TmplName` fields.
Text string
// Custom template funcs to used when `Text` is not empty.
Funcs template.FuncMap
// Custom template to use, overrides the `Text` and `Funcs` fields.
Tmpl *template.Template
// If not empty then this named template/block renders the log line.
TmplName string
dest io.Writer
mu sync.Mutex
}
// SetOutput creates the default template if missing
// when this formatter is registered.
func (f *Template) SetOutput(dest io.Writer) {
if f.Tmpl == nil {
tmpl := template.New("")
text := f.Text
if text != "" {
tmpl.Funcs(f.Funcs)
} else {
text = defaultTmplText
}
f.Tmpl = template.Must(tmpl.Parse(text))
}
f.dest = dest
}
const defaultTmplText = "{{.Now.Format .TimeFormat}}|{{.Latency}}|{{.Code}}|{{.Method}}|{{.Path}}|{{.IP}}|{{.RequestValuesLine}}|{{.BytesReceivedLine}}|{{.BytesSentLine}}|{{.Request}}|{{.Response}}|\n"
// Format prints the logs in text/template format.
func (f *Template) Format(log *Log) (bool, error) {
var err error
// A template may be executed safely in parallel, although if parallel
// executions share a Writer the output may be interleaved.
f.mu.Lock()
if f.TmplName != "" {
err = f.Tmpl.ExecuteTemplate(f.dest, f.TmplName, log)
} else {
err = f.Tmpl.Execute(f.dest, log)
}
f.mu.Unlock()
return true, err
}