[pacman-dev] [PATCH] Print callback messages to stderr

[Dave Reisner]

On Sat, Aug 20, 2011 at 12:05:40PM -0500, Dan McGee wrote:
> On Sat, Aug 20, 2011 at 10:16 AM, Dave Reisner <d at falconindy.com> wrote:
> > On Sat, Aug 20, 2011 at 10:11:11AM -0500, Dan McGee wrote:
> >> On Sat, Aug 20, 2011 at 7:58 AM, Dave Reisner <d at falconindy.com> wrote:
> >> > On Sat, Aug 20, 2011 at 03:15:34PM +1000, Allan McRae wrote:
> >> >> On 20/08/11 12:42, Allan McRae wrote:
> >> >> >Fixes FS#25099.
> >> >> >
> >> >> >Signed-off-by: Allan McRae<allan at archlinux.org>
> >> >> >---
> >> >> >  src/pacman/callback.c |    2 +-
> >> >> >  1 files changed, 1 insertions(+), 1 deletions(-)
> >> >> >
> >> >> >diff --git a/src/pacman/callback.c b/src/pacman/callback.c
> >> >> >index 873e3fc..5ee4e5a 100644
> >> >> >--- a/src/pacman/callback.c
> >> >> >+++ b/src/pacman/callback.c
> >> >> >@@ -690,7 +690,7 @@ void cb_log(alpm_loglevel_t level, const char *fmt, va_list args)
> >> >> >                     output = alpm_list_add(output, string);
> >> >> >             }
> >> >> >     } else {
> >> >> >-            pm_vfprintf(stdout, level, fmt, args);
> >> >> >+            pm_vfprintf(stderr, level, fmt, args);
> >> >> >     }
> >> >> >  }
> >> >> >
> >> >>
> >> >>
> >> >> This breaks some pactests because stdout/stderr output is not being
> >> >> kept in sync so timestamps with --debug get printed all over the
> >> >> place. e.g.
> >> >>
> >> >> > ./src/pacman/pacman -T glibc --debug
> >> >> <snip>
> >> >> debug: unregistering database 'local'
> >> >> debug: freeing package cache for repository 'local'
> >> >> debug: unregistering database 'allanbrokeit'
> >> >> debug: unregistering database 'kernel64'
> >> >> debug: unregistering database 'testing'
> >> >> debug: unregistering database 'core'
> >> >> debug: unregistering database 'extra'
> >> >> debug: unregistering database 'community-testing'
> >> >> debug: unregistering database 'community'
> >> >> [15:11:34] [15:11:34] [15:11:34] [15:11:34] [15:11:34] [15:11:34]
> >> >> [15:11:34] [15:11:34] [15:11:34]
> >> >>
> >> >>
> >> >
> >> > Wouldn't it make more sense to write the timestamps to stderr along with
> >> > the logging they belong to? If someone were to enable --debug and send
> >> > stderr off to a file, you'd see some really weird output.
> >>
> >> Yes- we shouldn't be trying to multiplex stderr and stdout correctly
> >> on the same line. These need to both go to the same place, and why
> >> aren't they printed in the same printf() invocation?
> >>
> >> -Dan
> >>
> >
> > Probably because we only timestamp when we build with --enable-debug so
> > its #ifdef'd. That said, I don't think the timestamps are incredibly
> > intrusive and they add value to debug output when we request it from
> > users. We could kill two birds with one stone here and get rid of
> > the #ifdef to just print the log line all at once.
> The real fix is this simple though, right?
> 
> $ git diff | cat
> diff --git a/src/pacman/util.c b/src/pacman/util.c
> index 91625a1..9c1e646 100644
> --- a/src/pacman/util.c
> +++ b/src/pacman/util.c
> @@ -1416,7 +1416,7 @@ int pm_vfprintf(FILE *stream, alpm_loglevel_t
> level, const char *format, va_list
>  		strftime(timestr, 9, "%H:%M:%S", tmp);
>  		timestr[8] = '\0';
> 
> -		printf("[%s] ", timestr);
> +		fprintf(stream, "[%s] ", timestr);
>  	}
>  #endif
> 

Yeah, assuming we don't want to get into the business of always printing
the timestamps for --debug output.

d