Bug 1457468

Targeting 4.2.

Yaniv, any specific items you would like to see there? it doesn't has any functional aspects, so medium priority from my side, unless certain critical info is missing.

(In reply to Moran Goldboim from comment #2)
> Yaniv, any specific items you would like to see there? it doesn't has any
> functional aspects, so medium priority from my side, unless certain critical
> info is missing.

Today they provide no value whatsoever (see above). They flood and do not provide value. For example (note the time, all in the same 0.01 second!):
15:28:30,163::listener::186::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(handle) Connection closed
Thread-3294586::INFO::2017-05-29 15:28:30,165::listener::134::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(setup) Connection established
Thread-3294586::INFO::2017-05-29 15:28:30,167::listener::186::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(handle) Connection closed
Thread-3294587::INFO::2017-05-29 15:28:30,167::listener::134::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(setup) Connection established
Thread-3294587::INFO::2017-05-29 15:28:30,168::listener::186::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(handle) Connection closed
Thread-3294588::INFO::2017-05-29 15:28:30,168::listener::134::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(setup) Connection established
Thread-3294588::INFO::2017-05-29 15:28:30,169::listener::186::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(handle) Connection closed
Thread-3294589::INFO::2017-05-29 

This is critical for supportability.

It may be that the underlying infra is wrong (why are we opening-closing connections that fast, with no sleep whatsoever, etc.).

After successful deployment of ovirt-hosted-engine-setup-2.2.0-0.0.master.20170913082146.git120d800.el7.centos.noarch, while using ovirt-engine-appliance-4.2-20170916.1.el7.centos.noarch, I'm still getting the same type of logging from /var/log/ovirt-hosted-engine-ha/broker.log e.g.

Thread-3::INFO::2017-09-17 15:57:36,693::mem_free::50::mem_free.MemFree::(action) memFree: 23950
Thread-3::INFO::2017-09-17 15:57:46,739::mem_free::50::mem_free.MemFree::(action) memFree: 23925

Thread-5::INFO::2017-09-17 12:56:41,624::engine_health::55::engine_health.CpuLoadNoEngine::(action) VM not on this host

I didn't seen this type though: "15:28:30,173::listener::134::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(setup) Connection established", it didn't appeared on my environment after deployment.

Moving back to assigned, as I don't see the difference between logging in previous version vs. current.

You should not see anymore useless lines like:

15:28:30,167::listener::134::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(setup) Connection established
Thread-3294587::INFO::2017-05-29 15:28:30,168::listener::186::ovirt_hosted_engine_ha.broker.listener.ConnectionHandler::(handle) Connection closed

Could you please confirm, that they are still in logs?


Other lines, like monitors reporting their values, should stay in logs, as they contain important runtime information.

(In reply to Denis Chaplygin from comment #5)
> You should not see anymore useless lines like:
> 
> 15:28:30,167::listener::134::ovirt_hosted_engine_ha.broker.listener.
> ConnectionHandler::(setup) Connection established
> Thread-3294587::INFO::2017-05-29
> 15:28:30,168::listener::186::ovirt_hosted_engine_ha.broker.listener.
> ConnectionHandler::(handle) Connection closed
> 
> Could you please confirm, that they are still in logs?
> 
> 
> Other lines, like monitors reporting their values, should stay in logs, as
> they contain important runtime information.

As I already reported previously, these lines are not happening.
From initial bug report I saw that Yaniv also wanted to get better logging for these lines:
Thread-23::INFO::2017-05-29 15:28:55,687::mem_free::50::mem_free.MemFree::(action) memFree: 511358
Thread-25::INFO::2017-05-29 15:28:59,684::engine_health::55::engine_health.CpuLoadNoEngine::(action) VM not on this host

In case that current fix isolating only "15:28:30,167::listener::134::ovirt_hosted_engine_ha.broker.listener.
> ConnectionHandler::(setup) Connection established" and this is fine, then we may move to verified.

Yaniv, may you provide your input on this please?

(In reply to Nikolai Sednev from comment #6)
> (In reply to Denis Chaplygin from comment #5)
> > You should not see anymore useless lines like:
> > 
> > 15:28:30,167::listener::134::ovirt_hosted_engine_ha.broker.listener.
> > ConnectionHandler::(setup) Connection established
> > Thread-3294587::INFO::2017-05-29
> > 15:28:30,168::listener::186::ovirt_hosted_engine_ha.broker.listener.
> > ConnectionHandler::(handle) Connection closed
> > 
> > Could you please confirm, that they are still in logs?
> > 
> > 
> > Other lines, like monitors reporting their values, should stay in logs, as
> > they contain important runtime information.
> 
> As I already reported previously, these lines are not happening.
> From initial bug report I saw that Yaniv also wanted to get better logging
> for these lines:
> Thread-23::INFO::2017-05-29
> 15:28:55,687::mem_free::50::mem_free.MemFree::(action) memFree: 511358
> Thread-25::INFO::2017-05-29
> 15:28:59,684::engine_health::55::engine_health.CpuLoadNoEngine::(action) VM
> not on this host
> 
> In case that current fix isolating only
> "15:28:30,167::listener::134::ovirt_hosted_engine_ha.broker.listener.
> > ConnectionHandler::(setup) Connection established" and this is fine, then we may move to verified.
> 
> Yaniv, may you provide your input on this please?

Per comment 5 they should stay in the logs. Moving to VERIFIED.
Thanks!

This bugzilla is included in oVirt 4.2.0 release, published on Dec 20th 2017.

Since the problem described in this bug report should be
resolved in oVirt 4.2.0 release, published on Dec 20th 2017, it has been closed with a resolution of CURRENT RELEASE.

If the solution does not work for you, please open a new bug report.