Sender: =?UTF-8?Q?Timo_Ter=C3=A4s?= <timo.teras@gmail.com>
Date: Fri, 28 Jun 2013 13:35:31 +0300
From: Timo Teras <timo.teras@iki.fi>
To: Dubiousjim <dubiousjim@gmail.com>
Cc: alpine-devel@lists.alpinelinux.org
Subject: Re: [alpine-devel] [PATCH 1/8] add logging infrastructure
Message-ID: <20130628133531.35c9e507@vostro>
In-Reply-To: <370646a3cbe979d2b309a44f86d06e50cc603f3c.1372372343.git.dubiousjim@gmail.com>
References: <cover.1372372343.git.dubiousjim@gmail.com>
	<370646a3cbe979d2b309a44f86d06e50cc603f3c.1372372343.git.dubiousjim@gmail.com>
Precedence: list
Mime-Version: 1.0
Content-Type: text/plain; charset=US-ASCII
Content-Transfer-Encoding: 7bit

On Thu, 27 Jun 2013 18:35:42 -0400
Dubiousjim <dubiousjim@gmail.com> wrote:

>  src/apk.c          |  4 ++++
>  src/apk_database.h |  2 +-
>  src/apk_defines.h  |  1 +
>  src/apk_print.h    | 12 ++++++++----
>  src/database.c     | 17 +++++++++++++++++
>  src/print.c        | 36 ++++++++++++++++++++++++++++++------
>  6 files changed, 61 insertions(+), 11 deletions(-)

I do like the feature here, but not the implementation as-is.

> 
> diff --git a/src/apk.c b/src/apk.c
> index c3709e7..4bac0ba 100644
> --- a/src/apk.c
> +++ b/src/apk.c
> @@ -46,6 +46,7 @@ static struct apk_option generic_options[] = {
>  				required_argument, "DIR" },
>  	{ 'X', "repository",	"Use packages from REPO",
>  				required_argument, "REPO" },
> +	{ 0x113, "no-log",      "Don't write to log" },
>  	{ 0x101, "progress",	"Show a progress bar" },
>  	{ 0x10f, "progress-fd",	"Write progress to fd",

This might have non-wanted implications on the tmpfs initramfs
bootstrap.

I've been thinking that we need some flag for apk to indicate that it's
the tmpfs initial initramfs call to get proper defaults for flags like
these.

Also wondering if we need to support flags specially in the options
handling and always have both "foo" and "no-foo" long options.

> required_argument, "FD" }, { 0x110, "no-progress",	"Disable
> progress bar even for TTYs" }, @@ -401,6 +402,9 @@ int main(int argc,
> char **argv) case 0x112:
>  			dbopts.arch = optarg;
>  			break;
> +		case 0x113:
> +			apk_flags |= APK_NO_LOG;
> +			break;
>  #ifdef TEST_MODE
>  		case 0x200:
>  			*apk_string_array_add(&test_repos) = (char*)
> optarg; diff --git a/src/apk_database.h b/src/apk_database.h
> index 3d557bd..dd975f9 100644
> --- a/src/apk_database.h
> +++ b/src/apk_database.h
> @@ -130,7 +130,7 @@ struct apk_repository_tag {
>  
>  struct apk_database {
>  	char *root;
> -	int root_fd, lock_fd, cache_fd, keys_fd;
> +	int root_fd, lock_fd, cache_fd, keys_fd, log_fd;
>  	unsigned num_repos, num_repo_tags;
>  	const char *cache_dir;
>  	char *cache_remount_dir;
> diff --git a/src/apk_defines.h b/src/apk_defines.h
> index 00a6f9e..71f9fdf 100644
> --- a/src/apk_defines.h
> +++ b/src/apk_defines.h
> @@ -65,6 +65,7 @@ extern char **apk_argv;
>  #define APK_INTERACTIVE		0x0400
>  #define APK_NO_NETWORK		0x1000
>  #define APK_OVERLAY_FROM_STDIN	0x2000
> +#define APK_NO_LOG              0x8000
>  
>  /* default architecture for APK packages. */
>  #if defined(__x86_64__)
> diff --git a/src/apk_print.h b/src/apk_print.h
> index 590b8f3..4a45b73 100644
> --- a/src/apk_print.h
> +++ b/src/apk_print.h
> @@ -14,13 +14,17 @@
>  
>  #include "apk_blob.h"
>  
> -#define apk_error(args...)	do { apk_log("ERROR: ", args); }
> while (0) -#define apk_warning(args...)	do { if (apk_verbosity
> > 0) { apk_log("WARNING: ", args); } } while (0) -#define
> > apk_message(args...)	do { if (apk_verbosity > 0)
> > { apk_log(NULL, args); } } while (0)
> +#define apk_error(args...)	do { apk_log(1, 0, "ERROR: ",
> args); } while (0) +#define apk_lerror(args...)	do
> { apk_log(1, apk_log_fd, "ERROR: ", args); } while (0) +#define
> apk_warning(args...)	do { apk_log(apk_verbosity, 0, "WARNING:
> ", args); } while (0) +#define apk_lwarning(args...)	do
> { apk_log(apk_verbosity, apk_log_fd, "WARNING: ", args); } while (0)
> +#define apk_message(args...)	do { apk_log(apk_verbosity, 0,
> NULL, args); } while (0) +#define apk_lmessage(args...)	do
> { apk_log(apk_verbosity, apk_log_fd, NULL, args); } while (0) extern
> int apk_progress_fd; +extern int apk_log_fd; 
> -void apk_log(const char *prefix, const char *format, ...);
> +void apk_log(int verbosity, int log_fd, const char *prefix, const
> char *format, ...); const char *apk_error_str(int error);

