forked from zach-klippenstein/adbfs
/
log_entry.go
181 lines (153 loc) · 4.25 KB
/
log_entry.go
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
package adbfs
import (
"fmt"
"os"
"time"
"syscall"
"github.com/Sirupsen/logrus"
"github.com/zach-klippenstein/adbfs/internal/cli"
"github.com/zach-klippenstein/goadb/util"
"golang.org/x/net/trace"
)
/*
LogEntry reports results, errors, and statistics for an individual operation.
Each method can only be called once, and will panic on subsequent calls.
If an error is reported, it is logged as a separate entry.
Example Usage
func DoTheThing(path string) fuse.Status {
logEntry := StartOperation("DoTheThing", path)
defer FinishOperation(log) // Where log is a logrus logger.
result, err := perform(path)
if err != nil {
logEntry.Error(err)
return err
}
logEntry.Result(result)
return logEntry.Status(fuse.OK)
}
*/
type LogEntry struct {
name string
path string
args string
startTime time.Time
err error
result string
status string
trace trace.Trace
cacheUsed bool
cacheHit bool
}
var traceEntryFormatter = new(logrus.JSONFormatter)
// StartOperation creates a new LogEntry with the current time.
// Should be immediately followed by a deferred call to FinishOperation.
func StartOperation(name string, path string) *LogEntry {
return &LogEntry{
name: name,
path: path,
startTime: time.Now(),
trace: trace.New(name, path),
}
}
func StartFileOperation(name, path string, args string) *LogEntry {
name = "File " + name
return &LogEntry{
name: name,
path: path,
args: args,
startTime: time.Now(),
trace: trace.New(name, args),
}
}
// ErrorMsg records a failure result.
// Panics if called more than once.
func (r *LogEntry) ErrorMsg(err error, msg string, args ...interface{}) {
r.Error(fmt.Errorf("%s: %v", fmt.Sprintf(msg, args...), util.ErrorWithCauseChain(err)))
}
// Error records a failure result.
// Panics if called more than once.
func (r *LogEntry) Error(err error) {
if r.err != nil {
panic(fmt.Sprintf("err already set to '%s', can't set to '%s'", r.err, err))
}
r.err = err
}
// Result records a non-failure result.
// Panics if called more than once.
func (r *LogEntry) Result(msg string, args ...interface{}) {
result := fmt.Sprintf(msg, args...)
if r.result != "" {
panic(fmt.Sprintf("result already set to '%s', can't set to '%s'", r.result, result))
}
r.result = result
}
// Status records the fuse.Status result of an operation.
func (r *LogEntry) Status(status syscall.Errno) syscall.Errno {
if r.status != "" {
panic(fmt.Sprintf("status already set to '%s', can't set to '%s'", r.status, status))
}
if status == OK {
r.status = "OK"
} else {
r.status = status.Error()
}
return status
}
// CacheUsed records that a cache was used to attempt to retrieve a result.
func (r *LogEntry) CacheUsed(hit bool) {
r.cacheUsed = true
r.cacheHit = r.cacheHit || hit
}
// FinishOperation should be deferred. It will log the duration of the operation, as well
// as any results and/or errors.
func (r *LogEntry) FinishOperation() {
r.finishOperation(false)
}
func (r *LogEntry) SuppressFinishOperation() {
r.finishOperation(true)
}
func (r *LogEntry) finishOperation(suppress bool) {
entry := cli.Log.WithFields(logrus.Fields{
"duration_ms": calculateDurationMillis(r.startTime),
"status": r.status,
"pid": os.Getpid(),
})
if r.path != "" {
entry = entry.WithField("path", r.path)
}
if r.args != "" {
entry = entry.WithField("args", r.args)
}
if r.result != "" {
entry = entry.WithField("result", r.result)
}
if r.cacheUsed {
entry = entry.WithField("cache_hit", r.cacheHit)
}
if !suppress {
entry.Debug(r.name)
}
if r.err != nil {
cli.Log.Errorln(util.ErrorWithCauseChain(r.err))
}
r.logTrace(entry)
}
func (r *LogEntry) logTrace(entry *logrus.Entry) {
var msg string
// Use a different formatter for logging to HTML trace viewer since the TextFormatter will include color escape codes.
msgBytes, err := traceEntryFormatter.Format(entry)
if err != nil {
msg = fmt.Sprint(entry)
} else {
msg = string(msgBytes)
}
r.trace.LazyPrintf("%s", msg)
if r.err != nil {
r.trace.SetError()
r.trace.LazyPrintf("%s", util.ErrorWithCauseChain(r.err))
}
r.trace.Finish()
}
func calculateDurationMillis(startTime time.Time) int64 {
return time.Now().Sub(startTime).Nanoseconds() / time.Millisecond.Nanoseconds()
}