Re: [openstack-dev] [nova] loss of WSGI request logs with request-id under uwsgi/apache - PLAN OF ACTION
On 07/20/2017 09:27 AM, Sean Dague wrote: > Here is a starting patch that gets us close (no tests yet) - > https://review.openstack.org/#/c/485602/ - it's going to require a paste > change, which is less than idea. After some #openstack-nova IRC discussion this morning, we decided the following: 1) we need something like this! 2) changing paste.ini, and having an upgrade note, is not the end of the world. If you are cutting over from eventlet to uwsgi/apache, you are going to need to do other configuration management changes in your environment, adding this to the mix would be another part of that manual change. 3) try to get this to go silent if enabled under eventlet (to prevent duplicate lines) as a stretch goal (which I think I just got working). -Sean -- Sean Dague http://dague.net __ OpenStack Development Mailing List (not for usage questions) Unsubscribe: openstack-dev-requ...@lists.openstack.org?subject:unsubscribe http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev
Re: [openstack-dev] [nova] loss of WSGI request logs with request-id under uwsgi/apache
On 07/19/2017 06:28 PM, Matt Riedemann wrote: > On 7/19/2017 6:16 AM, Sean Dague wrote: >> We hit a similar issue with placement, and added custom >> paste middleware for that. Maybe we need to consider a similar thing >> here, that would only emit if running under uwsgi/apache? > > For example, this: > > http://logs.openstack.org/97/479497/3/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/5a0fb17/logs/screen-placement-api.txt.gz#_Jul_19_03_41_21_429324 > > > If it's not optional for placement, why would we make it optional for > the compute API? Would turning it on always make it log the request IDs > twice or something? > > Is this a problem for glance/cinder/neutron/keystone and whoever else is > logging request IDs in the API? Here is a starting patch that gets us close (no tests yet) - https://review.openstack.org/#/c/485602/ - it's going to require a paste change, which is less than idea. -Sean -- Sean Dague http://dague.net __ OpenStack Development Mailing List (not for usage questions) Unsubscribe: openstack-dev-requ...@lists.openstack.org?subject:unsubscribe http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev
Re: [openstack-dev] [nova] loss of WSGI request logs with request-id under uwsgi/apache
On 07/19/2017 06:28 PM, Matt Riedemann wrote: > On 7/19/2017 6:16 AM, Sean Dague wrote: >> We hit a similar issue with placement, and added custom >> paste middleware for that. Maybe we need to consider a similar thing >> here, that would only emit if running under uwsgi/apache? > > For example, this: > > http://logs.openstack.org/97/479497/3/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/5a0fb17/logs/screen-placement-api.txt.gz#_Jul_19_03_41_21_429324 Placement can't run under eventlet, so there was no reason to make it optional (or to not emit if we're under eventlet). I'm fine with it being mandatory, but for niceness not run when we're under eventlet server. > If it's not optional for placement, why would we make it optional for > the compute API? Would turning it on always make it log the request IDs > twice or something? That was my concern. Right now the path for logging the INFO request lines comes from following: * http server is started via oslo.service * oslo.service is a wrapper around eventlet.wsgi * eventlet.wsgi takes a log object in, and uses that for logging * that log object is our log object, and it uses our .info method to emit Which means it has the context, which includes things like global request-id, request-id, project, user, domain, etc. > Is this a problem for glance/cinder/neutron/keystone and whoever else is > logging request IDs in the API? It will be the same issue for anyone else going from oslo.service -> wsgi. I had forgotten that bit of the problem when we did our cut over, but it's a pretty big problem, and it actually makes most of the global request id work somewhat pointless, because we threw away the REST call tracing entirely if people run under the uwsgi/apache model. -Sean -- Sean Dague http://dague.net __ OpenStack Development Mailing List (not for usage questions) Unsubscribe: openstack-dev-requ...@lists.openstack.org?subject:unsubscribe http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev
Re: [openstack-dev] [nova] loss of WSGI request logs with request-id under uwsgi/apache
On 07/19/2017 09:46 PM, Matt Riedemann wrote: > On 7/19/2017 6:16 AM, Sean Dague wrote: >> I was just starting to look through some logs to see if I could line up >> request ids (part of global request id efforts), when I realized that in >> the process to uwsgi by default, we've entirely lost the INFO wsgi >> request logs. :( >> >> Instead of the old format (which was coming out of oslo.service) we get >> the following - >> http://logs.openstack.org/97/479497/3/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/5a0fb17/logs/screen-n-api.txt.gz#_Jul_19_03_44_58_233532 >> >> >> >> That definitely takes us a step backwards in understanding the world, as >> we lose our request id on entry that was extremely useful to match up >> everything. We hit a similar issue with placement, and added custom >> paste middleware for that. Maybe we need to consider a similar thing >> here, that would only emit if running under uwsgi/apache? >> >> Thoughts? >> >> -Sean >> > > I'm noticing some other weirdness here: > > http://logs.openstack.org/65/483565/4/check/gate-tempest-dsvm-py35-ubuntu-xenial/9921636/logs/screen-n-sch.txt.gz#_Jul_19_20_17_18_801773 > > > The first part of the log message got cut off: > > Jul 19 20:17:18.801773 ubuntu-xenial-infracloud-vanilla-9950433 > nova-scheduler[22773]: > -01dc-4de3-9da7-8eb3de9e305e,vcpu_model=VirtCPUModel,vcpus=1,vm_mode=None,vm_state='active'), > 'a4eba582-075a-4200-ae6f-9fc7797c95dd': No, it's the log message exceeded buffer limits in systemd journal, and was split across lines. It starts 2 more lines up. -Sean -- Sean Dague http://dague.net __ OpenStack Development Mailing List (not for usage questions) Unsubscribe: openstack-dev-requ...@lists.openstack.org?subject:unsubscribe http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev
Re: [openstack-dev] [nova] loss of WSGI request logs with request-id under uwsgi/apache
On 7/19/2017 6:16 AM, Sean Dague wrote: I was just starting to look through some logs to see if I could line up request ids (part of global request id efforts), when I realized that in the process to uwsgi by default, we've entirely lost the INFO wsgi request logs. :( Instead of the old format (which was coming out of oslo.service) we get the following - http://logs.openstack.org/97/479497/3/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/5a0fb17/logs/screen-n-api.txt.gz#_Jul_19_03_44_58_233532 That definitely takes us a step backwards in understanding the world, as we lose our request id on entry that was extremely useful to match up everything. We hit a similar issue with placement, and added custom paste middleware for that. Maybe we need to consider a similar thing here, that would only emit if running under uwsgi/apache? Thoughts? -Sean I'm noticing some other weirdness here: http://logs.openstack.org/65/483565/4/check/gate-tempest-dsvm-py35-ubuntu-xenial/9921636/logs/screen-n-sch.txt.gz#_Jul_19_20_17_18_801773 The first part of the log message got cut off: Jul 19 20:17:18.801773 ubuntu-xenial-infracloud-vanilla-9950433 nova-scheduler[22773]: -01dc-4de3-9da7-8eb3de9e305e,vcpu_model=VirtCPUModel,vcpus=1,vm_mode=None,vm_state='active'), 'a4eba582-075a-4200-ae6f-9fc7797c95dd': -- Thanks, Matt __ OpenStack Development Mailing List (not for usage questions) Unsubscribe: openstack-dev-requ...@lists.openstack.org?subject:unsubscribe http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev
Re: [openstack-dev] [nova] loss of WSGI request logs with request-id under uwsgi/apache
On 7/19/2017 6:16 AM, Sean Dague wrote: We hit a similar issue with placement, and added custom paste middleware for that. Maybe we need to consider a similar thing here, that would only emit if running under uwsgi/apache? For example, this: http://logs.openstack.org/97/479497/3/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/5a0fb17/logs/screen-placement-api.txt.gz#_Jul_19_03_41_21_429324 If it's not optional for placement, why would we make it optional for the compute API? Would turning it on always make it log the request IDs twice or something? Is this a problem for glance/cinder/neutron/keystone and whoever else is logging request IDs in the API? -- Thanks, Matt __ OpenStack Development Mailing List (not for usage questions) Unsubscribe: openstack-dev-requ...@lists.openstack.org?subject:unsubscribe http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev
