#!/usr/bin/python3
# -*- coding: utf-8 -*-

####
# Copyright (c) 2018, Intel Corporation
#
# Redistribution and use in source and binary forms, with or without
# modification, are permitted provided that the following conditions are met:
#
#   * Redistributions of source code must retain the above copyright notice,
#     this list of conditions and the following disclaimer.
#   * Redistributions in binary form must reproduce the above copyright
#     notice, this list of conditions and the following disclaimer in the
#     documentation and/or other materials provided with the distribution.
#   * Neither the name of Intel Corporation nor the names of its contributors
#     may be used to endorse or promote products derived from this software
#     without specific prior written permission.
#
# THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
# AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
# IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
# DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT OWNER OR CONTRIBUTORS BE LIABLE
# FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
# DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR
# SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER
# CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
# OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
# OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
####


####
#  CHANGELOG
#
#  1.0
#  Parsing NLOG binary depending on dictionary given
#  Distinguishing between v1 and v2 NLOGs
#
#  1.1
#  Added detecting of NLOG wrapping and displaying entries in correct order
#
#  1.2
#  Remove Log Level Column
#  Add String Hash column
#
#  1.3
#  Don't sort by default
#  Add parameter to attempt sorting
#  Print parser version
#  Print message to tell consumer if the buffer may have wrapped
######

# NOTE layouts for processedData
#      for V1: [moduleId, logLine, argCount, fileName, outputString, logLevel]
#      for V2: [argCountDict, outputStringDict, sourceFile, logLevel]

import re, sys, os
import struct
import argparse
from operator import itemgetter

PARSER_VERSION_STRING = "1.3"

ARG_COUNT_MASK     = 0xFF
ARG_COUNT_OFFSET   = 0
LINE_NUMBER_MASK   = 0xFFFF
LINE_NUMBER_OFFSET = 8
MODULE_ID_MASK     = 0xFF
MODULE_ID_OFFSET   = 24

# magic number that shows we're reading a version #
HEADER_IDENTIFIER = 0xB605A5
HEADER_IDENTIFIER_MASK = 0xFFFFFF
VERSION_OFFSET = 24

FDL_VERSION_BOUNDARY = 256 # every 256 bytes should be a version dword
FDL_CHUNK_SUZE       = 256 # each chunk is 256 bytes
FDL_PARSING_COMPLETE = -1
FDL_PADDING_VALUE = 0
FDL_VERSION_1 = 1
FDL_VERSION_2 = 2

# Last chunk is full log buffer - chunk size
FDL_FINAL_CHUNK_OFFSET = 1024 * 1024 - FDL_CHUNK_SUZE

# Log string info
LOG_HEADER = "STRING HASH ::  TIMESTAMP  ::             FILE             :: LOG"
LOG_HEADER_LINE_BREAK = "====================================================================================="
FORMAT_STRING = "%11d :: %11d :: %28s :: " # log message

# since it's possible for FDL dumps to have multiple FDL versions
# we need to dynamically change what we're parsing
gCurrentParsingVersion = FDL_VERSION_1
gStringDictionaryV1 = {}
gStringDictionaryV2 = {}

class DictionaryStatus():
    """
    Container for dictionary enablement status

    props:
        bool enableV2: Version 2 dictionary is enabled
        bool enableV1: Version 1 dictionary is enabled (deprecated)
    """
    def __init__(self):
        self.enableV2 = False
        self.enableV1 = False

###############################################################################
###############################################################################
###############################################################################
# The input data takes the form of XXXX XXXX ... XXXX where XXXX is a hex number
# The numbers in Sequence are
#   STRING_HASH ARGS*
# The output of this module is:
#    STRING HASH :: TIMESTAMP ::              FILE            :: LOG
#    See format string above
# eg.
#  0 :: kechika_river_pmic_driver.c ::   ERROR :: "PMIC Manufacture ID: 0x82    Product Stepping: 0x12"
#
# Open the file for the user as read binary
# String data file opens as second sysarg
###############################################################################
###############################################################################
###############################################################################

def printLogHeader(sortingEnabled):
    """
    Prints out header with column names and some metadata on the args used.
    """
    print("Log Parser Version: {}".format(PARSER_VERSION_STRING))
    # Only print when sorting is enabled
    # Currently the feature is not completely reliable so we should have
    # a note when it's enabled
    if (sortingEnabled):
        print("Sorting is enabled. Check for any invalid timestamps")
    print(LOG_HEADER)
    print(LOG_HEADER_LINE_BREAK)

