Bug 1230165

Summary:	Not possible to change logging level for ovirt-engine init script
Product:	Red Hat Enterprise Virtualization Manager	Reporter:	Pavel Zhukov <pzhukov>
Component:	ovirt-engine	Assignee:	Nobody <nobody>
Status:	CLOSED INSUFFICIENT_DATA	QA Contact:	Pavel Stehlik <pstehlik>
Severity:	medium	Docs Contact:
Priority:	unspecified
Version:	3.5.1	CC:	alonbl, amureini, didi, ecohen, lpeer, lsurette, oourfali, pzhukov, rbalakri, Rhev-m-bugs, sbonazzo, yeylon, ylavi
Target Milestone:	---
Target Release:	3.6.0
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:	integration
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2015-08-12 11:13:54 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	Integration	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Pavel Zhukov 2015-06-10 11:42:42 UTC

Description of problem:
ovirt-engine initialization script doesn't write debug info.

Version-Release number of selected component (if applicable):
rhevm-backend-3.5.1.1-0.1.el6ev.noarch

How reproducible:
100%

Actual results:
Only info message are written to logger

Expected results:
debug info should be written

Additional info:
seems like at current implementation ovirt-engine.py uses logger.name == "ovirt.engine.__main" but services.setupLogger has hardcoded name "ovirt" and propagate = False. As the result self.logger always has NOTSET level regardsless of any env variables/configs etc.
There is parameter calls logger.level in /usr/share/ovirt-engine/services/ovirt-engine/ovirt-engine-logging.properties.in but seems like it's simply ignored.

Comment 1 Pavel Zhukov 2015-06-10 12:06:57 UTC

Additional info:
  logger doesn't have handlers attached

Comment 3 Alon Bar-Lev 2015-06-10 13:06:47 UTC

I am not sure what is the difference between this and bug#1230124.

what logger? what initialization?

Comment 4 Pavel Zhukov 2015-06-10 14:19:37 UTC

(In reply to Alon Bar-Lev from comment #3)
> I am not sure what is the difference between this and bug#1230124.
It's different issue
I can work  bz#1230124 around but not this one. 
> 
> what logger? what initialization?
Logger using in ovirt-engine.py
/usr/share/ovirt-engine/services/ovirt-engine/ovirt-engine.py

setupLogger() initiliazes logger like:
    logger = logging.getLogger('ovirt')

but Daemon.logger has one with name ("ovirt.engine.__main__) which is uninitialized (level is not set, no handlers etc)

Comment 5 Alon Bar-Lev 2015-06-10 19:02:33 UTC

(In reply to Pavel Zhukov from comment #4)
> (In reply to Alon Bar-Lev from comment #3)
> > I am not sure what is the difference between this and bug#1230124.
> It's different issue
> I can work  bz#1230124 around but not this one. 
> > 
> > what logger? what initialization?
> Logger using in ovirt-engine.py
> /usr/share/ovirt-engine/services/ovirt-engine/ovirt-engine.py
> 
> setupLogger() initiliazes logger like:
>     logger = logging.getLogger('ovirt')
> 
> but Daemon.logger has one with name ("ovirt.engine.__main__) which is
> uninitialized (level is not set, no handlers etc)

please state the issue leave us to find the cause.

in python sub module inherit the parent logger.

Comment 6 Oved Ourfali 2015-06-11 12:06:05 UTC

Reducing severity until it is clear what indeed the issue is.

Comment 7 Pavel Zhukov 2015-06-18 12:06:36 UTC

Over, 
To debug deployment of engine ears I tried to change log level to debug.

The issue is pretty simple (I think). 
Code example (packaging/services/ovirt-engine/ovirt-engine.py
        # The list of applications to be deployed:
        for engineAppDir in shlex.split(self._config.get('ENGINE_APPS')):
            self.logger.debug('Deploying: %s', engineAppDir)  ## <<<!!!!
            if not os.path.isabs(engineAppDir):
                engineAppDir = os.path.join(
                    self._config.get('ENGINE_USR'),
                    engineAppDir,
                )

This messages are not logged even if OVIRT_SERVICE_DEBUG is set to debug in proper way.

This code:
        # The list of applications to be deployed:
        for engineAppDir in shlex.split(self._config.get('ENGINE_APPS')):
            self.logger.debug("INFO:: Logger level is %s" %self.logger.level )
            self.logger.info("DEBUG: Logger level is %s Handlers count %d" %(self.logger.level, len(self.logger.handlers)))


prints only second message. 
Jun 10 13:51:46 rhevm 2015-06-10 13:51:46,300 ovirt-engine: INFO _setupEngineApps:187 DEBUG: Logger level is 0 Handlers count 0

Comment 8 Yedidyah Bar David 2015-07-20 10:17:35 UTC

Now verified that this works:

echo 'export OVIRT_SERVICE_DEBUG=1' > /etc/sysconfig/ovirt-engine

echo '*.debug;mail.none;authpriv.none;cron.none /var/log/debug' > /etc/rsyslog.d/debug.conf

service rsyslog restart

service ovirt-engine restart

You then get debug messages in /var/log/debug.

Please explain what doesn't work for you. Thanks!

Comment 9 Sandro Bonazzola 2015-08-12 11:13:54 UTC

Closing with insufficient data not having answer to requested needinfo in the last 3 weeks.
Please reopen if needed info can be provided.

Comment 10 Yedidyah Bar David 2016-03-23 15:46:55 UTC

(In reply to Yedidyah Bar David from comment #8)
> Now verified that this works:
> 
> echo 'export OVIRT_SERVICE_DEBUG=1' > /etc/sysconfig/ovirt-engine

For systemd, should be:

echo 'OVIRT_SERVICE_DEBUG=1' > /etc/sysconfig/ovirt-engine

> 
> echo '*.debug;mail.none;authpriv.none;cron.none /var/log/debug' >
> /etc/rsyslog.d/debug.conf
> 
> service rsyslog restart
> 
> service ovirt-engine restart
> 
> You then get debug messages in /var/log/debug.
> 
> Please explain what doesn't work for you. Thanks!