better telemetry messages (#1011)

azurelinuxagent/common/event.py

@@ -15,33 +15,29 @@
 # Requires Python 2.4+ and Openssl 1.0+
 #
 
+import atexit
+import datetime
+import json
 import os
 import sys
-import traceback
-import atexit
-import json
 import time
-import datetime
-import threading
-import platform
+import traceback
 
-from datetime import datetime, timedelta
+from datetime import datetime
 
 import azurelinuxagent.common.conf as conf
 import azurelinuxagent.common.logger as logger
 
-from azurelinuxagent.common.exception import EventError, ProtocolError
+from azurelinuxagent.common.exception import EventError
 from azurelinuxagent.common.future import ustr
 from azurelinuxagent.common.protocol.restapi import TelemetryEventParam, \
-    TelemetryEventList, \
     TelemetryEvent, \
-    set_properties, get_properties
-from azurelinuxagent.common.version import DISTRO_NAME, DISTRO_VERSION, \
-    DISTRO_CODE_NAME, AGENT_VERSION, \
-    CURRENT_AGENT, CURRENT_VERSION
+    get_properties
+from azurelinuxagent.common.version import CURRENT_VERSION
 
 _EVENT_MSG = "Event: name={0}, op={1}, message={2}, duration={3}"
 
+
 class WALAEventOperation:
     ActivateResourceDisk = "ActivateResourceDisk"
     AgentBlacklisted = "AgentBlacklisted"
@@ -228,12 +224,24 @@ class EventLogger(object):
             logger.error("{0}", e)
 
     def add_log_event(self, level, message):
+        # By the time the message has gotten to this point it is formatted as
+        #
+        #   YYYY/MM/DD HH:mm:ss.fffffff LEVEL <text>.
+        #
+        # The timestamp and the level are redundant, and should be stripped.
+        # The logging library does not schematize this data, so I am forced
+        # to parse the message.  The format is regular, so the burden is low.
+
+        parts = message.split(' ', 3)
+        msg = parts[3] if len(parts) == 4 \
+            else message
+
         event = TelemetryEvent(7, "FFF0196F-EE4C-4EAF-9AA5-776F622DEB4F")
         event.parameters.append(TelemetryEventParam('EventName', WALAEventOperation.Log))
         event.parameters.append(TelemetryEventParam('CapabilityUsed', logger.LogLevel.STRINGS[level]))
-        event.parameters.append(TelemetryEventParam('Context1', ''))
-        event.parameters.append(TelemetryEventParam('Context2', str(CURRENT_AGENT)))
-        event.parameters.append(TelemetryEventParam('Context3', str(message)))
+        event.parameters.append(TelemetryEventParam('Context1', msg))
+        event.parameters.append(TelemetryEventParam('Context2', ''))
+        event.parameters.append(TelemetryEventParam('Context3', ''))
 
         data = get_properties(event)
         try:

azurelinuxagent/common/osutil/default.py

@@ -998,7 +998,7 @@ class DefaultOSUtil(object):
         if not os.path.exists(hostname_record):
             # this file is created at provisioning time with agents >= 2.2.3
             hostname = socket.gethostname()
-            logger.warn('Hostname record does not exist, '
+            logger.info('Hostname record does not exist, '
                         'creating [{0}] with hostname [{1}]',
                         hostname_record,
                         hostname)

azurelinuxagent/common/protocol/wire.py

@@ -935,7 +935,7 @@ class WireClient(object):
             logger.info("Wire protocol version:{0}", PROTOCOL_VERSION)
         elif PROTOCOL_VERSION in version_info.get_supported():
             logger.info("Wire protocol version:{0}", PROTOCOL_VERSION)
-            logger.warn("Server preferred version:{0}", preferred)
+            logger.info("Server preferred version:{0}", preferred)
         else:
             error = ("Agent supported wire protocol version: {0} was not "
                      "advised by Fabric.").format(PROTOCOL_VERSION)

tests/common/test_logger.py

@@ -89,16 +89,16 @@ class TestLogger(AgentTestCase):
         self.assertEqual(5, len(telemetry_json['parameters']))
         for x in telemetry_json['parameters']:
             if x['name'] == 'EventName':
-                self.assertEqual('Log', x['value'])
+                self.assertEqual(x['value'], 'Log')
 
             elif x['name'] == 'CapabilityUsed':
-                self.assertEqual('WARNING', x['value'])
+                self.assertEqual(x['value'], 'WARNING')
 
             elif x['name'] == 'Context1':
-                self.assertEqual('', x['value'])
+                self.assertEqual(x['value'], '--unit-test--')
 
             elif x['name'] == 'Context2':
-                self.assertEqual(CURRENT_AGENT, x['value'])
+                self.assertEqual(x['value'], '')
 
             elif x['name'] == 'Context3':
-                self.assertEqual("--unit-test--", x['value'])
+                self.assertEqual(x['value'], '')