Utils/handlerutil2.py

#
# Handler library for Linux IaaS
#
# Copyright 2014 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.


"""
JSON def:
HandlerEnvironment.json
[{
  "name": "ExampleHandlerLinux",
  "seqNo": "seqNo",
  "version": "1.0",
  "handlerEnvironment": {
    "logFolder": "<your log folder location>",
    "configFolder": "<your config folder location>",
    "statusFolder": "<your status folder location>",
    "heartbeatFile": "<your heartbeat file location>",

  }
}]

Example ./config/1.settings
"{"runtimeSettings":[{"handlerSettings":{"protectedSettingsCertThumbprint":"1BE9A13AA1321C7C515EF109746998BAB6D86FD1","protectedSettings":
"MIIByAYJKoZIhvcNAQcDoIIBuTCCAbUCAQAxggFxMIIBbQIBADBVMEExPzA9BgoJkiaJk/IsZAEZFi9XaW5kb3dzIEF6dXJlIFNlcnZpY2UgTWFuYWdlbWVudCBmb3IgR+nhc6VHQTQpCiiV2zANBgkqhkiG9w0BAQEFAASCAQCKr09QKMGhwYe+O4/a8td+vpB4eTR+BQso84cV5KCAnD6iUIMcSYTrn9aveY6v6ykRLEw8GRKfri2d6tvVDggUrBqDwIgzejGTlCstcMJItWa8Je8gHZVSDfoN80AEOTws9Fp+wNXAbSuMJNb8EnpkpvigAWU2v6pGLEFvSKC0MCjDTkjpjqciGMcbe/r85RG3Zo21HLl0xNOpjDs/qqikc/ri43Y76E/Xv1vBSHEGMFprPy/Hwo3PqZCnulcbVzNnaXN3qi/kxV897xGMPPC3IrO7Nc++AT9qRLFI0841JLcLTlnoVG1okPzK9w6ttksDQmKBSHt3mfYV+skqs+EOMDsGCSqGSIb3DQEHATAUBggqhkiG9w0DBwQITgu0Nu3iFPuAGD6/QzKdtrnCI5425fIUy7LtpXJGmpWDUA==","publicSettings":{"port":"3000"}}}]}"


Example HeartBeat
{
"version": 1.0,
    "heartbeat" : {
        "status": "ready",
        "code": 0,
        "Message": "Sample Handler running. Waiting for a new configuration from user."
    }
}
Example Status Report:
[{"version":"1.0","timestampUTC":"2014-05-29T04:20:13Z","status":{"name":"Chef Extension Handler","operation":"chef-client-run","status":"success","code":0,"formattedMessage":{"lang":"en-US","message":"Chef-client run success"}}}]

"""

import os
import os.path
import sys
import base64
import json
import time
import re

import Utils.extensionutils as ext_utils
import Utils.constants as constants
import Utils.logger as logger
from xml.etree import ElementTree
from os.path import join

DateTimeFormat = "%Y-%m-%dT%H:%M:%SZ"

MANIFEST_XML = "manifest.xml"


class HandlerContext:
    def __init__(self, name):
        self._name = name
        self._version = '0.0'
        self._config_dir = None
        self._log_dir = None
        self._log_file = None
        self._status_dir = None
        self._heartbeat_file = None
        self._seq_no = -1
        self._status_file = None
        self._settings_file = None
        self._config = None
        return