def checkForLogWrap(fp):
    """
    Prints a message to warn log consumers that the data may have wrapped
    """
    # Store current pointer to restore later to prevent bad side effects
    currentPointer = fp.tell()
    try:
        # Set pointer to the final log chunk
        # If the log has reached this point, we'll see some metadata here
        # so if it's empty or it's all 0's then we know the log buffer
        # has not wrapped. Which means the logs are all ordered
        fp.seek(FDL_FINAL_CHUNK_OFFSET)
        data = fp.read(FDL_CHUNK_SUZE)
        foundData = False
        for byte in data:
            # In python3 byte is already an integer since the file is opened as a binary file
            # In python2 it's treated as a string. So cover both cases to be safe
            if (byte) and (byte != "\0"):
                foundData = True
                break
        if (foundData):
            print("Potential log wrap detected. Data found in last chunk")
        else:
            print("No data in last chunk. Logs are printed in order")
    except Exception as e:
        print("Unable to check for log wrap")
    finally:
        # Don't expect the check to fail, but this ensures
        # any bugs with this function don't cause us to lose data
        # during parsing.
        fp.seek(currentPointer)

def checkFdlChunkVersion(dword):
    """
    Checks the given value for the FDL version
    This should be run on the first dword of each 128
    byte chunk
    """
    identifier = dword & HEADER_IDENTIFIER_MASK
    version = dword >> VERSION_OFFSET
    if identifier == HEADER_IDENTIFIER:
        return version
    else:
        return FDL_VERSION_1

def readDwordFromFdl(fp):
    """
    Returns the next dword from the FDL dump
    Returns FDL_PARSING_COMPLETE when parsing is complete

    Checks if the byte we're on should be a header or not.
    If it is a header, then it will set gCurrentParsingVersion as well.
    """
    global gCurrentParsingVersion
    # every 256 bytes should be an FDL header
    alignment = fp.tell() % FDL_VERSION_BOUNDARY
    data = fp.read(4)

    if data == '':
        # print 'No more data exists within the binary blob'
        return FDL_PARSING_COMPLETE
    else:
        try:
            fullDwordUnpack = struct.unpack('=L', data)
            value = fullDwordUnpack[0]
        except struct.error:
            print('FDL data not 4 byte aligned, log entries should be in 4 byte chunks')
            return FDL_PARSING_COMPLETE

    # On the alignment, check the version
    if alignment == 0:
        gCurrentParsingVersion = checkFdlChunkVersion(value)

        # For v1, the data is actually a log, so return that data
        if (gCurrentParsingVersion == FDL_VERSION_1):
            return value
        # otherwise, it was a header id, so return the next dword
        else:
            # Go recursion! Since it's not on an alignment anymore this will
            # go into the else case to just return the next value
            return readDwordFromFdl(fp)

    # if not on the alignment, then just return the raw data
    else:
        return value

