yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1498565] [NEW] remove imported library DEBUG statements from neutron logs

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Ryan Moats <rmoats@xxxxxxxxxx>
Date: Tue, 22 Sep 2015 16:03:56 -0000
Reply-to: Bug 1498565 <1498565@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Today, neutron log files include debug statements from imported
libraries that are not particularly useful.

Selected examples:

q-agt.log:
--------

2015-09-21 05:58:50.765 ^[[00;32mDEBUG oslo_rootwrap.client
[^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mPopen for ['sudo',
'/usr/local/bin/neutron-rootwrap-daemon', '/etc/neutron/rootwrap.conf']
command has been instantiated^[[00m ^[[00;33mfrom (pid=17560)
_initialize /usr/local/lib/python2.7/dist-
packages/oslo_rootwrap/client.py:76^[[00m

2015-09-21 05:58:51.666 ^[[00;32mDEBUG
oslo_messaging._drivers.amqpdriver [^[[01;36mreq-9ae26b0d-cfb4-4417
-b54f-13970adc62ed ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mMSG_ID
is 6430fa63de2f46afa0d19e30db724fa7^[[00m ^[[00;33mfrom (pid=17560)
_send /usr/local/lib/python2.7/dist-
packages/oslo_messaging/_drivers/amqpdriver.py:392^[[00m

2015-09-21 05:58:51.231 ^[[00;32mDEBUG oslo_messaging._drivers.amqp
[^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mPool creating new
connection^[[00m ^[[00;33mfrom (pid=17560) create
/usr/local/lib/python2.7/dist-
packages/oslo_messaging/_drivers/amqp.py:103^[[00m

q-l3.log:

2015-08-27 11:19:18.027 ^[[00;32mDEBUG oslo_concurrency.lockutils [^[[01
;36mreq-c6a9f3dc-8254-4634-ae2b-0c5b916a70bc ^[[00;36mNone
None^[[00;32m] ^[[01;35m^[[00;32mAcquired semaphore
"singleton_lock"^[[00m ^[[00;33mfrom (pid=20186) lock
/usr/local/lib/python2.7/dist-
packages/oslo_concurrency/lockutils.py:198^[[00m

2015-08-27 11:19:18.111 ^[[00;32mDEBUG oslo_messaging._drivers.amqpdriver [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMSG_ID is e1322001df9c4886b94c8270d053f100^[[00m ^[[00;33mfrom (pid=20186) _send /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:392^[[00m
/

2015-08-27 11:19:18.170 ^[[00;32mDEBUG oslo_service.loopingcall
[^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mFixed interval looping call
'neutron.agent.l3.agent.L3NATAgentWithStateReport._report_state'
sleeping for 29.94 seconds^[[00m ^[[00;33mfrom (pid=20186) _run_loop
/usr/local/lib/python2.7/dist-
packages/oslo_service/loopingcall.py:121^[[00m

q-svc.log:

2015-09-18 11:59:24.674 ^[[00;32mDEBUG keystoneclient.session
[^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mREQ: curl -g -i --cacert
"/opt/stack/data/ca-bundle.pem" -X GET http://10.18.0.21:35357 -H
"Accept: application/json" -H "User-Agent: neutron/7.0.0.0b4.dev217
keystonemiddleware.auth_token/2.2.0"^[[00m ^[[00;33mfrom (pid=10920)
_http_log_request /usr/local/lib/python2.7/dist-
packages/keystoneclient/session.py:198^[[00m

2015-09-18 11:59:25.782 ^[[00;32mDEBUG oslo_policy._cache_handler [^[[01
;36mreq-c533f8b0-f260-4a2b-8e61-de2c1f801980 ^[[00;36mtempest-
verify_tempest_config-176885932
062fbda3c2cd4966bfacf772bf0f0ed2^[[00;32m] ^[[01;35m^[[00;32mReloading
cached file /etc/neutron/policy.json^[[00m ^[[00;33mfrom (pid=10920)
read_cached_file /usr/local/lib/python2.7/dist-
packages/oslo_policy/_cache_handler.py:38^[[00m

2015-09-18 12:19:02.534 ^[[00;32mDEBUG oslo_concurrency.lockutils
[^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mLock "manager" acquired by
"neutron.manager._create_instance" :: waited 0.000s^[[00m ^[[00;33mfrom
(pid=14653) inner /usr/local/lib/python2.7/dist-
packages/oslo_concurrency/lockutils.py:253^[[00m

2015-09-18 12:19:02.778 ^[[00;32mDEBUG oslo_db.sqlalchemy.engines
[^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMySQL server mode set to
STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION^[[00m
^[[00;33mfrom (pid=14653) _check_effective_sql_mode
/usr/local/lib/python2.7/dist-
packages/oslo_db/sqlalchemy/engines.py:256^[[00m

2015-09-18 11:56:23.468 ^[[00;32mDEBUG oslo_messaging._drivers.amqp
[^[[01;36mreq-a46b008e-3fcc-4741-b138-0bcc8f7a8be7 ^[[00;36mNone
None^[[00;32m] ^[[01;35m^[[00;32mPool creating new connection^[[00m
^[[00;33mfrom (pid=10891) create /usr/local/lib/python2.7/dist-
packages/oslo_messaging/_drivers/amqp.py:103^[[00m

2015-09-18 11:56:24.600 ^[[00;32mDEBUG oslo_service.service
[^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mFull set of CONF:^[[00m
^[[00;33mfrom (pid=10891) wait /usr/local/lib/python2.7/dist-
packages/oslo_service/service.py:505^[[00m

** Affects: neutron
     Importance: Medium
     Assignee: Ryan Moats (rmoats)
         Status: In Progress

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1498565

Title:
  remove imported library DEBUG statements from neutron logs

Status in neutron:
  In Progress

Bug description:
  Today, neutron log files include debug statements from imported
  libraries that are not particularly useful.

  Selected examples:

  q-agt.log:
  --------

  2015-09-21 05:58:50.765 ^[[00;32mDEBUG oslo_rootwrap.client
  [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mPopen for ['sudo',
  '/usr/local/bin/neutron-rootwrap-daemon',
  '/etc/neutron/rootwrap.conf'] command has been instantiated^[[00m
  ^[[00;33mfrom (pid=17560) _initialize /usr/local/lib/python2.7/dist-
  packages/oslo_rootwrap/client.py:76^[[00m

  2015-09-21 05:58:51.666 ^[[00;32mDEBUG
  oslo_messaging._drivers.amqpdriver [^[[01;36mreq-9ae26b0d-cfb4-4417
  -b54f-13970adc62ed ^[[00;36mNone None^[[00;32m]
  ^[[01;35m^[[00;32mMSG_ID is 6430fa63de2f46afa0d19e30db724fa7^[[00m
  ^[[00;33mfrom (pid=17560) _send /usr/local/lib/python2.7/dist-
  packages/oslo_messaging/_drivers/amqpdriver.py:392^[[00m

  2015-09-21 05:58:51.231 ^[[00;32mDEBUG oslo_messaging._drivers.amqp
  [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mPool creating new
  connection^[[00m ^[[00;33mfrom (pid=17560) create
  /usr/local/lib/python2.7/dist-
  packages/oslo_messaging/_drivers/amqp.py:103^[[00m

  q-l3.log:

  2015-08-27 11:19:18.027 ^[[00;32mDEBUG oslo_concurrency.lockutils
  [^[[01;36mreq-c6a9f3dc-8254-4634-ae2b-0c5b916a70bc ^[[00;36mNone
  None^[[00;32m] ^[[01;35m^[[00;32mAcquired semaphore
  "singleton_lock"^[[00m ^[[00;33mfrom (pid=20186) lock
  /usr/local/lib/python2.7/dist-
  packages/oslo_concurrency/lockutils.py:198^[[00m

  2015-08-27 11:19:18.111 ^[[00;32mDEBUG oslo_messaging._drivers.amqpdriver [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMSG_ID is e1322001df9c4886b94c8270d053f100^[[00m ^[[00;33mfrom (pid=20186) _send /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:392^[[00m
  /

  2015-08-27 11:19:18.170 ^[[00;32mDEBUG oslo_service.loopingcall
  [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mFixed interval looping call
  'neutron.agent.l3.agent.L3NATAgentWithStateReport._report_state'
  sleeping for 29.94 seconds^[[00m ^[[00;33mfrom (pid=20186) _run_loop
  /usr/local/lib/python2.7/dist-
  packages/oslo_service/loopingcall.py:121^[[00m

  q-svc.log:

  2015-09-18 11:59:24.674 ^[[00;32mDEBUG keystoneclient.session
  [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mREQ: curl -g -i --cacert
  "/opt/stack/data/ca-bundle.pem" -X GET http://10.18.0.21:35357 -H
  "Accept: application/json" -H "User-Agent: neutron/7.0.0.0b4.dev217
  keystonemiddleware.auth_token/2.2.0"^[[00m ^[[00;33mfrom (pid=10920)
  _http_log_request /usr/local/lib/python2.7/dist-
  packages/keystoneclient/session.py:198^[[00m

  2015-09-18 11:59:25.782 ^[[00;32mDEBUG oslo_policy._cache_handler
  [^[[01;36mreq-c533f8b0-f260-4a2b-8e61-de2c1f801980 ^[[00;36mtempest-
  verify_tempest_config-176885932
  062fbda3c2cd4966bfacf772bf0f0ed2^[[00;32m] ^[[01;35m^[[00;32mReloading
  cached file /etc/neutron/policy.json^[[00m ^[[00;33mfrom (pid=10920)
  read_cached_file /usr/local/lib/python2.7/dist-
  packages/oslo_policy/_cache_handler.py:38^[[00m

  2015-09-18 12:19:02.534 ^[[00;32mDEBUG oslo_concurrency.lockutils
  [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mLock "manager" acquired by
  "neutron.manager._create_instance" :: waited 0.000s^[[00m
  ^[[00;33mfrom (pid=14653) inner /usr/local/lib/python2.7/dist-
  packages/oslo_concurrency/lockutils.py:253^[[00m

  2015-09-18 12:19:02.778 ^[[00;32mDEBUG oslo_db.sqlalchemy.engines
  [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMySQL server mode set to
  STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION^[[00m
  ^[[00;33mfrom (pid=14653) _check_effective_sql_mode
  /usr/local/lib/python2.7/dist-
  packages/oslo_db/sqlalchemy/engines.py:256^[[00m

  2015-09-18 11:56:23.468 ^[[00;32mDEBUG oslo_messaging._drivers.amqp
  [^[[01;36mreq-a46b008e-3fcc-4741-b138-0bcc8f7a8be7 ^[[00;36mNone
  None^[[00;32m] ^[[01;35m^[[00;32mPool creating new connection^[[00m
  ^[[00;33mfrom (pid=10891) create /usr/local/lib/python2.7/dist-
  packages/oslo_messaging/_drivers/amqp.py:103^[[00m

  2015-09-18 11:56:24.600 ^[[00;32mDEBUG oslo_service.service
  [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mFull set of CONF:^[[00m
  ^[[00;33mfrom (pid=10891) wait /usr/local/lib/python2.7/dist-
  packages/oslo_service/service.py:505^[[00m

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1498565/+subscriptions
Follow ups

[Bug 1498565] Re: remove imported library DEBUG statements from neutron logs
From: Ryan Moats, 2015-09-23