diff --git a/requirements.txt b/requirements.txt
index 3947be027..435976b67 100644
--- a/requirements.txt
+++ b/requirements.txt
@@ -5,7 +5,6 @@ wsgiref>=0.1.2
pecan>=0.4.5
WSME>=0.6
six>=1.5.2
-structlog==0.4.1
oslo.config==1.2.1
Babel==1.3
iso8601==0.1.10
diff --git a/teeth_agent/agent.py b/teeth_agent/agent.py
index fbc263951..783ac5e5d 100644
--- a/teeth_agent/agent.py
+++ b/teeth_agent/agent.py
@@ -21,7 +21,6 @@ import time
import pkg_resources
from stevedore import driver
-import structlog
from wsgiref import simple_server
from teeth_agent.api import app
@@ -29,9 +28,15 @@ from teeth_agent import base
from teeth_agent import encoding
from teeth_agent import errors
from teeth_agent import hardware
+from teeth_agent.openstack.common import log
from teeth_agent import overlord_agent_api
+def _time():
+ """Wraps time.time() for simpler testing."""
+ return time.time()
+
+
class TeethAgentStatus(encoding.Serializable):
def __init__(self, mode, started_at, version):
self.mode = mode
@@ -66,7 +71,7 @@ class TeethAgentHeartbeater(threading.Thread):
self.agent = agent
self.hardware = hardware.get_manager()
self.api = overlord_agent_api.APIClient(agent.api_url)
- self.log = structlog.get_logger(api_url=agent.api_url)
+ self.log = log.getLogger(__name__)
self.stop_event = threading.Event()
self.error_delay = self.initial_delay
@@ -79,8 +84,9 @@ class TeethAgentHeartbeater(threading.Thread):
next_heartbeat_by = self.do_heartbeat()
interval_multiplier = random.uniform(self.min_jitter_multiplier,
self.max_jitter_multiplier)
- interval = (next_heartbeat_by - time.time()) * interval_multiplier
- self.log.info('sleeping before next heartbeat', interval=interval)
+ interval = (next_heartbeat_by - _time()) * interval_multiplier
+ log_msg = 'sleeping before next heartbeat, interval: {0}'
+ self.log.info(log_msg.format(interval))
def do_heartbeat(self):
try:
@@ -91,8 +97,9 @@ class TeethAgentHeartbeater(threading.Thread):
self.error_delay = self.initial_delay
self.log.info('heartbeat successful')
except Exception as e:
- self.log.error('error sending heartbeat', exception=e)
- deadline = time.time() + self.error_delay
+ self.log.error('error sending heartbeat')
+ self.log.exception(e)
+ deadline = _time() + self.error_delay
self.error_delay = min(self.error_delay * self.backoff_factor,
self.max_delay)
pass
@@ -117,7 +124,7 @@ class TeethAgent(object):
self.heartbeater = TeethAgentHeartbeater(self)
self.hardware = hardware.get_manager()
self.command_lock = threading.Lock()
- self.log = structlog.get_logger()
+ self.log = log.getLogger(__name__)
self.started_at = None
def get_mode_name(self):
@@ -197,7 +204,7 @@ class TeethAgent(object):
def run(self):
"""Run the Teeth Agent."""
- self.started_at = time.time()
+ self.started_at = _time()
self.heartbeater.start()
wsgi = simple_server.make_server(
self.listen_address[0],
@@ -208,7 +215,8 @@ class TeethAgent(object):
try:
wsgi.serve_forever()
except BaseException as e:
- self.log.error('shutting down', exception=e)
+ self.log.error('shutting down')
+ self.log.exception(e)
self.heartbeater.stop()
diff --git a/teeth_agent/base.py b/teeth_agent/base.py
index 8147c43d9..babed349f 100644
--- a/teeth_agent/base.py
+++ b/teeth_agent/base.py
@@ -17,10 +17,10 @@ limitations under the License.
import threading
import uuid
-import structlog
from teeth_agent import encoding
from teeth_agent import errors
+from teeth_agent.openstack.common import log
class AgentCommandStatus(object):
@@ -117,7 +117,7 @@ class AsyncCommandResult(BaseCommandResult):
class BaseAgentMode(object):
def __init__(self, name):
super(BaseAgentMode, self).__init__()
- self.log = structlog.get_logger(agent_mode=name)
+ self.log = log.getLogger(__name__)
self.name = name
self.command_map = {}
diff --git a/teeth_agent/cmd/agent.py b/teeth_agent/cmd/agent.py
index 92f4ef386..7075693a5 100644
--- a/teeth_agent/cmd/agent.py
+++ b/teeth_agent/cmd/agent.py
@@ -17,7 +17,6 @@ limitations under the License.
import argparse
from teeth_agent import agent
-from teeth_agent import logging
def run():
@@ -44,7 +43,6 @@ def run():
help='The external IP address to advertise to ironic')
args = parser.parse_args()
- logging.configure()
agent.build_agent(args.api_url,
args.listen_host,
args.listen_port,
diff --git a/teeth_agent/hardware.py b/teeth_agent/hardware.py
index a8e4e0fd9..4f192a1d9 100644
--- a/teeth_agent/hardware.py
+++ b/teeth_agent/hardware.py
@@ -20,9 +20,9 @@ import os
import subprocess
import stevedore
-import structlog
from teeth_agent import encoding
+from teeth_agent.openstack.common import log
_global_manager = None
@@ -162,7 +162,7 @@ def get_manager():
global _global_manager
if not _global_manager:
- log = structlog.get_logger()
+ LOG = log.getLogger()
extension_manager = stevedore.ExtensionManager(
namespace='teeth_agent.hardware_managers',
invoke_on_load=True)
@@ -175,8 +175,8 @@ def get_manager():
if preferred_manager.evaluate_hardware_support() <= 0:
raise RuntimeError('No suitable HardwareManager could be found')
- log.info('selected hardware manager',
- manager_name=preferred_extension.entry_point_target)
+ LOG.info('selected hardware manager {0}'.format(
+ preferred_extension.entry_point_target))
_global_manager = preferred_manager
diff --git a/teeth_agent/logging.py b/teeth_agent/logging.py
deleted file mode 100644
index 5c66bc900..000000000
--- a/teeth_agent/logging.py
+++ /dev/null
@@ -1,72 +0,0 @@
-"""
-Copyright 2013 Rackspace, Inc.
-
-Licensed under the Apache License, Version 2.0 (the "License");
-you may not use this file except in compliance with the License.
-You may obtain a copy of the License at
-
- http://www.apache.org/licenses/LICENSE-2.0
-
-Unless required by applicable law or agreed to in writing, software
-distributed under the License is distributed on an "AS IS" BASIS,
-WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-See the License for the specific language governing permissions and
-limitations under the License.
-"""
-
-import string
-
-import structlog
-
-import traceback
-
-EXCEPTION_LOG_METHODS = ['error']
-
-
-def _capture_stack_trace(logger, method, event):
- if method in EXCEPTION_LOG_METHODS:
- event['exception'] = traceback.format_exc()
-
- return event
-
-
-def _format_event(logger, method, event):
- """Formats the log message using keyword args.
- log('hello {keyword}', keyword='world') should log: "hello world"
- Removes the keywords used for formatting from the logged message.
- Throws a KeyError if the log message requires formatting but doesn't
- have enough keys to format.
- """
- if 'event' not in event:
- # nothing to format
- return event
- # Get a list of fields that need to be filled.
- formatter = string.Formatter()
- try:
- formatted = formatter.format(event['event'], **event)
- except KeyError:
- keys = formatter.parse(event['event'])
- # index 1 is the key name
- keys = [item[1] for item in keys]
- missing_keys = list(set(keys) - set(event))
- raise KeyError("Log formatter missing keys: {}, cannot format."
- .format(missing_keys))
- event['event'] = formatted
- return event
-
-
-def configure(pretty=False):
- processors = [
- _capture_stack_trace,
- _format_event,
- ]
-
- if pretty:
- processors.append(structlog.processors.ExceptionPrettyPrinter())
- processors.append(structlog.processors.KeyValueRenderer())
- else:
- processors.append(structlog.processors.JSONRenderer())
-
- structlog.configure(
- processors=processors
- )
diff --git a/teeth_agent/standby.py b/teeth_agent/standby.py
index 43df5c621..7dc9a3eb4 100644
--- a/teeth_agent/standby.py
+++ b/teeth_agent/standby.py
@@ -17,7 +17,6 @@ limitations under the License.
import hashlib
import os
import requests
-import structlog
import subprocess
import time
@@ -26,8 +25,9 @@ from teeth_agent import configdrive
from teeth_agent import decorators
from teeth_agent import errors
from teeth_agent import hardware
+from teeth_agent.openstack.common import log
-log = structlog.get_logger()
+LOG = log.getLogger(__name__)
def _configdrive_location():
@@ -49,29 +49,31 @@ def _write_image(image_info, device):
script = _path_to_script('shell/write_image.sh')
command = ['/bin/bash', script, image, device]
- log.info('Writing image', command=' '.join(command))
+ LOG.info('Writing image with command: {0}'.format(' '.join(command)))
exit_code = subprocess.call(command)
if exit_code != 0:
raise errors.ImageWriteError(exit_code, device)
totaltime = time.time() - starttime
- log.info('Image written', device=device, seconds=totaltime, image=image)
+ LOG.info('Image {0} written to device {1} in {2} seconds'.format(
+ image, device, totaltime))
def _copy_configdrive_to_disk(configdrive_dir, device):
starttime = time.time()
script = _path_to_script('shell/copy_configdrive_to_disk.sh')
command = ['/bin/bash', script, configdrive_dir, device]
- log.info('copying configdrive to disk', command=' '.join(command))
+ LOG.info('copying configdrive to disk with command {0}'.format(
+ ' '.join(command)))
exit_code = subprocess.call(command)
if exit_code != 0:
raise errors.ConfigDriveWriteError(exit_code, device)
totaltime = time.time() - starttime
- log.info('configdrive copied',
- from_directory=configdrive_dir,
- device=device,
- seconds=totaltime)
+ LOG.info('configdrive copied from {0} to {1} in {2} seconds'.format(
+ configdrive_dir,
+ device,
+ totaltime))
def _request_url(image_info, url):
@@ -86,11 +88,12 @@ def _download_image(image_info):
resp = None
for url in image_info['urls']:
try:
- log.info("Attempting to download image", url=url)
+ LOG.info("Attempting to download image from {0}".format(url))
resp = _request_url(image_info, url)
except errors.ImageDownloadError:
failtime = time.time() - starttime
- log.warning("Image download failed", url=url, seconds=failtime)
+ log_msg = "Image download failed. URL: {0}; time: {1} seconds"
+ LOG.warning(log_msg.format(url, failtime))
continue
else:
break
@@ -106,7 +109,8 @@ def _download_image(image_info):
raise errors.ImageDownloadError(image_info['id'])
totaltime = time.time() - starttime
- log.info("Image downloaded", image=image_location, seconds=totaltime)
+ LOG.info("Image downloaded from {0} in {1} seconds".format(image_location,
+ totaltime))
if not _verify_image(image_info, image_location):
raise errors.ImageChecksumError(image_info['id'])
@@ -118,19 +122,16 @@ def _verify_image(image_info, image_location):
algo = getattr(hashlib, k, None)
if algo is None:
continue
- log.debug('Verifying image',
- image=image_location,
- algo=k,
- passed_hash=v)
+ log_msg = 'Verifying image at {0} with algorithm {1} against hash {2}'
+ LOG.debug(log_msg.format(image_location, k, v))
hash_ = algo(open(image_location).read()).hexdigest()
if hash_ == v:
return True
else:
- log.warning('Image verification failed',
- image=image_location,
- algo=k,
- imagehash=hash_,
- passed_hash=v)
+ log_msg = ('Image verification failed. Location: {0};'
+ 'algorithm: {1}; image hash: {2};'
+ 'verification hash: {3}')
+ LOG.warning(log_msg.format(image_location, k, hash_, v))
return False
@@ -185,14 +186,14 @@ class StandbyMode(base.BaseAgentMode):
_write_image(image_info, device)
self.cached_image_id = image_info['id']
- log.debug('Writing configdrive', location=location)
+ LOG.debug('Writing configdrive to {0}'.format(location))
configdrive.write_configdrive(location, metadata, files)
_copy_configdrive_to_disk(location, device)
@decorators.async_command()
def run_image(self, command_name):
script = _path_to_script('shell/reboot.sh')
- log.info('Rebooting system')
+ LOG.info('Rebooting system')
command = ['/bin/bash', script]
# this should never return if successful
exit_code = subprocess.call(command)
diff --git a/teeth_agent/tests/agent.py b/teeth_agent/tests/agent.py
index 83313606f..61a48c686 100644
--- a/teeth_agent/tests/agent.py
+++ b/teeth_agent/tests/agent.py
@@ -53,7 +53,7 @@ class TestHeartbeater(unittest.TestCase):
hardware.HardwareManager)
self.heartbeater.stop_event = mock.Mock()
- @mock.patch('time.time')
+ @mock.patch('teeth_agent.agent._time')
@mock.patch('random.uniform')
def test_heartbeat(self, mocked_uniform, mocked_time):
time_responses = []
diff --git a/teeth_agent/tests/logging.py b/teeth_agent/tests/logging.py
deleted file mode 100644
index fc8fde34e..000000000
--- a/teeth_agent/tests/logging.py
+++ /dev/null
@@ -1,44 +0,0 @@
-"""
-Copyright 2013 Rackspace, Inc.
-
-Licensed under the Apache License, Version 2.0 (the "License");
-you may not use this file except in compliance with the License.
-You may obtain a copy of the License at
-
- http://www.apache.org/licenses/LICENSE-2.0
-
-Unless required by applicable law or agreed to in writing, software
-distributed under the License is distributed on an "AS IS" BASIS,
-WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-See the License for the specific language governing permissions and
-limitations under the License.
-"""
-
-import structlog
-import unittest
-
-import teeth_agent.logging
-
-
-def _return_event_processor(logger, method, event):
- return event['event']
-
-
-class EventLogger(unittest.TestCase):
- def test_format_event_basic(self):
- processors = [teeth_agent.logging._format_event,
- _return_event_processor]
- structlog.configure(processors=processors)
- log = structlog.wrap_logger(structlog.ReturnLogger())
- logged_msg = log.msg("hello {word}", word='world')
- self.assertEqual(logged_msg, "hello world")
-
- def test_no_format_keys(self):
- """Check that we get an exception if you don't provide enough keys to
- format a log message requiring format
- """
- processors = [teeth_agent.logging._format_event,
- _return_event_processor]
- structlog.configure(processors=processors)
- log = structlog.wrap_logger(structlog.ReturnLogger())
- self.assertRaises(KeyError, log.msg, "hello {word}")
diff --git a/tox.ini b/tox.ini
index 3e8f68a98..87ef3fb57 100644
--- a/tox.ini
+++ b/tox.ini
@@ -16,3 +16,6 @@ commands =
[testenv:devenv]
envdir = devenv
usedevelop = True
+
+[flake8]
+exclude=*openstack/common*