log: improve the most common use case (#19242)

vlib/log/README.md

@@ -3,3 +3,48 @@
 `log` provides your application logging services.
 You can log to file or to the console and use different
 logging levels, so that you are not overwhelmed by the logs.
+
+## Basic usage:
+The log module creates a default Log instance by default, and
+provides utility functions, that you can use to access it.
+Note: the default Log instance is thread safe.
+
+That makes it very convenient to use in subsystems, without having
+to thread a log instance everywhere:
+```v
+import log
+
+fn abc() {
+	log.info('some information')
+	log.warn('a warning')
+}
+
+// this will not be visible, the default log level is .info:
+log.debug('a debug message')
+
+log.set_level(.debug)
+
+// this will be now visible, the log level was changed to .debug:
+log.debug('a debug message')
+
+abc()
+```
+
+## Advanced usage:
+You can also create your own log instances, with different options
+applied to them:
+```v
+import log
+
+fn main() {
+	mut l := log.Log{}
+	l.set_level(.info)
+	l.set_full_logpath('./info.log')
+	l.log_to_console_too()
+
+	l.info('info')
+	l.warn('warn')
+	l.error('error')
+	l.fatal('fatal') // panic, marked as [noreturn]
+}
+```

vlib/log/common.v

@@ -0,0 +1,69 @@
+module log
+
+import term
+
+// Level defines the possible log levels, used by Log.set_level()
+pub enum Level {
+	disabled = 0 // lowest level, disables everything else
+	fatal // disables error, warn, info and debug
+	error // disables warn, info and debug
+	warn // disables info and debug
+	info // disables debug
+	debug
+}
+
+// LogTarget defines the possible log targets, that Log supports
+pub enum LogTarget {
+	console
+	file
+	both
+}
+
+// tag_to_cli returns the tag for log level `l` as a colored string.
+fn tag_to_cli(l Level) string {
+	return match l {
+		.disabled { '' }
+		.fatal { term.red('FATAL') }
+		.error { term.red('ERROR') }
+		.warn { term.yellow('WARN ') }
+		.info { term.white('INFO ') }
+		.debug { term.magenta('DEBUG') }
+	}
+}
+
+// tag_to_file returns the tag for log level `l` as a string.
+fn tag_to_file(l Level) string {
+	return match l {
+		.disabled { '     ' }
+		.fatal { 'FATAL' }
+		.error { 'ERROR' }
+		.warn { 'WARN ' }
+		.info { 'INFO ' }
+		.debug { 'DEBUG' }
+	}
+}
+
+// level_from_tag returns the log level from the given string.
+// It returns `none` when it does not find a match.
+pub fn level_from_tag(tag string) ?Level {
+	return match tag {
+		'DISABLED' { Level.disabled }
+		'FATAL' { Level.fatal }
+		'ERROR' { Level.error }
+		'WARN' { Level.warn }
+		'INFO' { Level.info }
+		'DEBUG' { Level.debug }
+		else { none }
+	}
+}
+
+// target_from_label returns the log target from the given string.
+// It returns `none` when it does not find a match.
+pub fn target_from_label(label string) ?LogTarget {
+	return match label {
+		'console' { LogTarget.console }
+		'file' { LogTarget.file }
+		'both' { LogTarget.both }
+		else { none }
+	}
+}

vlib/log/default.c.v

@@ -0,0 +1,42 @@
+// Copyright (c) 2019-2023 Alexander Medvednikov. All rights reserved.
+// Use of this source code is governed by an MIT license
+// that can be found in the LICENSE file.
+[has_globals]
+module log
+
+__global default_logger &Logger
+
+// TODO: remove this hack, when the language has a way to access the raw pointer to an interface value directly:
+[typedef]
+struct C.log__Logger {
+mut:
+	_object voidptr
+}
+
+// init will be called before the user's main program starts, to initialize the default logger
+fn init() {
+	default_logger = new_thread_safe_log()
+	C.atexit(deinit)
+}
+
+// deinit will be called on exit of the program and will free the memory allocated for the default logger
+fn deinit() {
+	free_logger(default_logger)
+}
+
+[manualfree]
+fn free_logger(logger &Logger) {
+	if voidptr(logger) == unsafe { nil } {
+		return
+	}
+	unsafe {
+		// C.printf(c'free_logger logger: %p\n', logger)
+		logger.free()
+		//
+		pobject := &C.log__Logger(logger)._object
+		// C.printf(c'free_logger pobject: %p\n', pobject)
+		free(pobject)
+		//
+		free(logger)
+	}
+}

vlib/log/default.v

@@ -0,0 +1,55 @@
+// Copyright (c) 2019-2023 Alexander Medvednikov. All rights reserved.
+// Use of this source code is governed by an MIT license
+// that can be found in the LICENSE file.
+module log
+
+// set_logger changes the default logger instance to the one provided by the user.
+// The existing logger will be freed, *after* the change is done.
+[manualfree]
+pub fn set_logger(logger &Logger) {
+	// C.printf(c"set_logger  logger: %p | old logger: %p\n", logger, default_logger)
+	old_logger := unsafe { default_logger }
+	default_logger = unsafe { logger }
+	free_logger(old_logger)
+}
+
+// get_logger returns a pointer to the current default logger instance
+[unsafe]
+pub fn get_logger() &Logger {
+	return default_logger
+}
+
+// get_level returns the log level of the default Logger instance
+pub fn get_level() Level {
+	return default_logger.get_level()
+}
+
+// set_level changes the log level of the default Logger instance
+pub fn set_level(level Level) {
+	default_logger.set_level(level)
+}
+
+// fatal logs a `fatal` message, using the default Logger instance
+pub fn fatal(s string) {
+	default_logger.fatal(s)
+}
+
+// error logs an `error` message, using the default Logger instance
+pub fn error(s string) {
+	default_logger.error(s)
+}
+
+// error logs a `warning` message, using the default Logger instance
+pub fn warn(s string) {
+	default_logger.warn(s)
+}
+
+// info logs an `info` message, using the default Logger instance
+pub fn info(s string) {
+	default_logger.info(s)
+}
+
+// debug logs a `debug` message, using the default Logger instance
+pub fn debug(s string) {
+	default_logger.debug(s)
+}

vlib/log/default_test.v

@@ -0,0 +1,37 @@
+import log
+import time
+
+fn test_default_log_instance() {
+	println(@FN + ' start')
+	log.info('info')
+	log.warn('warn')
+	log.error('error')
+	log.debug('no output for debug')
+	println('^^^ there should be no `no output for debug` shown above')
+	log.set_level(.debug)
+	log.debug('debug now')
+	println('^^^ there should be `debug now` shown above')
+	log.set_level(log.level_from_tag('INFO') or { log.Level.disabled })
+	log.info('info again')
+	log.set_level(log.level_from_tag('') or { log.Level.disabled })
+	log.error('no output anymore')
+	println('^^^ there should be no `no output anymore` shown above')
+	println(@FN + ' end')
+}
+
+fn log_messages(tidx int) {
+	time.sleep(2 * time.millisecond)
+	for i in 0 .. 3 {
+		log.debug('hi from thread ${tidx}')
+	}
+}
+
+fn test_default_log_instance_used_in_multiple_threads() {
+	eprintln('\n${@METHOD} start')
+	log.set_level(.debug)
+	mut threads := []thread{}
+	for tidx in 0 .. 3 {
+		threads << spawn log_messages(tidx)
+	}
+	threads.wait()
+}

vlib/log/log.v

@@ -5,82 +5,6 @@ module log
 
 import os
 import time
-import term
-
-// Level defines possible log levels used by `Log`
-pub enum Level {
-	disabled = 0
-	fatal
-	error
-	warn
-	info
-	debug
-}
-
-// LogTarget defines possible log targets
-pub enum LogTarget {
-	console
-	file
-	both
-}
-
-// tag_to_cli returns the tag for log level `l` as a colored string.
-fn tag_to_cli(l Level) string {
-	return match l {
-		.disabled { '' }
-		.fatal { term.red('FATAL') }
-		.error { term.red('ERROR') }
-		.warn { term.yellow('WARN ') }
-		.info { term.white('INFO ') }
-		.debug { term.blue('DEBUG') }
-	}
-}
-
-// tag_to_file returns the tag for log level `l` as a string.
-fn tag_to_file(l Level) string {
-	return match l {
-		.disabled { '     ' }
-		.fatal { 'FATAL' }
-		.error { 'ERROR' }
-		.warn { 'WARN ' }
-		.info { 'INFO ' }
-		.debug { 'DEBUG' }
-	}
-}
-
-// level_from_tag returns the log level from the given string if it matches.
-pub fn level_from_tag(tag string) ?Level {
-	return match tag {
-		'DISABLED' { Level.disabled }
-		'FATAL' { Level.fatal }
-		'ERROR' { Level.error }
-		'WARN' { Level.warn }
-		'INFO' { Level.info }
-		'DEBUG' { Level.debug }
-		else { none }
-	}
-}
-
-// target_from_label returns the log target from the given string if it matches.
-pub fn target_from_label(label string) ?LogTarget {
-	return match label {
-		'console' { LogTarget.console }
-		'file' { LogTarget.file }
-		'both' { LogTarget.both }
-		else { none }
-	}
-}
-
-// Logger is an interface that describes a generic Logger
-pub interface Logger {
-mut:
-	fatal(s string)
-	error(s string)
-	warn(s string)
-	info(s string)
-	debug(s string)
-	set_level(level Level)
-}
 
 // Log represents a logging object
 pub struct Log {
@@ -94,16 +18,20 @@ pub mut:
 }
 
 // get_level gets the internal logging level.
-pub fn (mut l Log) get_level() Level {
+pub fn (l &Log) get_level() Level {
 	return l.level
 }
 
-// set_level sets the internal logging to `level`.
+// set_level sets the logging level to `level`. Messges for levels above it will skipped.
+// For example, after calling log.set_level(.info), log.debug('message') will produce nothing.
+// Call log.set_level(.disabled) to turn off the logging of all messages.
 pub fn (mut l Log) set_level(level Level) {
 	l.level = level
 }
 
 // set_output_level sets the internal logging output to `level`.
+[deprecated: 'use .set_level(level) instead']
+[deprecated_after: '2023-09-30']
 pub fn (mut l Log) set_output_level(level Level) {
 	l.level = level
 }
@@ -154,14 +82,14 @@ pub fn (mut l Log) close() {
 
 // log_file writes log line `s` with `level` to the log file.
 fn (mut l Log) log_file(s string, level Level) {
-	timestamp := time.now().format_ss()
+	timestamp := time.now().format_ss_micro()
 	e := tag_to_file(level)
 	l.ofile.writeln('${timestamp} [${e}] ${s}') or { panic(err) }
 }
 
 // log_cli writes log line `s` with `level` to stdout.
 fn (l &Log) log_cli(s string, level Level) {
-	timestamp := time.now().format_ss()
+	timestamp := time.now().format_ss_micro()
 	e := tag_to_cli(level)
 	println('${timestamp} [${e}] ${s}')
 }
@@ -219,3 +147,13 @@ pub fn (mut l Log) debug(s string) {
 	}
 	l.send_output(s, .debug)
 }
+
+// free frees the given Log instance
+[unsafe]
+pub fn (mut f Log) free() {
+	unsafe {
+		f.output_label.free()
+		f.ofile.close()
+		f.output_file_name.free()
+	}
+}

vlib/log/log_test.v

@@ -1,7 +1,5 @@
 module log
 
-import time
-
 fn log_mutable_statements(mut log Log) {
 	println(@FN + ' start')
 	log.info('info')
@@ -30,10 +28,6 @@ fn logger_mutable_statements(mut log Logger) {
 	println(@FN + ' end')
 }
 
-fn delay() {
-	time.sleep(1 * time.second)
-}
-
 // Note that Log and Logger methods requires a mutable instance
 
 // new_log create and return a new Log reference
@@ -63,8 +57,8 @@ fn test_log_mutable_reference() {
 	println(@FN + ' start')
 	mut log := new_log()
 	assert typeof(log).name == '&log.Log'
-	spawn log_mutable_statements(mut log)
-	delay() // wait to finish
+	t := spawn log_mutable_statements(mut log)
+	t.wait()
 	assert true
 	println(@FN + ' end')
 }
@@ -75,8 +69,8 @@ fn test_logger_mutable_reference() {
 	mut logger := new_log_as_logger()
 	logger.set_level(.warn)
 	assert typeof(logger).name == '&log.Logger'
-	spawn logger_mutable_statements(mut logger)
-	delay() // wait to finish
+	t := spawn logger_mutable_statements(mut logger)
+	t.wait()
 	assert true
 	println(@FN + ' end')
 }

vlib/log/logger_interface.v

@@ -0,0 +1,15 @@
+module log
+
+// Logger is an interface that describes a generic Logger
+pub interface Logger {
+	get_level() Level
+mut:
+	fatal(s string)
+	error(s string)
+	warn(s string)
+	info(s string)
+	debug(s string)
+	// utility methods:
+	set_level(level Level)
+	free()
+}

vlib/log/safe_log.v

@@ -0,0 +1,79 @@
+module log
+
+import sync
+
+// ThreadSafeLog embeds Log, and adds a mutex field.
+// It uses the mutex to synchronise accesses to the embedded Log.
+pub struct ThreadSafeLog {
+	Log
+pub mut:
+	mu sync.Mutex
+}
+
+// new_thread_safe_log returns a new log structure, whose methods are safe
+// to call by multiple threads.
+pub fn new_thread_safe_log() &ThreadSafeLog {
+	mut x := &ThreadSafeLog{
+		level: .info
+	}
+	x.mu.init()
+	return x
+}
+
+// free frees the given ThreadSafeLog instance.
+[unsafe]
+pub fn (mut x ThreadSafeLog) free() {
+	unsafe {
+		x.Log.free()
+		x.mu.destroy()
+		// C.printf(c'ThreadSafeLog free(x), x: %p\n', x)
+	}
+}
+
+// set_level changes the log level
+pub fn (mut x ThreadSafeLog) set_level(level Level) {
+	x.mu.@lock()
+	x.Log.set_level(level)
+	x.mu.unlock()
+}
+
+// debug logs a debug message
+pub fn (mut x ThreadSafeLog) debug(s string) {
+	x.mu.@lock()
+	x.Log.debug(s)
+	x.mu.unlock()
+}
+
+// info logs an info messagep
+pub fn (mut x ThreadSafeLog) info(s string) {
+	x.mu.@lock()
+	x.Log.info(s)
+	x.mu.unlock()
+}
+
+// warn logs a warning message
+pub fn (mut x ThreadSafeLog) warn(s string) {
+	x.mu.@lock()
+	x.Log.warn(s)
+	x.mu.unlock()
+}
+
+// error logs an error message
+pub fn (mut x ThreadSafeLog) error(s string) {
+	x.mu.@lock()
+	x.Log.error(s)
+	x.mu.unlock()
+}
+
+// fatal logs a fatal message, and panics
+[noreturn]
+pub fn (mut x ThreadSafeLog) fatal(s string) {
+	x.mu.@lock()
+	defer {
+		// TODO: Log.fatal() is marked as noreturn, but this defer is allowed.
+		// Think whether it should be, or if it should be a compiler notice at least,
+		// since it would not be reached at all (.fatal() panics).
+		x.mu.unlock()
+	}
+	x.Log.fatal(s)
+}