You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

387 lines
18 KiB

  1. # rlog - A simple Golang logger with lots of features and no external dependencies
  2. Rlog is a simple logging package, rich in features. It is configurable 'from
  3. the outside' via environment variables and/or config file and has no
  4. dependencies other than the standard Golang library.
  5. It is called "rlog", because it was originally written for the
  6. [Romana project](https://github.com/romana/romana).
  7. ## Features
  8. * Logging configuration of a running process can be modified, without needing
  9. to restart it. This allows for on-demand finer level logging, if a process
  10. starts to experience issues, for example.
  11. * Is configured through environment variables or config file: No need to call a
  12. special init function of some kind to initialize and configure the logger.
  13. * A new config file can be specified and applied programmatically at any time.
  14. * Offers familiar and easy to use log functions for the usual levels: Debug,
  15. Info, Warn, Error and Critical.
  16. * Offers an additional multi level logging facility with arbitrary depth,
  17. called Trace.
  18. * Log and trace levels can be configured separately for the individual files
  19. that make up your executable.
  20. * Every log function comes in a 'plain' version (to be used like Println)
  21. and in a formatted version (to be used like Printf). For example, there
  22. is Debug() and Debugf(), which takes a format string as first parameter.
  23. * Can be configured to print caller info (process ID, module filename and line,
  24. function name). In addition, can also print the goroutine ID in the caller
  25. info.
  26. * Has NO external dependencies, except things contained in the standard Go
  27. library.
  28. * Fully configurable date/time format.
  29. * Logging of date and time can be disabled (useful in case of systemd, which
  30. adds its own time stamps in its log database).
  31. * By default logs to stderr or stdout. A logfile can be configured via
  32. environment variable. Output may happen exclusively to the logfile or in
  33. addition to the output on stderr/stdout. Also, a different output stream
  34. or file can be specified from within your programs at any time.
  35. ## Defaults
  36. Rlog comes with reasonable defaults, so you can just start using it without any
  37. configuration at all. By default:
  38. * Log level set to INFO.
  39. * Trace messages are not logged.
  40. * Time stamps are logged with each message.
  41. * No caller information.
  42. * Output is sent to stderr.
  43. All those defaults can easily be changed through environment variables or the
  44. config file.
  45. ## Controlling rlog through environment or config file variables
  46. Rlog is configured via the following settings, which may either be defined as
  47. environment variables or via a config file.
  48. * `RLOG_LOG_LEVEL`: Set to "DEBUG", "INFO", "WARN", "ERROR", "CRITICAL" or
  49. "NONE". Any message of a level >= than what's configured will be printed. If
  50. this is not defined it will default to "INFO". If it is set to "NONE" then
  51. all logging is disabled, except Trace logs, which are controlled via a
  52. separate variable. In addition, log levels can be set for individual files
  53. (see below for more information). Default: INFO - meaning that INFO and
  54. higher is logged.
  55. * `RLOG_TRACE_LEVEL`: "Trace" log messages take an additional numeric level as
  56. first parameter. The user can specify an arbitrary number of levels. Set
  57. RLOG_TRACE_LEVEL to a number. All Trace messages with a level <=
  58. RLOG_TRACE_LEVEL will be printed. If this variable is undefined, or set to -1
  59. then no Trace messages are printed. The idea is that the higher the
  60. RLOG_TRACE_LEVEL value, the more 'chatty' and verbose the Trace message
  61. output becomes. In addition, trace levels can be set for individual files
  62. (see below for more information). Default: Not set - meaning that no trace
  63. messages are logged.
  64. * `RLOG_CALLER_INFO`: If this variable is set to "1", "yes" or something else
  65. that evaluates to 'true' then the message also contains the caller
  66. information, consisting of the process ID, file and line number as well as
  67. function name from which the log message was called. Default: No - meaning
  68. that no caller info is logged.
  69. * `RLOG_GOROUTINE_ID`: If this variable is set to "1", "yes" or something else
  70. that evaluates to 'true' AND the printing of caller info is requested, then
  71. the caller info contains the goroutine ID, separated from the process ID by a
  72. ':'. Note that calculation of the goroutine ID has a performance impact, so
  73. please only enable this option if needed.
  74. * `RLOG_TIME_FORMAT`: Use this variable to customize the date/time format. The
  75. format is specified either by the well known formats listed in
  76. https://golang.org/src/time/format.go, for example "UnixDate" or "RFC3339".
  77. Or as an example date/time output, which is described here:
  78. https://golang.org/pkg/time/#Time.Format Default: Not set - formatted
  79. according to RFC3339.
  80. * `RLOG_LOG_NOTIME`: If this variable is set to "1", "yes" or something else
  81. that evaluates to 'true' then no date/time stamp is logged with each log
  82. message. This is useful in environments that use systemd where access to the
  83. logs via their logging tools already gives you time stamps. Default: No -
  84. meaning that time/date is logged.
  85. * `RLOG_LOG_FILE`: Provide a filename here to determine if the logfile should
  86. be written to a file, in addition to the output stream specified in
  87. RLOG_LOG_STREAM. Default: Not set - meaning that output is not written to a
  88. file.
  89. * `RLOG_LOG_STREAM`: Use this to direct the log output to a different output
  90. stream, instead of stderr. This accepts three values: "stderr", "stdout" or
  91. "none". If either stderr or stdout is defined here AND a logfile is specified
  92. via RLOG_LOG_FILE then the output is sent to both. Default: Not set -
  93. meaning the output goes to stderr.
  94. There are two more settings, related to the configuration file, which can only
  95. be set via environment variables.
  96. * `RLOG_CONF_FILE`: If this variable is set then rlog looks for the config
  97. file at the specified location, which needs to be the path of the
  98. file. If this variable is not defined, then rlog will look for the config
  99. file in `/etc/rlog/<your-executable-name>.conf`. Therefore, by default every
  100. executable has its own config file. By setting this variable, you could
  101. force multiple processes to share the same config file.
  102. Note that with the `SetConfFile()` function you can specify a new config file
  103. programmatically at any time, even with a relative path.
  104. * `RLOG_CONF_CHECK_INTERVAL`: Number of seconds between checking whether the
  105. config file has changed. By default, this is set to 15 seconds. This means
  106. that within 15 seconds a changed logging configuration in the config file
  107. will take effect. Note that this check is only performed when a log message
  108. is actually written. If the program does nothing or doesn't log messages, the
  109. config file won't be read. If there is no config file or it has been removed
  110. then the configuration from the environment variables is used. Set this value
  111. to 0 in order to switch off the regular config file checking: The config file
  112. will then only be read once at the start.
  113. Please note! If these environment variables have incorrect or misspelled
  114. values then they will be silently ignored and a default value will be used.
  115. ## Using the config file
  116. A config file for rlog is entirely optional, since rlog works just fine even
  117. without it. However, it does provide you with a very neat feature: You can
  118. change the logging configuration of a running program from the outside and
  119. without having to restart it!
  120. When rlog is imported it starts out with the defaults described above. It then
  121. takes an initial configuration from environment variables, which may override
  122. the default values. Next, it looks for the rlog config file. If it cannot find
  123. the config file it will quietly continue without error. If the config file is
  124. found then the configuration from environment variables is combined with the
  125. configuration from the config file. More about how this combination works, and
  126. what takes precedence, in a moment.
  127. ### Config file location
  128. The path for the config file can be set via the RLOG_CONF_FILE
  129. environment variable. Absent that, rlog looks for a config file in
  130. `/etc/rlog/<your-executable-name>.conf`. This means that you can easily provide
  131. different logging configurations for each of your processes.
  132. A new config file location can also be specified at any time via the
  133. SetConfFile() function. An absolute or relative path may be specfied with that
  134. function.
  135. ### Config file format
  136. The format of the config file is simple. Each setting is referred to by the
  137. same name as the environment variable. So, your config file may look like this:
  138. # Comment lines start with a '#'
  139. RLOG_LOG_LEVEL = WARN
  140. RLOG_LOG_STREAM = stdout
  141. RLOG_TIME_FORMAT= UnixDate
  142. RLOG_LOG_FILE = /var/log/myapp.log
  143. A few notes about config file formatting:
  144. * Empty lines, or lines starting with '#' are ignored.
  145. * Leading and trailing spaces in lines are removed.
  146. * Everything after the first '=' will be taken as the value of the setting.
  147. * Leading and trailing spaces in values are removed.
  148. * Spaces or further '=' characters within values are taken as they are.
  149. ### Combining configuration from environment variables and config file
  150. Generally, environment variables take precedence. Assume you have set a log
  151. level of INFO via the RLOG_LOG_LEVEL variable. This value will be used,
  152. even if you specified DEBUG in the config file, since an explicitly set
  153. environment variable takes precedence.
  154. There are only two cases when a config file value takes precedence:
  155. 1. If you do not have an explicit value set in the environment variable. For
  156. example, if you do not have the RLOG_LOG_LEVEL environment variable defined
  157. at all, or if it is set to the empty string.
  158. 2. If you apply a '!' as prefix in the config file. That marks this value as
  159. higher priority than the environment variable. Consider the following config
  160. file as example. Here RLOG_LOG_LEVEL and RLOG_TIME_FORMAT will take
  161. precedence over whatever was defined in the environment variables.
  162. An example of using '!' in the config file:
  163. !RLOG_LOG_LEVEL=WARN
  164. RLOG_LOG_STREAM=stdout
  165. !RLOG_TIME_FORMAT=UnixDate
  166. RLOG_LOG_FILE=/var/log/myapp.log
  167. ## Updating the logging config of a running program
  168. ### From the outside: By modifying the config file
  169. Every time you log a message and at least RLOG_CONF_CHECK_INTERVAL seconds have
  170. elapsed since the last reading of the config file, rlog will automatically
  171. re-read the content of the conf file and re-apply the configuration it finds
  172. there over the initial configuration, which was based on the environment
  173. variables.
  174. You can always just delete the config file to go back to the configuration
  175. based solely on environment variables.
  176. ### From the inside: By modifying your own environment variables
  177. A running program may also change its rlog configuration on its own: The
  178. process can use the `os.Setenv()` function to modify its own environment
  179. variables and then call `rlog.UpdatEnv()` to reapply the settings
  180. from the environment variables. The `examples/example.go` file shows how this
  181. is done. But in short:
  182. // Programmatically change an rlog setting from within the program
  183. os.Setenv("RLOG_LOG_LEVEL", "DEBUG")
  184. rlog.UpdateEnv()
  185. Note that this will not change rlog behaviour if the value for this config
  186. setting was specified with a '!' in the config file.
  187. ## Per file level log and trace levels
  188. In most cases you might want to set just a single log or trace level, which is
  189. then applied to all log messages in your program. With environment variables,
  190. you would set it like this:
  191. export RLOG_LOG_LEVEL=INFO
  192. export RLOG_TRACE_LEVEL=3
  193. However, with rlog the log and trace levels can not only be configured
  194. 'globally' with a single value, but can also independently be set for the
  195. individual module files that were compiled into your executable. This is useful
  196. if enabling high trace levels or DEBUG logging for the entire executable would
  197. fill up logs or consume too many resources.
  198. For example, if your executable is compiled out of several files and one of
  199. those files is called 'example.go' then you could set log levels like this:
  200. export RLOG_LOG_LEVEL=INFO,example.go=DEBUG
  201. This sets the global log level to INFO, but for the messages originating from
  202. the module file 'example.go' it is DEBUG.
  203. Similarly, you can set trace levels for individual module files:
  204. export RLOG_TRACE_LEVEL=example.go=5,2
  205. This sets a trace level of 5 for example.go and 2 for everyone else.
  206. More examples:
  207. # DEBUG level for all files whose name starts with 'ex', WARNING level for
  208. # everyone else.
  209. export RLOG_LOG_LEVEL=WARN,ex*=DEBUG
  210. # DEBUG level for example.go, INFO for everyone else, since INFO is the
  211. # default level if nothing is specified.
  212. export RLOG_LOG_LEVEL=example.go=DEBUG
  213. # DEBUG level for example.go, no logging for anyone else.
  214. export RLOG_LOG_LEVEL=NONE,example.go=DEBUG
  215. # Multiple files' levels can be specified at once.
  216. export RLOG_LOG_LEVEL=NONE,example.go=DEBUG,foo.go=INFO
  217. # The default log level can appear anywhere in the list.
  218. export RLOG_LOG_LEVEL=example.go=DEBUG,INFO,foo.go=WARN
  219. Note that as before, if in RLOG_LOG_LEVEL no global log level is specified then
  220. INFO is assumed to be the global log level. If in RLOG_TRACE_LEVEL no global
  221. trace level is specified then -1 (no trace output) is assumed as the global
  222. trace level.
  223. ## Usage example
  224. import "github.com/romana/rlog"
  225. func main() {
  226. rlog.Debug("A debug message: For the developer")
  227. rlog.Info("An info message: Normal operation messages")
  228. rlog.Warn("A warning message: Intermittent issues, high load, etc.")
  229. rlog.Error("An error message: An error occurred, I will recover.")
  230. rlog.Critical("A critical message: That's it! I give up!")
  231. rlog.Trace(2, "A trace message")
  232. rlog.Trace(3, "An even deeper trace message")
  233. }
  234. For a more interesting example, please check out 'examples/example.go'.
  235. ## Sample output
  236. With time stamp, trace to level 2, log level WARNING, no caller info:
  237. $ export RLOG_LOG_LEVEL=WARN
  238. $ export RLOG_TRACE_LEVEL=2
  239. $ go run examples/example.go
  240. 2017-11-16T08:06:56+13:00 WARN : Warning level log message
  241. 2017-11-16T08:06:56+13:00 ERROR : Error level log message
  242. 2017-11-16T08:06:56+13:00 CRITICAL : Critical level log message
  243. 2017-11-16T08:06:56+13:00 DEBUG : You can see this message, because we changed level to DEBUG.
  244. 2017-11-16T08:06:56+13:00 TRACE(1) : Trace messages have their own numeric levels
  245. 2017-11-16T08:06:56+13:00 TRACE(1) : To see them set RLOG_TRACE_LEVEL to the cut-off number
  246. 2017-11-16T08:06:56+13:00 TRACE(1) : We're 1 levels down now...
  247. 2017-11-16T08:06:56+13:00 TRACE(2) : We're 2 levels down now...
  248. 2017-11-16T08:06:56+13:00 INFO : Reached end of recursion at level 10
  249. 2017-11-16T08:06:56+13:00 INFO : About to change log output. Check /tmp/rlog-output.log...
  250. 2017-11-16T08:06:56+13:00 INFO : Back to stderr
  251. With time stamp, log level WARN, no trace logging (switched off by unsetting
  252. the variable), but with caller info ('23730' in the example below is the
  253. process ID):
  254. $ export RLOG_CALLER_INFO=yes
  255. $ export RLOG_LOG_LEVEL=WARN
  256. $ export RLOG_TRACE_LEVEL=
  257. $ go run examples/example.go
  258. 2017-11-16T08:07:57+13:00 WARN : [21233 examples/example.go:31 (main.main)] Warning level log message
  259. 2017-11-16T08:07:57+13:00 ERROR : [21233 examples/example.go:32 (main.main)] Error level log message
  260. 2017-11-16T08:07:57+13:00 CRITICAL : [21233 examples/example.go:33 (main.main)] Critical level log message
  261. 2017-11-16T08:07:57+13:00 DEBUG : [21233 examples/example.go:42 (main.main)] You can see this message, because we changed level to DEBUG.
  262. 2017-11-16T08:07:57+13:00 INFO : [21233 examples/example.go:17 (main.someRecursiveFunction)] Reached end of recursion at level 10
  263. 2017-11-16T08:07:57+13:00 INFO : [21233 examples/example.go:52 (main.main)] About to change log output. Check /tmp/rlog-output.log...
  264. 2017-11-16T08:07:57+13:00 INFO : [21233 examples/example.go:61 (main.main)] Back to stderr
  265. Without time stamp, no trace logging, no caller info:
  266. $ export RLOG_LOG_NOTIME=yes
  267. $ export RLOG_CALLER_INFO=no
  268. $ go run examples/example.go
  269. WARN : Warning level log message
  270. ERROR : Error level log message
  271. CRITICAL : Critical level log message
  272. DEBUG : You can see this message, because we changed level to DEBUG.
  273. INFO : Reached end of recursion at level 10
  274. INFO : About to change log output. Check /tmp/rlog-output.log...
  275. INFO : Back to stderr
  276. With time stamp in RFC822 format.
  277. $ export RLOG_LOG_NOTIME=no
  278. $ export RLOG_TIME_FORMAT=RFC822
  279. $ go run examples/example.go
  280. 2017-11-16T08:08:49+13:00 WARN : Warning level log message
  281. 2017-11-16T08:08:49+13:00 ERROR : Error level log message
  282. 2017-11-16T08:08:49+13:00 CRITICAL : Critical level log message
  283. 2017-11-16T08:08:49+13:00 DEBUG : You can see this message, because we changed level to DEBUG.
  284. 2017-11-16T08:08:49+13:00 INFO : Reached end of recursion at level 10
  285. 2017-11-16T08:08:49+13:00 INFO : About to change log output. Check /tmp/rlog-output.log...
  286. 2017-11-16T08:08:49+13:00 INFO : Back to stderr
  287. With custom time stamp:
  288. $ export RLOG_TIME_FORMAT="2006/01/06 15:04:05"
  289. $ go run examples/example.go
  290. 2017-11-16T08:09:08+13:00 WARN : Warning level log message
  291. 2017-11-16T08:09:08+13:00 ERROR : Error level log message
  292. 2017-11-16T08:09:08+13:00 CRITICAL : Critical level log message
  293. 2017-11-16T08:09:08+13:00 DEBUG : You can see this message, because we changed level to DEBUG.
  294. 2017-11-16T08:09:08+13:00 INFO : Reached end of recursion at level 10
  295. 2017-11-16T08:09:08+13:00 INFO : About to change log output. Check /tmp/rlog-output.log...
  296. 2017-11-16T08:09:08+13:00 INFO : Back to stderr
  297. ## Links
  298. * [Goreportcard.com](https://goreportcard.com/report/github.com/romana/rlog)
  299. * [Godoc.com](https://godoc.org/github.com/romana/rlog)
  300. * [Gocover.io](http://gocover.io/github.com/romana/rlog)