From c0a9cc93f8ffdc89789936d5ca956e7ea0f7efa8 Mon Sep 17 00:00:00 2001 From: Hans Krijger Date: Mon, 3 Apr 2017 11:29:34 -0700 Subject: [PATCH] Bug fixes (#642) * additional logging when exceptions occur (#640) * handle heartbeat keyerror correctly (#641) * correct ext state case sensitivity check (#639) * better old event handling (#637) * unit test fix * pr feedback --- azurelinuxagent/common/event.py | 13 ++++- azurelinuxagent/ga/exthandlers.py | 6 +-- azurelinuxagent/ga/update.py | 2 + tests/common/test_event.py | 90 +++++++++++++++++++++++++++++++ tests/ga/test_update.py | 1 - 5 files changed, 106 insertions(+), 6 deletions(-) create mode 100644 tests/common/test_event.py diff --git a/azurelinuxagent/common/event.py b/azurelinuxagent/common/event.py index 9265820..fb2c97c 100644 --- a/azurelinuxagent/common/event.py +++ b/azurelinuxagent/common/event.py @@ -65,8 +65,17 @@ class EventLogger(object): if not os.path.exists(self.event_dir): os.mkdir(self.event_dir) os.chmod(self.event_dir, 0o700) - if len(os.listdir(self.event_dir)) > 1000: - raise EventError("Too many files under: {0}".format(self.event_dir)) + + existing_events = os.listdir(self.event_dir) + if len(existing_events) >= 1000: + existing_events.sort() + oldest_files = existing_events[:-999] + logger.warn("Too many files under: {0}, removing oldest".format(self.event_dir)) + try: + for f in oldest_files: + os.remove(os.path.join(self.event_dir, f)) + except IOError as e: + raise EventError(e) filename = os.path.join(self.event_dir, ustr(int(time.time() * 1000000))) diff --git a/azurelinuxagent/ga/exthandlers.py b/azurelinuxagent/ga/exthandlers.py index 70bb246..9d3cec3 100644 --- a/azurelinuxagent/ga/exthandlers.py +++ b/azurelinuxagent/ga/exthandlers.py @@ -221,9 +221,9 @@ class ExtHandlersHandler(object): self.log_etag = True - state = ext_handler.properties.state + state = ext_handler.properties.state.lower() ext_handler_i.logger.info("Expected handler state: {0}", state) - if state == "enabled": + if state == u"enabled": self.handle_enable(ext_handler_i) elif state == u"disabled": self.handle_disable(ext_handler_i) @@ -709,7 +709,7 @@ class ExtHandlerInstance(object): heartbeat = json.loads(heartbeat_json)[0]['heartbeat'] except IOError as e: raise ExtensionError("Failed to get heartbeat file:{0}".format(e)) - except ValueError as e: + except (ValueError, KeyError) as e: raise ExtensionError("Malformed heartbeat file: {0}".format(e)) return heartbeat diff --git a/azurelinuxagent/ga/update.py b/azurelinuxagent/ga/update.py index 53f0173..61d9f47 100644 --- a/azurelinuxagent/ga/update.py +++ b/azurelinuxagent/ga/update.py @@ -27,6 +27,7 @@ import signal import subprocess import sys import time +import traceback import zipfile import azurelinuxagent.common.conf as conf @@ -250,6 +251,7 @@ class UpdateHandler(object): except Exception as e: logger.warn(u"Agent {0} failed with exception: {1}", CURRENT_AGENT, ustr(e)) + logger.warn(traceback.format_exc()) sys.exit(1) return diff --git a/tests/common/test_event.py b/tests/common/test_event.py new file mode 100644 index 0000000..726474c --- /dev/null +++ b/tests/common/test_event.py @@ -0,0 +1,90 @@ +# Copyright 2017 Microsoft Corporation +# +# 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. +# +# Requires Python 2.4+ and Openssl 1.0+ +# + +from __future__ import print_function + +from tests.tools import * +from azurelinuxagent.common.event import * + + +class TestEvent(AgentTestCase): + def test_save_event(self): + tmp_evt = tempfile.mkdtemp() + init_event_logger(tmp_evt) + add_event('test', message='test event') + self.assertTrue(len(os.listdir(tmp_evt)) == 1) + shutil.rmtree(tmp_evt) + + def test_save_event_rollover(self): + tmp_evt = tempfile.mkdtemp() + init_event_logger(tmp_evt) + add_event('test', message='first event') + for i in range(0, 999): + add_event('test', message='test event {0}'.format(i)) + + events = os.listdir(tmp_evt) + events.sort() + self.assertTrue(len(events) == 1000) + + first_event = os.path.join(tmp_evt, events[0]) + with open(first_event) as first_fh: + first_event_text = first_fh.read() + self.assertTrue('first event' in first_event_text) + + add_event('test', message='last event') + events = os.listdir(tmp_evt) + events.sort() + self.assertTrue(len(events) == 1000, "{0} events found, 1000 expected".format(len(events))) + + first_event = os.path.join(tmp_evt, events[0]) + with open(first_event) as first_fh: + first_event_text = first_fh.read() + self.assertFalse('first event' in first_event_text) + self.assertTrue('test event 0' in first_event_text) + + last_event = os.path.join(tmp_evt, events[-1]) + with open(last_event) as last_fh: + last_event_text = last_fh.read() + self.assertTrue('last event' in last_event_text) + + shutil.rmtree(tmp_evt) + + def test_save_event_cleanup(self): + tmp_evt = tempfile.mkdtemp() + init_event_logger(tmp_evt) + + for i in range(0, 2000): + evt = os.path.join(tmp_evt, '{0}.tld'.format(ustr(1491004920536531 + i))) + with open(evt, 'w') as fh: + fh.write('test event {0}'.format(i)) + + events = os.listdir(tmp_evt) + self.assertTrue(len(events) == 2000, "{0} events found, 2000 expected".format(len(events))) + add_event('test', message='last event') + + events = os.listdir(tmp_evt) + events.sort() + self.assertTrue(len(events) == 1000, "{0} events found, 1000 expected".format(len(events))) + first_event = os.path.join(tmp_evt, events[0]) + with open(first_event) as first_fh: + first_event_text = first_fh.read() + self.assertTrue('test event 1001' in first_event_text) + + last_event = os.path.join(tmp_evt, events[-1]) + with open(last_event) as last_fh: + last_event_text = last_fh.read() + self.assertTrue('last event' in last_event_text) diff --git a/tests/ga/test_update.py b/tests/ga/test_update.py index 46502cc..46d0673 100644 --- a/tests/ga/test_update.py +++ b/tests/ga/test_update.py @@ -1083,7 +1083,6 @@ class TestUpdate(UpdateTestCase): self._test_run_latest(mock_child=mock_child, mock_time=mock_time) self.assertEqual(1, mock_child.poll.call_count) self.assertEqual(0, mock_child.wait.call_count) - self.assertEqual(2, mock_time.time_call_count) return def test_run_latest_defaults_to_current(self):