class HandlerUtility:
    def __init__(self, s_name=None, l_name=None, extension_version=None, logFileName='extension.log',
                 console_logger=None, file_logger=None):
        self._log = logger.log
        self._log_to_con = console_logger
        self._log_to_file = file_logger
        self._error = logger.error
        self._logFileName = logFileName
        if s_name is None or l_name is None or extension_version is None:
            (l_name, s_name, extension_version) = self._get_extension_info()

        self._short_name = s_name
        self._extension_version = extension_version
        self._log_prefix = '[%s-%s] ' % (l_name, extension_version)

    def get_extension_version(self):
        return self._extension_version

    def _get_log_prefix(self):
        return self._log_prefix

    def _get_extension_info(self):
        if os.path.isfile(MANIFEST_XML):
            return self._get_extension_info_manifest()

        ext_dir = os.path.basename(os.getcwd())
        (long_name, version) = ext_dir.split('-')
        short_name = long_name.split('.')[-1]

        return long_name, short_name, version

    def _get_extension_info_manifest(self):
        with open(MANIFEST_XML) as fh:
            doc = ElementTree.parse(fh)
            namespace = doc.find('{http://schemas.microsoft.com/windowsazure}ProviderNameSpace').text
            short_name = doc.find('{http://schemas.microsoft.com/windowsazure}Type').text
            version = doc.find('{http://schemas.microsoft.com/windowsazure}Version').text

            long_name = "%s.%s" % (namespace, short_name)
            return (long_name, short_name, version)

    def _get_current_seq_no(self, config_folder):
        seq_no = -1
        cur_seq_no = -1
        freshest_time = None
        for subdir, dirs, files in os.walk(config_folder):
            for file in files:
                try:
                    cur_seq_no = int(os.path.basename(file).split('.')[0])
                    if (freshest_time == None):
                        freshest_time = os.path.getmtime(join(config_folder, file))
                        seq_no = cur_seq_no
                    else:
                        current_file_m_time = os.path.getmtime(join(config_folder, file))
                        if (current_file_m_time > freshest_time):
                            freshest_time = current_file_m_time
                            seq_no = cur_seq_no
                except ValueError:
                    continue
        return seq_no

    def log(self, message):
        self._log(self._get_log_prefix() + message)

    def log_to_console(self, message):
        if self._log_to_con is not None:
            self._log_to_con(self._get_log_prefix() + message)
        else:
            self.error("Unable to log to console, console log method not set")

    def log_to_file(self, message):
        if self._log_to_file is not None:
            self._log_to_file(self._get_log_prefix() + message)
        else:
            self.error("Unable to log to file, file log method not set")

    def error(self, message):
        self._error(self._get_log_prefix() + message)

    @staticmethod
    def redact_protected_settings(content):
        redacted_tmp = re.sub('"protectedSettings":\s*"[^"]+=="', '"protectedSettings": "*** REDACTED ***"', content)
        redacted = re.sub('"protectedSettingsCertThumbprint":\s*"[^"]+"', '"protectedSettingsCertThumbprint": "*** REDACTED ***"', redacted_tmp)
        return redacted

    def _parse_config(self, ctxt):
        config = None
        try:
            config = json.loads(ctxt)
        except:
            self.error('JSON exception decoding ' + HandlerUtility.redact_protected_settings(ctxt))

        if config is None:
            self.error("JSON error processing settings file:" + HandlerUtility.redact_protected_settings(ctxt))
        else:
            handlerSettings = config['runtimeSettings'][0]['handlerSettings']
            if 'protectedSettings' in handlerSettings and \
                    'protectedSettingsCertThumbprint' in handlerSettings and \
                    handlerSettings['protectedSettings'] is not None and \
                    handlerSettings["protectedSettingsCertThumbprint"] is not None:
                protectedSettings = handlerSettings['protectedSettings']
                thumb = handlerSettings['protectedSettingsCertThumbprint']
                cert = constants.LibDir + '/' + thumb + '.crt'
                pkey = constants.LibDir + '/' + thumb + '.prv'
                unencodedSettings = base64.standard_b64decode(protectedSettings)
                openSSLcmd_cms = ['openssl', 'cms', '-inform', 'DER', '-decrypt', '-recip' , cert, '-inkey', pkey]
                cleartxt = ext_utils.run_send_stdin(openSSLcmd_cms, unencodedSettings)[1]
                if cleartxt is None:
                    self.log("OpenSSL decode error using cms command with thumbprint " + thumb + "\n trying smime command")
                    openSSLcmd_smime = ['openssl', 'smime', '-inform', 'DER', '-decrypt', '-recip' , cert, '-inkey', pkey]
                    cleartxt = ext_utils.run_send_stdin(openSSLcmd_smime, unencodedSettings)[1]
                    if cleartxt is None:
                        self.error("OpenSSL decode error using smime command with thumbprint " + thumb)
                        self.do_exit(1, "Enable", 'error', '1', 'Failed to decrypt protectedSettings')
                jctxt = ''
                try:
                    jctxt = json.loads(cleartxt)
                except:
                    self.error('JSON exception decoding ' + HandlerUtility.redact_protected_settings(cleartxt))
                handlerSettings['protectedSettings']=jctxt
                self.log('Config decoded correctly.')
        return config

    def do_parse_context(self, operation):
        _context = self.try_parse_context()
        if not _context:
            self.do_exit(1, operation, 'error', '1', operation + ' Failed')
        return _context

    def try_parse_context(self):
        self._context = HandlerContext(self._short_name)
        handler_env = None
        config = None
        ctxt = None
        code = 0
        # get the HandlerEnvironment.json. According to the extension handler spec, it is always in the ./ directory
        self.log('cwd is ' + os.path.realpath(os.path.curdir))
        handler_env_file = './HandlerEnvironment.json'
        if not os.path.isfile(handler_env_file):
            self.error("Unable to locate " + handler_env_file)
            return None
        ctxt = ext_utils.get_file_contents(handler_env_file)
        if ctxt == None:
            self.error("Unable to read " + handler_env_file)
        try:
            handler_env = json.loads(ctxt)
        except:
            pass
        if handler_env == None:
            self.log("JSON error processing " + handler_env_file)
            return None
        if type(handler_env) == list:
            handler_env = handler_env[0]

        self._context._name = handler_env['name']
        self._context._version = str(handler_env['version'])
        self._context._config_dir = handler_env['handlerEnvironment']['configFolder']
        self._context._log_dir = handler_env['handlerEnvironment']['logFolder']

        self._context._log_file = os.path.join(handler_env['handlerEnvironment']['logFolder'], self._logFileName)
        self._change_log_file()
        self._context._status_dir = handler_env['handlerEnvironment']['statusFolder']
        self._context._heartbeat_file = handler_env['handlerEnvironment']['heartbeatFile']
        self._context._seq_no = self._get_current_seq_no(self._context._config_dir)
        if self._context._seq_no < 0:
            self.error("Unable to locate a .settings file!")
            return None
        self._context._seq_no = str(self._context._seq_no)
        self.log('sequence number is ' + self._context._seq_no)
        self._context._status_file = os.path.join(self._context._status_dir, self._context._seq_no + '.status')
        self._context._settings_file = os.path.join(self._context._config_dir, self._context._seq_no + '.settings')
        self.log("setting file path is" + self._context._settings_file)
        ctxt = None
        ctxt = ext_utils.get_file_contents(self._context._settings_file)
        if ctxt == None:
            error_msg = 'Unable to read ' + self._context._settings_file + '. '
            self.error(error_msg)
            return None

        self.log("JSON config: " + HandlerUtility.redact_protected_settings(ctxt))
        self._context._config = self._parse_config(ctxt)
        return self._context

    def _change_log_file(self):
        self.log("Change log file to " + self._context._log_file)
        # this will change the logging file for all python files that share the same process
        logger.global_shared_context_logger = logger.Logger(self._context._log_file, '/dev/stdout')

    def is_seq_smaller(self):
        return int(self._context._seq_no) <= self._get_most_recent_seq()

    def save_seq(self):
        self._set_most_recent_seq(self._context._seq_no)
        self.log("set most recent sequence number to " + str(self._context._seq_no))

    def exit_if_enabled(self, remove_protected_settings=False):
        self.exit_if_seq_smaller(remove_protected_settings)

    def exit_if_seq_smaller(self, remove_protected_settings):
        if(self.is_seq_smaller()):
            self.log(
                "Current sequence number, " + str(self._context._seq_no) +
                ", is not greater than the sequence number of the most recent executed configuration. Exiting...")
            sys.exit(0)
        self.save_seq()

        if remove_protected_settings:
            self.scrub_settings_file()

    def _get_most_recent_seq(self):
        if (os.path.isfile('mrseq')):
            seq = ext_utils.get_file_contents('mrseq')
            if (seq):
                return int(seq)

        return -1

    def is_current_config_seq_greater_inused(self):
        return int(self._context._seq_no) > self._get_most_recent_seq()

    def get_inused_config_seq(self):
        return self._get_most_recent_seq()

    def set_inused_config_seq(self, seq):
        self._set_most_recent_seq(seq)

    def _set_most_recent_seq(self, seq):
        ext_utils.set_file_contents('mrseq', str(seq))

    def do_status_report(self, operation, status, status_code, message):
        self.log("{0},{1},{2},{3}".format(operation, status, status_code, message))
        tstamp = time.strftime(DateTimeFormat, time.gmtime())
        stat = [{
            "version": self._context._version,
            "timestampUTC": tstamp,
            "status": {
                "name": self._context._name,
                "operation": operation,
                "status": status,
                "code": status_code,
                "formattedMessage": {
                    "lang": "en-US",
                    "message": message
                }
            }
        }]
        stat_rept = json.dumps(stat)
        if self._context._status_file:
            tmp = "%s.tmp" % (self._context._status_file)
            with open(tmp, 'w+') as f:
                f.write(stat_rept)
            os.rename(tmp, self._context._status_file)

    def do_heartbeat_report(self, heartbeat_file, status, code, message):
        # heartbeat
        health_report = '[{"version":"1.0","heartbeat":{"status":"' + status + '","code":"' + code + '","Message":"' + message + '"}}]'
        if ext_utils.set_file_contents(heartbeat_file, health_report) is None:
            self.error('Unable to wite heartbeat info to ' + heartbeat_file)

    def do_exit(self, exit_code, operation, status, code, message):
        try:
            self.do_status_report(operation, status, code, message)
        except Exception as e:
            self.log("Can't update status: " + str(e))
        sys.exit(exit_code)

    def get_name(self):
        return self._context._name

    def get_seq_no(self):
        return self._context._seq_no

    def get_log_dir(self):
        return self._context._log_dir

    def get_handler_settings(self):
        if (self._context._config != None):
            return self._context._config['runtimeSettings'][0]['handlerSettings']
        return None

    def get_protected_settings(self):
        if (self._context._config != None):
            return self.get_handler_settings().get('protectedSettings')
        return None

    def get_public_settings(self):
        handlerSettings = self.get_handler_settings()
        if (handlerSettings != None):
            return self.get_handler_settings().get('publicSettings')
        return None

    def scrub_settings_file(self):
        content = ext_utils.get_file_contents(self._context._settings_file)
        redacted = HandlerUtility.redact_protected_settings(content)
        ext_utils.set_file_contents(self._context._settings_file, redacted)