def parseLog(fp, enableV1, enableV2, sort=False):
    """
    Main log parsing. Continue reading lines until the read function
    sees we're at the end and bails
    """

    # if we don't have a v2 dictionary then we can't parse v2 logs
    # this bool let's us know if we should print the message that we found
    # logs we can't parse.
    logV2Disabled = True

    previousTimestamp = 0
    #Single part of text (may consists of many lines) to be sorted
    textToWrite = ""
    #List of text parts
    textBlocksList = []
    TIMESTAMP_VAL_MAX = 2**32-1
    #Some value which satisfies BOTH conditions below:
    # 1) converted to epoch time is to small to be considered as correct value
    # 2) converted to boot timer value is to big to be considered as correct value
    #epoch time for 01:00:00, 01.01.1971
    #seconds equivalent of 1 year
    TIMESTAMP_RELIABLE_VAL_MIN = (365 * 24 * 60 * 60)
    lastValidTimestamp = TIMESTAMP_VAL_MAX

    while True:
        dword = readDwordFromFdl(fp)
        if (dword == FDL_PARSING_COMPLETE):
            break;

        if gCurrentParsingVersion == FDL_VERSION_1:
            logV2Disabled = True # we're inside a new chunk, so set this back to true
            argCount   = (dword >> ARG_COUNT_OFFSET) & ARG_COUNT_MASK
            lineNumber = (dword >> LINE_NUMBER_OFFSET) & LINE_NUMBER_MASK
            moduleId   = (dword >> MODULE_ID_OFFSET) & MODULE_ID_MASK

            # if it's all 0's, nothing to do
            if (argCount == lineNumber == moduleId == FDL_PADDING_VALUE):
                continue
            else:
                hasV1Data = False
                if (enableV1):
                    if (moduleId, lineNumber) in gStringDictionaryV1:
                        hasV1Data = True
                        processedData = gStringDictionaryV1[(moduleId, lineNumber)]

                timestamp = readDwordFromFdl(fp)
                if (timestamp == FDL_PARSING_COMPLETE):
                    textToWrite += "Reached end of FDL data unexpectedly!\n"
                    break;

                # Print a general log for these. Users will need to manually decode them.
                if (enableV1 and hasV1Data):
                    argCount = processedData[2]
                    logString = FORMAT_STRING + processedData[4]
                    logData = [0, timestamp, processedData[3]]
                else:
                    logString = FORMAT_STRING + "V1 Log module: 0x%X, line: %d, args: "
                    logData = [0, timestamp, '-', '-', moduleId, lineNumber]
                # read args and append to the log
                for x in range(argCount):
                    arg = readDwordFromFdl(fp)
                    if (arg == FDL_PARSING_COMPLETE):
                        textToWrite += "Reached end of FDL data unexpectedly!\n"
                        break;
                    if (not enableV1) or (not hasV1Data):
                        # with V1 enabled we already have a format string, so don't need this.
                        logString += "0x%X "
                    logData.append(arg)
                linetowrite = logString % tuple(logData)
                textToWrite += linetowrite + "\n"

        elif gCurrentParsingVersion == FDL_VERSION_2:
            stringHash = dword

            if stringHash == FDL_PADDING_VALUE:
                continue
            else:
                if not enableV2:
                    # Since we'll most likely hit this for every Dword in this chunk,
                    # only print the log once per chunk
                    if logV2Disabled:
                        # keep the same log format
                        textToWrite += (FORMAT_STRING + "Found version 2 log area, but don't have the dictionary to parse it\n") % (0, 0, '-')
                        logV2Disabled = False
                    # If we don't have a V2 dictionary we don't know how many args to read
                    # so just let parsing continue.
                    continue
                if stringHash not in gStringDictionaryV2:
                    textToWrite += "Hash %d not found in dictionary\n" % stringHash
                    continue

                timestamp = readDwordFromFdl(fp)
                if (timestamp == FDL_PARSING_COMPLETE):
                    textToWrite += "Reached end of FDL data unexpectedly!\n"
                    break;
                if enableV2:
                    processedData = gStringDictionaryV2[stringHash]
                    argCount = processedData[0]
                    logString = FORMAT_STRING + processedData[1]
                    logData = [stringHash, timestamp, processedData[2]]
                    for x in range(argCount):
                        arg = readDwordFromFdl(fp)
                        if (arg == FDL_PARSING_COMPLETE):
                            textToWrite += "Reached end of FDL data unexpectedly!\n"
                            break;
                        logData.append(arg)
                    # Fill in variables in logstring with logData array
                    linetowrite = logString % tuple(logData)
                    if timestamp < previousTimestamp and previousTimestamp > TIMESTAMP_RELIABLE_VAL_MIN:
                        textBlocksList.append((textToWrite, previousTimestamp))
                        textToWrite = ""
                    if previousTimestamp > TIMESTAMP_RELIABLE_VAL_MIN:
                        lastValidTimestamp = previousTimestamp
                    textToWrite += linetowrite + "\n"
                    previousTimestamp = timestamp

    textBlocksList.append((textToWrite, lastValidTimestamp))
    if (sort):
        # Sort functionality depends on host timestamps. If host time is inaccurate, then the sorting
        # will be inaccurate
        textBlocksList.sort(key=itemgetter(1))
    for textBlock in textBlocksList:
        print(textBlock[0])

