Re: [Qemu-devel] [PATCH] qemu.py: Call logging.basicConfig() automatically

["Lukáš Doktor" <ldoktor@redhat.com>]

[-- Attachment #1: Type: text/plain, Size: 3153 bytes --]

Dne 21.9.2017 v 18:22 Eduardo Habkost napsal(a):
> Not all scripts using qemu.py configure the Python logging
> module, and end up generating a "No handlers could be found for
> logger" message instead of actual log messages.
> 
> To avoid requiring every script using qemu.py to configure
> logging manually, call basicConfig() when creating a QEMUMachine
> object.  This won't affect scripts that already set up logging,
> but will ensure that scripts that don't configure logging keep
> working.
> 
> Reported-by: Kevin Wolf <kwolf@redhat.com>
> Fixes: 4738b0a85a0c2031fddc71b51cccebce0c4ba6b1
> Signed-off-by: Eduardo Habkost <ehabkost@redhat.com>
> ---
>  scripts/qemu.py | 3 +++
>  1 file changed, 3 insertions(+)
> 
> diff --git a/scripts/qemu.py b/scripts/qemu.py
> index 5e02dd8e78..73d6031e02 100644
> --- a/scripts/qemu.py
> +++ b/scripts/qemu.py
> @@ -89,6 +89,9 @@ class QEMUMachine(object):
>          self._qmp = None
>          self._qemu_full_args = None
>  
> +        # just in case logging wasn't configured by the main script:
> +        logging.basicConfig(level=(logging.DEBUG if debug else logging.WARN))
> +
>      def __enter__(self):
>          return self
>  
> 

Hello Eduardo,

what troubles me about this approach is it enables debug based on first instance arguments, while other instances might use a different value. Ideally we should create `"%s.%s" % (__name__, id(self))` logger per each instance and only set this log level there. The same would have to happen for QMP and other modules, which should either use the configured instance's logger, or create own logger as a child of that logger and optionally tweaked the levels there (if necessary), so the result would be:

QEMUMachine(debug=True)
QEMUMachine(debug=False)

qemu.139855463298312: DEBUG: Starting instance 139855463298312
qemu.139855463298312.qmp: DEBUG: Initializing connection to qmp
qemu.139855463298312: INFO: Started qemu cmd...
qemu.139855463216512: INFO: Started qemu cmd...

while with your patch you get:

qemu.139855463298312: DEBUG: Starting instance 139855463298312
qemu.139855463298312.qmp: DEBUG: Initializing connection to qmp
qemu.139855463298312: INFO: Started qemu cmd...
qemu.139855463216512: DEBUG: Starting instance 139855463298312
qemu.139855463216512.qmp: DEBUG: Initializing connection to qmp
qemu.139855463216512: INFO: Started qemu cmd...


But mine approach would break other scripts that call logging.baseConfig (eg. qemu/device-crash-test), because they rely on root logger's log-level (because `import qemu` would have issued logging.baseConfig). I can't come-up with a better alternative and this indeed fixes the issues with scripts using qemu without initializing loggers so considering this as a **hotfix**:

Acked-by: Lukáš Doktor <ldoktor@redhat.com>

But we should focus on fixing all the entry points (either initialize from all of them, or force-create the root logger based on the entry-point requirements). Kevin, could you please share the exact reproducer? I used a custom file importing QEMUMachine() with a some added LOG calls.

Lukáš


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 502 bytes --]