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.

414 lines
19 KiB

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