def parseDictionary(dictionaryV2=None, dictionaryV1=None):
    """
    Parse the dictionary into module's dictionary struct

    Returns:
        Instance of DictionaryStatus
        you may check status.enableV2/status.enableV1 to see which dictionaries are enabled
    """

    status = DictionaryStatus()

    if (dictionaryV1 is None) and (dictionaryV2 is None):
        print("At least one dictionary is required. v1 or v2.")
        return status

    # To track status of dictionary parsing
    success = True
    # Setup V2 dictionary
    if dictionaryV2:
        with open(dictionaryV2, 'r') as my_file:
            processedSources = my_file.readlines()
            for idx, line in enumerate(processedSources):
                    # First line of dictionary is the version
                    if (idx == 0):
                        match = re.search(r"version=(\d)", line)
                        if not match:
                            # Parsing failed, save status
                            print("Invalid version 2 dictionary")
                            success = False
                            break
                        else:
                            if match.group(1) != "2":
                                # Parsing failed, save status
                                print("Invalid version 2 dictionary")
                                success = False
                                break
                        continue
                    else:
                        # Match data looking for STRING_HASH, ARG_COUNT, DATA_STRING
                        assembledLoggingString = ""
                        assembledLoggingString = assembledLoggingString + line[:-1]
                        match = re.search(r"(\d+),(\d+),([A-Z]*),([a-z_0-9]+\.c),(\".*\")", assembledLoggingString)
                        if match:
                            stringHashDict = int(match.group(1))
                            argCountDict = int(match.group(2))
                            logLevel = match.group(3)
                            sourceFile   = match.group(4)
                            outputStringDict = match.group(5)
                            gStringDictionaryV2[stringHashDict] = [argCountDict, outputStringDict, sourceFile, logLevel]
                        else:
                            # use idx + 1 since idx is 0 based but line #s are 1 based.
                            # Parsing failed, save status
                            print('Failed string dictionary on line %d: %s' % (idx + 1, assembledLoggingString))
                            break
            # Dictionary parsing complete update enabled status
            status.enableV2 = success

    # To track status of dictionary parsing
    success = True
    # Setup V1 dictionary
    if dictionaryV1:
        status.enableV1 = True
        with open(dictionaryV1, 'r') as my_file:
            processedSources = my_file.readlines()
            for line in processedSources:
                # Match data looking for LOG_LEVEL, MODULE_ID, LOG_LINE, ARG_COUNT, FILE_NAME, DATA_STRING
                match = re.search("NLOG_(\w+),\s+(\d+),\s+(\d+),\s+(\d+),\s+(.*),\s+(\".*\")", line)
                if match:
                    logLevel = match.group(1)
                    moduleId = int(match.group(2))
                    logLine = int(match.group(3))
                    argCount = int(match.group(4))
                    fileName = match.group(5)
                    outputString = match.group(6)
                    gStringDictionaryV1[(moduleId, logLine)] = [moduleId, logLine,
                            argCount, fileName, outputString, logLevel]
                else:
                    print('Failed string dictionary on: ' + line)
                    success = False
                    break
            # Dictionary parsing complete update enabled status
            status.enableV1 = success

    return status

def parse(fdl_file, dictionaryV2=None, dictionaryV1=None, sort=False):
    if (fdl_file is None):
        print("Missing the Firmware Debug Log.")
        return -1

    dictionaryStatus = parseDictionary(dictionaryV2, dictionaryV1)
    if (not dictionaryStatus.enableV1) and (not dictionaryStatus.enableV2):
        print("Error loading dictionary")
        return -1

    with open(fdl_file, 'rb') as data_f:
        directory, file_b = os.path.split(fdl_file)
        checkForLogWrap(data_f)
        printLogHeader(sort)
        parseLog(data_f, dictionaryStatus.enableV1, dictionaryStatus.enableV2, sort)

def parse_args():
    ap = argparse.ArgumentParser()
    ap.add_argument("--log", dest="logDataFile", help="Path to Firmware Debug Log Data File", default=None)
    ap.add_argument("--dict", dest="dictionaryV2", help="Path to Firmware Dictionary File", default=None)
    ap.add_argument("--v1", dest="dictionaryV1", help="Path to (deprecated) Version 1 Firmware Dictionary File", default=None)
    ap.add_argument("--sort", help="Attempt to sort logs by host timestamp (Currently not reliable)", action="store_true", default=False)
    ap.add_argument("--version", help="Print Version", action="store_true")
    return ap.parse_args()


def main():
    args = parse_args()
    if args.version:
        print("Version: " + PARSER_VERSION_STRING)
    else:
        logDataFile      = args.logDataFile
        dictionaryV2File = args.dictionaryV2
        dictionaryV1File = args.dictionaryV1
        sort = args.sort
        parse(logDataFile, dictionaryV2File, dictionaryV1File, sort)


if __name__ == "__main__":
    sys.exit(main())
