1// Copyright 2017 Google Inc. All rights reserved.
2//
3// Licensed under the Apache License, Version 2.0 (the "License");
4// you may not use this file except in compliance with the License.
5// You may obtain a copy of the License at
6//
7//     http://www.apache.org/licenses/LICENSE-2.0
8//
9// Unless required by applicable law or agreed to in writing, software
10// distributed under the License is distributed on an "AS IS" BASIS,
11// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12// See the License for the specific language governing permissions and
13// limitations under the License.
14
15// Package logger implements a logging package designed for command line
16// utilities.  It uses the standard 'log' package and function, but splits
17// output between stderr and a rotating log file.
18//
19// In addition to the standard logger functions, Verbose[f|ln] calls only go to
20// the log file by default, unless SetVerbose(true) has been called.
21//
22// The log file also includes extended date/time/source information, which are
23// omitted from the stderr output for better readability.
24//
25// In order to better handle resource cleanup after a Fatal error, the Fatal
26// functions panic instead of calling os.Exit(). To actually do the cleanup,
27// and prevent the printing of the panic, call defer logger.Cleanup() at the
28// beginning of your main function.
29package logger
30
31import (
32	"android/soong/ui/metrics"
33	"errors"
34	"fmt"
35	"io"
36	"io/ioutil"
37	"log"
38	"os"
39	"path/filepath"
40	"strconv"
41	"sync"
42	"syscall"
43)
44
45type Logger interface {
46	// Print* prints to both stderr and the file log.
47	// Arguments to Print are handled in the manner of fmt.Print.
48	Print(v ...interface{})
49	// Arguments to Printf are handled in the manner of fmt.Printf
50	Printf(format string, v ...interface{})
51	// Arguments to Println are handled in the manner of fmt.Println
52	Println(v ...interface{})
53
54	// Verbose* is equivalent to Print*, but skips stderr unless the
55	// logger has been configured in verbose mode.
56	Verbose(v ...interface{})
57	Verbosef(format string, v ...interface{})
58	Verboseln(v ...interface{})
59
60	// Fatal* is equivalent to Print* followed by a call to panic that
61	// can be converted to an error using Recover, or will be converted
62	// to a call to os.Exit(1) with a deferred call to Cleanup()
63	Fatal(v ...interface{})
64	Fatalf(format string, v ...interface{})
65	Fatalln(v ...interface{})
66
67	// Panic is equivalent to Print* followed by a call to panic.
68	Panic(v ...interface{})
69	Panicf(format string, v ...interface{})
70	Panicln(v ...interface{})
71
72	// Output writes the string to both stderr and the file log.
73	Output(calldepth int, str string) error
74}
75
76// fatalError is the type used when Fatal[f|ln]
77type fatalError struct {
78	error
79}
80
81func fileRotation(from, baseName, ext string, cur, max int) error {
82	newName := baseName + "." + strconv.Itoa(cur) + ext
83
84	if _, err := os.Lstat(newName); err == nil {
85		if cur+1 <= max {
86			fileRotation(newName, baseName, ext, cur+1, max)
87		}
88	}
89
90	if err := os.Rename(from, newName); err != nil {
91		return fmt.Errorf("Failed to rotate %s to %s. %s", from, newName, err)
92	}
93	return nil
94}
95
96// CreateFileWithRotation returns a new os.File using os.Create, renaming any
97// existing files to <filename>.#.<ext>, keeping up to maxCount files.
98// <filename>.1.<ext> is the most recent backup, <filename>.2.<ext> is the
99// second most recent backup, etc.
100func CreateFileWithRotation(filename string, maxCount int) (*os.File, error) {
101	lockFileName := filepath.Join(filepath.Dir(filename), ".lock_"+filepath.Base(filename))
102	lockFile, err := os.OpenFile(lockFileName, os.O_RDWR|os.O_CREATE, 0666)
103	if err != nil {
104		return nil, err
105	}
106	defer lockFile.Close()
107
108	err = syscall.Flock(int(lockFile.Fd()), syscall.LOCK_EX)
109	if err != nil {
110		return nil, err
111	}
112
113	if _, err := os.Lstat(filename); err == nil {
114		ext := filepath.Ext(filename)
115		basename := filename[:len(filename)-len(ext)]
116		if err = fileRotation(filename, basename, ext, 1, maxCount); err != nil {
117			return nil, err
118		}
119	}
120
121	return os.Create(filename)
122}
123
124// Recover can be used with defer in a GoRoutine to convert a Fatal panics to
125// an error that can be handled.
126func Recover(fn func(err error)) {
127	p := recover()
128
129	if p == nil {
130		return
131	} else if log, ok := p.(fatalError); ok {
132		fn(error(log))
133	} else {
134		panic(p)
135	}
136}
137
138type stdLogger struct {
139	stderr  *log.Logger
140	verbose bool
141
142	fileLogger *log.Logger
143	mutex      sync.Mutex
144	file       *os.File
145	metrics    *metrics.Metrics
146}
147
148var _ Logger = &stdLogger{}
149
150// New creates a new Logger. The out variable sets the destination, commonly
151// os.Stderr, but it may be a buffer for tests, or a separate log file if
152// the user doesn't need to see the output.
153func New(out io.Writer) *stdLogger {
154	return NewWithMetrics(out, nil)
155}
156
157func NewWithMetrics(out io.Writer, m *metrics.Metrics) *stdLogger {
158	return &stdLogger{
159		stderr:     log.New(out, "", log.Ltime),
160		fileLogger: log.New(ioutil.Discard, "", log.Ldate|log.Lmicroseconds|log.Llongfile),
161		metrics:    m,
162	}
163}
164
165// SetVerbose controls whether Verbose[f|ln] logs to stderr as well as the
166// file-backed log.
167func (s *stdLogger) SetVerbose(v bool) *stdLogger {
168	s.verbose = v
169	return s
170}
171
172// SetOutput controls where the file-backed log will be saved. It will keep
173// some number of backups of old log files.
174func (s *stdLogger) SetOutput(path string) *stdLogger {
175	if f, err := CreateFileWithRotation(path, 5); err == nil {
176		s.mutex.Lock()
177		defer s.mutex.Unlock()
178
179		if s.file != nil {
180			s.file.Close()
181		}
182		s.file = f
183		s.fileLogger.SetOutput(f)
184	} else {
185		s.Fatal(err.Error())
186	}
187	return s
188}
189
190type panicWriter struct{}
191
192func (panicWriter) Write([]byte) (int, error) { panic("write to panicWriter") }
193
194// Close disables logging to the file and closes the file handle.
195func (s *stdLogger) Close() {
196	s.mutex.Lock()
197	defer s.mutex.Unlock()
198	if s.file != nil {
199		s.fileLogger.SetOutput(panicWriter{})
200		s.file.Close()
201		s.file = nil
202	}
203}
204
205// Cleanup should be used with defer in your main function. It will close the
206// log file and convert any Fatal panics back to os.Exit(1)
207func (s *stdLogger) Cleanup() {
208	fatal := false
209	p := recover()
210
211	if _, ok := p.(fatalError); ok {
212		fatal = true
213		p = nil
214	} else if p != nil {
215		s.Println(p)
216	}
217
218	s.Close()
219
220	if p != nil {
221		panic(p)
222	} else if fatal {
223		os.Exit(1)
224	}
225}
226
227type verbosityLevel int
228
229const (
230	verboseLog verbosityLevel = iota
231	infoLog
232	fatalLog
233	panicLog
234)
235
236// Output writes string to both stderr and the file log.
237func (s *stdLogger) Output(calldepth int, str string) error {
238	return s.output(calldepth, str, infoLog)
239}
240
241// output writes string to stderr, the file log, and if fatal or panic, to metrics.
242func (s *stdLogger) output(calldepth int, str string, level verbosityLevel) error {
243	if level != verboseLog || s.verbose {
244		s.stderr.Output(calldepth+1, str)
245	}
246	if level >= fatalLog {
247		s.metrics.SetFatalOrPanicMessage(str)
248	}
249	return s.fileLogger.Output(calldepth+1, str)
250}
251
252// VerboseOutput is equivalent to Output, but only goes to the file log
253// unless SetVerbose(true) has been called.
254func (s *stdLogger) VerboseOutput(calldepth int, str string) error {
255	return s.output(calldepth, str, verboseLog)
256}
257
258// Print prints to both stderr and the file log.
259// Arguments are handled in the manner of fmt.Print.
260func (s *stdLogger) Print(v ...interface{}) {
261	output := fmt.Sprint(v...)
262	s.output(2, output, infoLog)
263}
264
265// Printf prints to both stderr and the file log.
266// Arguments are handled in the manner of fmt.Printf.
267func (s *stdLogger) Printf(format string, v ...interface{}) {
268	output := fmt.Sprintf(format, v...)
269	s.output(2, output, infoLog)
270}
271
272// Println prints to both stderr and the file log.
273// Arguments are handled in the manner of fmt.Println.
274func (s *stdLogger) Println(v ...interface{}) {
275	output := fmt.Sprintln(v...)
276	s.output(2, output, infoLog)
277}
278
279// Verbose is equivalent to Print, but only goes to the file log unless
280// SetVerbose(true) has been called.
281func (s *stdLogger) Verbose(v ...interface{}) {
282	output := fmt.Sprint(v...)
283	s.VerboseOutput(2, output)
284}
285
286// Verbosef is equivalent to Printf, but only goes to the file log unless
287// SetVerbose(true) has been called.
288func (s *stdLogger) Verbosef(format string, v ...interface{}) {
289	output := fmt.Sprintf(format, v...)
290	s.VerboseOutput(2, output)
291}
292
293// Verboseln is equivalent to Println, but only goes to the file log unless
294// SetVerbose(true) has been called.
295func (s *stdLogger) Verboseln(v ...interface{}) {
296	output := fmt.Sprintln(v...)
297	s.VerboseOutput(2, output)
298}
299
300// Fatal is equivalent to Print() followed by a call to panic() that
301// Cleanup will convert to a os.Exit(1).
302func (s *stdLogger) Fatal(v ...interface{}) {
303	output := fmt.Sprint(v...)
304	s.output(2, output, fatalLog)
305	panic(fatalError{errors.New(output)})
306}
307
308// Fatalf is equivalent to Printf() followed by a call to panic() that
309// Cleanup will convert to a os.Exit(1).
310func (s *stdLogger) Fatalf(format string, v ...interface{}) {
311	output := fmt.Sprintf(format, v...)
312	s.output(2, output, fatalLog)
313	panic(fatalError{errors.New(output)})
314}
315
316// Fatalln is equivalent to Println() followed by a call to panic() that
317// Cleanup will convert to a os.Exit(1).
318func (s *stdLogger) Fatalln(v ...interface{}) {
319	output := fmt.Sprintln(v...)
320	s.output(2, output, fatalLog)
321	panic(fatalError{errors.New(output)})
322}
323
324// Panic is equivalent to Print() followed by a call to panic().
325func (s *stdLogger) Panic(v ...interface{}) {
326	output := fmt.Sprint(v...)
327	s.output(2, output, panicLog)
328	panic(output)
329}
330
331// Panicf is equivalent to Printf() followed by a call to panic().
332func (s *stdLogger) Panicf(format string, v ...interface{}) {
333	output := fmt.Sprintf(format, v...)
334	s.output(2, output, panicLog)
335	panic(output)
336}
337
338// Panicln is equivalent to Println() followed by a call to panic().
339func (s *stdLogger) Panicln(v ...interface{}) {
340	output := fmt.Sprintln(v...)
341	s.output(2, output, panicLog)
342	panic(output)
343}
344