1065340 - [mozversion] Update mozversion to use structured logging

Status: RESOLVED FIXED

(Testing :: Mozbase, defect)

Description

[Dave Hunt [:davehunt] [he/him] ⌚BST]

Let's update mozversion to use structured logging.

Comment 1

[Dave Hunt [:davehunt] [he/him] ⌚BST]

Attachment: Update mozversion to use structured logging. v1.0

Comment 2

[James Graham [:jgraham]]

Comment on attachment 8487133 [details] [diff] [review]
Update mozversion to use structured logging. v1.0

Review of attachment 8487133 [details] [diff] [review]:
-----------------------------------------------------------------

This isn't quite using mozlog in the idiomatic way.

::: testing/mozbase/mozversion/mozversion/mozversion.py
@@ +40,3 @@
>  
>      def __init__(self):
> +        self.logger = StructuredLogger('mozversion',

You don't want to do this.

You want to use get_default_logger() and fall back to stdlib logging if it returns None.

@@ +266,5 @@
>                                     device_serial=device_serial)
> +
> +    for (key, value) in sorted(version._info.items()):
> +        if value:
> +            version.logger.info('%s: %s' % (key, value))

Why are we destructuring this stuff to log it? Do we want a new action for this data?

@@ +283,4 @@
>      parser.add_option('--device',
>                        help='serial identifier of device to target (Firefox OS '
>                             'only)')
>      (options, args) = parser.parse_args(args)

This should add the logging command line options, and set up the logger using those options (preferably using argparse).

Comment 3

[Dave Hunt [:davehunt] [he/him] ⌚BST]

Attachment: Update mozversion to use structured logging. v2.0

(In reply to James Graham [:jgraham] from comment #2)
> ::: testing/mozbase/mozversion/mozversion/mozversion.py
> @@ +40,3 @@
> >  
> >      def __init__(self):
> > +        self.logger = StructuredLogger('mozversion',
> 
> You don't want to do this.
> 
> You want to use get_default_logger() and fall back to stdlib logging if it
> returns None.

Thanks. I knew this didn't feel right. :)

> @@ +266,5 @@
> >                                     device_serial=device_serial)
> > +
> > +    for (key, value) in sorted(version._info.items()):
> > +        if value:
> > +            version.logger.info('%s: %s' % (key, value))
> 
> Why are we destructuring this stuff to log it? Do we want a new action for
> this data?

For presentation. I'm not sure what you mean by a new action? The main purpose for the command line usage is to print the version details. For some reason I wasn't using the logging for this previously.

> @@ +283,4 @@
> >      parser.add_option('--device',
> >                        help='serial identifier of device to target (Firefox OS '
> >                             'only)')
> >      (options, args) = parser.parse_args(args)
> 
> This should add the logging command line options, and set up the logger
> using those options (preferably using argparse).

The reason I previously avoided this was bug that certain log formats are not appropriate for mozversion. I've raised this as bug 1066643.

Thanks for the review, the output is looking much nicer now - especially when used alongside other packages using structured logging.

Comment 4

[James Graham [:jgraham]]

(In reply to Dave Hunt (:davehunt) from comment #3)
> Created attachment 8488768 [details] [diff] [review]
> Update mozversion to use structured logging. v2.0
> 
> (In reply to James Graham [:jgraham] from comment #2)
> > ::: testing/mozbase/mozversion/mozversion/mozversion.py
> > @@ +40,3 @@
> > >  
> > >      def __init__(self):
> > > +        self.logger = StructuredLogger('mozversion',
> > 
> > You don't want to do this.
> > 
> > You want to use get_default_logger() and fall back to stdlib logging if it
> > returns None.
> 
> Thanks. I knew this didn't feel right. :)
> 
> > @@ +266,5 @@
> > >                                     device_serial=device_serial)
> > > +
> > > +    for (key, value) in sorted(version._info.items()):
> > > +        if value:
> > > +            version.logger.info('%s: %s' % (key, value))
> > 
> > Why are we destructuring this stuff to log it? Do we want a new action for
> > this data?
> 
> For presentation. I'm not sure what you mean by a new action? The main
> purpose for the command line usage is to print the version details. For some
> reason I wasn't using the logging for this previously.

So the question is whether the version data is something that log consumers might care about. For example if you use mozversion from a testsuite, should it be possible to include the version data as part of a report? It seems to me that it should, in which case we should add this to mozlog as a new datatype (i.e. a new "action") rather than logging it as a string.

Comment 5

[James Graham [:jgraham]]

Comment on attachment 8488768 [details] [diff] [review]
Update mozversion to use structured logging. v2.0

Review of attachment 8488768 [details] [diff] [review]:
-----------------------------------------------------------------

Can you  file a followup on adding the version information as a specific structured logging action? I think this should be machine-parsable information in the logs rather than just human-readable.

::: testing/mozbase/mozversion/mozversion/mozversion.py
@@ +279,5 @@
> +    parser = argparse.ArgumentParser(
> +        description='Display version information for Mozilla applications')
> +    parser.add_argument(
> +        '--binary',
> +        dest='binary',

No need for dest if it matches the argument name.

Comment 6

[Dave Hunt [:davehunt] [he/him] ⌚BST]

Attachment: Update mozversion to use structured logging. v2.1

Carrying r+

Comment 7

[Dave Hunt [:davehunt] [he/him] ⌚BST]

Followup raised as bug 1067423.

Comment 8

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/e060088b31df

Comment 9

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/e060088b31df