Open Stack

Hi,

I opened LP for that [1] and I will propose some fix for it ASAP.

On Mon, Aug 17, 2020 at 10:50:15AM -0700, melanie witt wrote:
> Hi all,
> 
> Recently we've noticed elastic search indexing is behind 115 hours [1] and we looked for abnormally large log files being generated in the gate.
> 
> We found that the q-svc log is very large, one example being 71.6M [2]. There is a lot of Time-Cost profiling output in the log, like this:
> 
> Aug 17 14:22:23.210076 ubuntu-bionic-ovh-bhs1-0019298855 neutron-server[5168]: DEBUG neutron_lib.utils.helpers [req-75719db1-4abf-4500-bb0a-6d24e82cd4fd req-d88e7052-7da9-4bc9-8b35-5730ae76dcad service neutron] Time-cost: call 48e628cc-8c3a-408d-a36f-b219524480e0 function apply_funcs start {{(pid=5554) wrapper /usr/local/lib/python3.6/dist-packages/neutron_lib/utils/helpers.py:218}}
> 
> We saw that there was a recent-ish change to remove some of the profiling output [3] but it was only for the get_objects method.
> 
> Looking at the total number of lines in the file vs the number of lines without apply_funcs Time-Cost output:
> 
> $ wc -l screen-q-svc.txt
> 186387 screen-q-svc.txt
> 
> $ grep -v "function apply_funcs" screen-q-svc.txt|wc -l
> 102593
> 
> Would it be possible to remove this profiling output from the gate log to give elastic search indexing a better chance at keeping up? Or is there something else I've missed that could be made less verbose in the logging?
> 
> Thanks for your help.
> 
> Cheers,
> -melanie
> 
> [1] http://status.openstack.org/elastic-recheck
> [2] https://b6ba3b9af8fd7de57099-18aa39cea11f738aa67ebd6bc9fb5e4c.ssl.cf2.rackcdn.com/744958/4/check/tempest-integrated-compute/4421bf9/controller/logs/screen-q-svc.txt
> [3] https://review.opendev.org/741540
> 

[1] https://bugs.launchpad.net/neutron/+bug/1892017

-- 
Slawek Kaplonski
Principal software engineer
Red Hat