The inline apk_verbosity compare is there intentionally, and while in
the current code base it's not critical due to performance, I'd still
like to keep it there.

I'd likely want variants that get apk_database as parameter; or perhaps
separate apk_log_options that contains the verbosity and the logging fd
amongst other things. Might be an idea to add later logging to syslog
too.

I would also like to separate debugging message to go to separate fd.
solver.c with debug messages compiled on will fail the test cases - I'd
like those to be redirectable to separate file.

Will currently the code works with single apk_database, it is later on
perfectly reasonable to have two apk_databases open. Due to that I'd
like to keep apk_log et al not using more globals then the current ones.

>  void apk_reset_screen_width(void);
> diff --git a/src/database.c b/src/database.c
> index 33f7af8..5f1ca25 100644
> --- a/src/database.c
> +++ b/src/database.c
> @@ -45,6 +45,7 @@ enum {
>  
>  int apk_verbosity = 1;
>  unsigned int apk_flags = 0;
> +int apk_log_fd = 0;
>  
>  static apk_blob_t tmpprefix = { .len=8, .ptr = ".apknew." };
>  
> @@ -54,6 +55,7 @@ static const char * const apk_static_cache_dir =
> "var/cache/apk"; static const char * const apk_linked_cache_dir =
> "etc/apk/cache"; 
>  static const char * const apk_lock_file = "var/lock/apkdb";
> +static const char * const apk_log_file = "var/log/apk";
>  
>  static const char * const apk_world_file = "etc/apk/world";
>  static const char * const apk_world_file_tmp = "etc/apk/world.new";
> @@ -1326,6 +1328,7 @@ static int apk_db_create(struct apk_database
> *db) mkdirat(db->root_fd, "var/cache/apk", 0755);
>  	mkdirat(db->root_fd, "var/cache/misc", 0755);
>  	mkdirat(db->root_fd, "var/lock", 0755);
> +	mkdirat(db->root_fd, "var/log", 0755);
>  
>  	fd = openat(db->root_fd, apk_world_file,
> O_CREAT|O_RDWR|O_TRUNC|O_CLOEXEC, 0644); if (fd < 0)
> @@ -1402,6 +1405,7 @@ static void relocate_database(struct
> apk_database *db) mkdirat(db->root_fd, "var/cache/apk", 0755);
>  	mkdirat(db->root_fd, "var/cache/misc", 0755);
>  	mkdirat(db->root_fd, "var/lock", 0755);
> +	mkdirat(db->root_fd, "var/log", 0755);
>  	apk_move_file(db->root_fd, apk_world_file_old,
> apk_world_file); apk_move_file(db->root_fd, apk_scripts_file_old,
> apk_scripts_file); apk_move_file(db->root_fd, apk_triggers_file_old,
> apk_triggers_file); @@ -1555,6 +1559,15 @@ int apk_db_open(struct
> apk_database *db, struct apk_db_options *dbopts) } else
>  				goto ret_errno;
>  		}
> +		if (!(apk_flags & APK_NO_LOG)) {
> +			db->log_fd = openat(db->root_fd,
> apk_log_file,
> +					    O_CREAT | O_WRONLY |
> O_CLOEXEC | O_APPEND, 0644);
> +			if (db->log_fd < 0) {
> +				msg = "Unable to create log";
> +				goto ret_errno;
> +			}
> +			apk_log_fd = db->log_fd;
> +		}
>  		if (write_arch)
>  			apk_blob_to_file(db->root_fd, apk_arch_file,
> *db->arch, APK_BTF_ADD_EOL); }
> @@ -1772,6 +1785,10 @@ void apk_db_close(struct apk_database *db)
>  		close(db->cache_fd);
>  	if (db->root_fd)
>  		close(db->root_fd);
> +	if (db->log_fd) {
> +		close(db->log_fd);
> +		apk_log_fd = 0;
> +	}
>  	if (db->lock_fd)
>  		close(db->lock_fd);
>  	if (db->root != NULL)
> diff --git a/src/print.c b/src/print.c
> index 6d00064..8ab2b50 100644
> --- a/src/print.c
> +++ b/src/print.c
> @@ -139,16 +139,40 @@ const char *apk_error_str(int error)
>  	}
>  }
>  
> -void apk_log(const char *prefix, const char *format, ...)
> +void apk_log(int verbosity, int log_fd, const char *prefix, const
> char *format, ...) {
>  	va_list va;
> -
> -	if (prefix != NULL)
> -		fprintf(stderr, "%s", prefix);
> +	char timestamp[20];
> +	time_t t;
> +	struct tm *tmp = NULL;
> +
> +	if (log_fd) {
> +		t = time(NULL);
> +		tmp = localtime(&t);
> +		if (tmp != NULL) {
> +			if (strftime(timestamp, sizeof(timestamp),
> "%b %d %T", tmp) == 0) {
> +				fprintf(stderr, "ERROR: Unable to
> create timestamp, logging failed\n");
> +				tmp = NULL;
> +			} else
> +				dprintf(log_fd, "%s ", timestamp);
> +		}
> +	}
> +	if (prefix != NULL) {
> +		if (tmp != NULL)
> +			dprintf(log_fd, "%s", prefix);
> +		if (verbosity > 0)
> +			fprintf(stderr, "%s", prefix);
> +	}
>  	va_start(va, format);
> -	vfprintf(stderr, format, va);
> +	if (tmp != NULL)
> +		vdprintf(log_fd, format, va);
> +	if (verbosity > 0)
> +		vfprintf(stderr, format, va);
>  	va_end(va);
> -	fprintf(stderr, "\n");
> +	if (tmp != NULL)
> +		dprintf(log_fd, "\n");
> +	if (verbosity > 0)
> +		fprintf(stderr, "\n");
>  	apk_progress_force = 1;
>  }

I wonder if it is worth snprintf:ing once to a buffer with the
timestamp, and then writing to the targets where the message goes.

- Timo


---
Unsubscribe:  alpine-devel+unsubscribe@lists.alpinelinux.org
Help:         alpine-devel+help@lists.alpinelinux.org
---