ZblLogReader.cpp

Go to the documentation of this file.

/*
 * Zuble - A run-time system for QML/Javascript applications
 * Copyright (C) 2015 Bob Dinitto
 *
 * Filename:   ZblLogReader.cpp
 * Created on: 11/22/2015
 * Author:     Bob Dinitto
 *
 * Zuble is free software; you can redistribute it and/or
 * modify it under the terms of the GNU Lesser General Public
 * License as published by the Free Software Foundation; either
 * version 2.1 of the License, or (at your option) any later version.
 *
 * This library is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
 * Lesser General Public License for more details.
 *
 * You should have received a copy of the GNU Lesser General Public
 * License along with this library; if not, write to the Free Software
 * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301  USA
 *
 */

#include "ZblLogReader.h"
#include "ZLogViewport.h"
#include "ZApplication.h"
#include "ZLogReader.h"
#include "ZblLogLinkList.h"
#include "ZblLogManager.h"
#include "ZblLogScanner.h"
#include "ZblLogSearch.h"
#include <QThread>
#include <QtQml>


namespace Zbl {

ZBL_DEFINE_LOGGED_OBJECT(Zbl::ZblLogReader)

QThread* ZblLogReader::m_readerThread = 0;

QMutex ZblLogReader::m_lock(QMutex::Recursive);

int ZblLogReader::m_readerCount = 0;

qint64 ZblLogReader::m_defaultPageSize = 10000;

int ZblLogReader::m_recordRoleCount = -1;

const int ZblLogReader::m_updateBatchSize = 10;

const qint64 ZblLogReader::m_maxLineSize = 20000;




ZblLogReader::ZblLogReader(QObject *parent) :
    QObject(parent),
    //m_logModel(NULL),
    m_fileActive(false),
    m_firstRecordPos(-1),
    m_timerID(0)
{


}

ZblLogReader::~ZblLogReader()
{

}


void ZblLogReader::zInit(int logRecordRoleCount)
{
    ZBL_REGISTER_LOGGED_OBJECT

    qmlRegisterUncreatableType<ZblLogReader>("org.zuble.qml", 1, 0,
                    "ZblLogReader", "ZblLogReader is an internal Zuble type. Use ZLogReader instead.");

    // TBD WE'RE CALLING THIS TWICE FOR ZLogViewport!

    qmlRegisterUncreatableType<ZLogViewport>("org.zuble.qml", 1, 0,
                    "ZLogViewport", "Use ZLogReader to create ZLogViewport objects.");

    m_recordRoleCount = logRecordRoleCount;

}

void ZblLogReader::initializeMetadata()
{
    if(m_firstRecordPos != -1)
        return;

    QByteArray metaRecord;

    zDebug() << "Loading log file metadata.";

    m_inputFile.seek(0);
    metaRecord = m_inputFile.readLine(m_maxLineSize);
    m_firstRecordPos = m_inputFile.pos();

    if(metaRecord.size() == 0)
    {
        zWarning() << "Log file id and metadata not available.";
        return;
    }

    int uuidEndPos = metaRecord.indexOf('}');

    if(uuidEndPos == -1)
    {
        zWarning() << "Log file id not available.";
        return;
    }

    QUuid uuid(metaRecord.left(uuidEndPos+1));

    if(uuid.isNull())
    {
        zWarning() << "Log file id invalid format.";
        return;
    }
    else
    {
        zDebug() << "Log file id: " << uuid.toByteArray();

        m_uuid = uuid;
    }

    if(metaRecord.size() <= uuidEndPos+1)
    {
        zWarning() << "Log file metadata not available.";
        return;
    }

    QJsonParseError er;

    QByteArray metaBytes = metaRecord.right(metaRecord.size() - uuidEndPos - 1);

    zDebug() << "Log file metadata: " << metaBytes;

    QJsonDocument doc = QJsonDocument::fromJson(metaBytes, &er);

    if(er.error != QJsonParseError::NoError)
    {
        zWarning() << "Log file metadata parse error: "
                    << er.errorString();

        return;
    }

    zDebug() << "Log file metadata parsed OK.";

    if(!doc.isObject())
    {
        zWarning() << "Log file metadata format error. Metadata must be a JSON object.";
        return;
    }

    QJsonObject jsonObj = doc.object();

    m_metadata = jsonObj.toVariantMap();
}


void ZblLogReader::timerEvent(QTimerEvent * event)
{
    //zDebug() << "Got timerEvent function call";

    if(m_fileActive)
    {
        //zDebug() << "Emitting notifyFileSize signal";

        emit notifyFileSize(m_inputFile.size());
    }
}

ZblLogReader* ZblLogReader::newLogReader()
{

    {
        QMutexLocker lock(&m_lock);
        if(!m_readerThread)
        {
            m_readerThread = new QThread();
            m_readerThread->start();
        }
        m_readerCount++;
    }

    ZblLogReader* newReader = new ZblLogReader();

    newReader->moveToThread(m_readerThread);

    return newReader;

}

void ZblLogReader::openFile(const QString& filePath, QVariantMap contextMap)
{
    if(m_fileActive)
        close();

    QString err;

    m_inputFile.setFileName(ZApplication::resolvePath(filePath, false));

    m_fileActive = m_inputFile.open(QFile::ReadOnly | QIODevice::Text);

    if(!m_fileActive)
    {
        err = m_inputFile.errorString();

        zCritical() << "OpenFile error: " << err
                 << ", error =" << m_inputFile.error();
    }
    else
    {
        initializeMetadata();
    }


    emit openComplete(m_fileActive, err, contextMap);

    m_timerID = startTimer(5000);

}

void ZblLogReader::close()
{
    if(m_fileActive)
    {
        if(m_timerID != 0)
        {
            killTimer(m_timerID);
            m_timerID = 0;
        }

        m_fileActive = false;
        m_inputFile.close();
    }
}

void ZblLogReader::loadViewport(QObject *viewport,
        qint64 seekPosition,
        qint64 viewportSize,
        ZblLogSearchParams searchParams,
        bool loadMarkupColumn,
        QVariantMap contextMap)
{

    QString errMsg;

    qint64 rowsFound = 0;
    qint64 rowsStored = 0;
    bool eof = false;

    ZLogViewport* zViewport = qobject_cast<ZLogViewport*>(viewport);

    if(!zViewport)
    {
        errMsg = "You must pass a ZLogViewport object as first argument.";

        emit loadComplete(viewport, searchParams, eof, errMsg, contextMap);

        return;
    }

   ZTableModel* model = zViewport->getZModel();

   model->clearData();

   zViewport->m_optimalCount = viewportSize;

   if(seekPosition > m_inputFile.size())
   {
       // TBD: ENDING should not necessarily be an error.

       errMsg = "Log file doesn't contain requested rows.";

       emit loadComplete(viewport, searchParams, eof, errMsg, contextMap);
       emit zViewport->loadComplete(eof, errMsg, contextMap);

       return;
   }


    errMsg = loadRowsAhead(
                zViewport,
                seekPosition,
                viewportSize,
                false,
                &searchParams,
                loadMarkupColumn,
                rowsFound,
                rowsStored,
                eof
                );

    //emit loadComplete(viewport, searchParams, eof, errMsg, contextMap);

    // TBD: ZblLogBkSearch will connect the loadComplete signal of it's background
    // viewport to it's loadComplete processing function no need to pass searchparams anymore.

    emit zViewport->loadComplete(eof, errMsg, contextMap);

}

QString ZblLogReader::loadRowsAhead(
        ZLogViewport* viewport,
        qint64 seekPos,
        qint64 rowCount,
        bool truncate,
        const ZblLogSearchParams* searchParams,
        bool loadMarkupColumn,
        qint64& foundCount,
        qint64& storedCount,
        bool& eof
        )
{
    foundCount = 0;
    storedCount = 0;
    eof = false;

    qint64 parsedLines = 0;

    qint64 currentIndex = 0;
    const qint64 finalIndex = rowCount - 1;

    //qint64 nextRecordIdIndex = 0;
    //QMap<qint64, QStringList> bookmarks;

    QByteArray ba;
    QString errMsg;
    ZDataRow cellBuffer;
    ZblLogError logError;

    ZblLogScanner::controlFlags flags = ZblLogScanner::controlFlags(0);

    if(loadMarkupColumn && searchParams->origin() != -1)
        flags = ZblLogScanner::HighlightSearchText;

    ZblLogScanner scanner(searchParams, flags, loadMarkupColumn);

    if(seekPos == 0)
    {
        zDebug() << "Skipping log file metadata.";
        m_inputFile.seek(0);
        m_inputFile.readLine(m_maxLineSize);
    }
    else
    {
        m_inputFile.seek(seekPos);
    }

    while(true)
    {
        ba = m_inputFile.readLine(m_maxLineSize);

        if(ba.isEmpty())
        {
            eof = m_inputFile.atEnd();

            if(!eof && (currentIndex < finalIndex))
            {
                errMsg = "Log file doesn't contain requested rows.";
            }

            if(!cellBuffer.isEmpty())
            {
                storeViewportData(cellBuffer, viewport, truncate);
                storedCount += parsedLines;
                parsedLines = 0;
            }

            break;
        }

        foundCount++;

        parseNextFileRecord(viewport, ba, seekPos, scanner, cellBuffer, logError);

        // TBD: add a method to input cellBuffer and search text list (role, index, length)
        // and output a second cell buffer containing rich text; load rich text cell buffer
        // into col 1 of data model. do this only if search mode = true.

        if(logError.errorType == ZblLogError::PARSE_ERROR)
        {
            errMsg = "JSON parse error at seek position: %1, %2";

            errMsg = errMsg.arg(seekPos);
            errMsg = errMsg.arg(logError.parseError.errorString());

            zWarning() << errMsg;
        }
        else if(logError.errorType == ZblLogError::NOTARRAY_ERROR)
        {
            errMsg = "Log file format error at seek position: %1, "
                    "Each Zuble log record must be a JSON array.";

            errMsg.arg(seekPos);

            zWarning() << errMsg;
        }
        else if(logError.errorType == ZblLogError::FIELDCOUNT_ERROR)
        {
            errMsg = "Log file format error at seek position: %1, "
                    "Each Zuble log record must be a JSON array.";

            errMsg.arg(seekPos);

            zWarning() << errMsg;
        }
        else
        {
            parsedLines++;

            //zDebug() << "READING RECORD: " << recordID;

        }

        if((rowCount != -1) && (currentIndex == finalIndex))
        {
            storeViewportData(cellBuffer, viewport, truncate);
            storedCount += parsedLines;
            parsedLines = 0;
            break;
        }

        if(currentIndex % m_updateBatchSize == 0)
        {
            storeViewportData(cellBuffer, viewport, truncate);
            storedCount += parsedLines;
            parsedLines = 0;
        }

        seekPos = m_inputFile.pos();
        currentIndex++;
    }

    return errMsg;
}

void ZblLogReader::parseNextFileRecord(
        ZLogViewport* viewport,
        const QByteArray& ba,
        qint64 seekPos,
        ZblLogScanner& logScanner,
        ZDataRow& cellBuffer,
        ZblLogError& logError
        )
{
    logError.errorType = logError.NO_ERROR;
    logError.formatErrorString.clear();

    if(ba.isEmpty())
        return;

    QJsonDocument doc = QJsonDocument::fromJson(ba, &logError.parseError);

    if(logError.parseError.error != QJsonParseError::NoError)
    {
        logError.errorType = logError.PARSE_ERROR;
        return;
    }

    if(!doc.isArray())
    {
        logError.errorType = logError.NOTARRAY_ERROR;
        logError.formatErrorString =
                "Each Zuble log record must be a JSON array "
                "containing %1 cells per row.";
        logError.formatErrorString.arg(m_recordRoleCount);
        return;
    }

    QJsonArray ja = doc.array();

    const int arraySize = ja.size();

    if(arraySize != m_recordRoleCount)
    {
        logError.errorType = logError.FIELDCOUNT_ERROR;
        logError.formatErrorString =
                "Can't load log record: Record size mismatch! Expecting %1 "
                "cells per row but file has %2.";
        logError.formatErrorString.arg(m_recordRoleCount, arraySize);
        return;
    }

    QVariantList va(ja.toVariantList());

    // insert additional model roles for log viewer use only

    qint64 recordID = va.at(0).toLongLong();

    //va.append(recordID);

    va.append(QVariant(seekPos));
    va.append(QVariant(ba.size()));

    // TDB: we must move this call to ZLogReader to foreground thread!!!
    //va.append(QVariant(viewport->getZReader()->getBookmarkNames(recordID))); // TBD: SLOW!!!!!

    va.append(QVariant("")); // dummy placeholder for bookmark names data

    cellBuffer.append(va);

    if(logScanner.outputMarkupColumn())
    {
        if(logScanner.outputHighlightedText())
        {
            va = logScanner.markupOrdinalRoleList(va);

        }
        cellBuffer.append(va);
    }

    return;
}

void ZblLogReader::storeViewportData(
        ZDataRow& cellData,
        ZLogViewport* viewport,
        bool truncate)
{
    ZTableModel* model = viewport->getZModel();
    model->appendCells(cellData, truncate);
    cellData.clear();
}

int ZblLogReader::parseAndStoreViewportData(
        zRowBuffer& logRecords,
        zSeekBuffer& seekPositions,
        qint64 rowCount,
        ZLogViewport* viewport,
        ZblLogScanner& logScanner)
{

    const qint64 recordCount = logRecords.size();

    zDebug() << "Record count = " << recordCount;
    zDebug() << "Rows needed = " << rowCount;

    if(recordCount == 0 || rowCount == 0)
    {
        zDebug() << "rows stored = " << 0;
        return 0;
    }

    int rowsStored = -1;

    ZDataRow cellBuffer;
    ZblLogError logError;

    qint64 index = recordCount - rowCount;

    if(index < 0)
        index = 0;

    zDebug() << "index = " << index;

    //const int lastIndex = recordCount - 1;

    rowsStored = recordCount - index;

    int lostRecords;

    for(lostRecords = 0; index < recordCount; index++)
    {
        //zDebug() << "Saving record at index: " << index;

        qint64 seekPos = seekPositions.at(index);

        parseNextFileRecord(
                viewport,
                logRecords.at(index),
                seekPos,
                logScanner,
                cellBuffer,
                logError
                );

        if(logError.errorType == ZblLogError::PARSE_ERROR)
        {
            lostRecords++;

            QString errMsg = "JSON parse error at seek position: %1, %2";

            errMsg.arg(seekPos).arg(logError.parseError.errorString());

            zWarning() << errMsg;
        }
        else if(logError.errorType != ZblLogError::NO_ERROR)
        {
            lostRecords++;

            QString errMsg = "Log file format error at seek position: %1, %2";

            errMsg.arg(seekPos).arg(logError.formatErrorString);

            zWarning() << errMsg;
        }
        //TBD: ARE WE MISSING SOME ERROR CONDITIONS HERE?
    }

    rowsStored -= lostRecords;

    zDebug() << "rows stored = " << rowsStored;

    ZTableModel* model = viewport->getZModel();

    zDebug() << "Saving log records to data model, cell count: " << cellBuffer.size();

    model->prependCells(cellBuffer, true);

    return rowsStored;
}


QString ZblLogReader::loadRowsBehind(
        ZLogViewport* viewport,
        qint64 seekPos,
        qint64 rowCount,
        const ZblLogSearchParams* searchParams,
        bool loadMarkupColumn,
        qint64& foundCount,
        qint64& storedCount,
        bool& bof
        )
{
    //qint64 currentIndex = 0;
    //const qint64 finalIndex = rowCount - 1;

    foundCount = 0;
    storedCount = 0;
    bof = false;

    //int startSeek = seekPos;
    qint64 chunkSize = 1024; // number of bytes to fetch
    zRowBuffer rowBuffer;     // raw (JSON array) data row buffer
    zSeekBuffer seekBuffer; // seek positions for rowBuffer
    bool moreData = true; // becomes false when first row in file has been read

    QByteArray ba;      // temporary row storage
    QString errMsg;     // holds error message
    //ZDataRow cellBuffer; // multi-row list of data model cells

    qint64 rowsNeeded = rowCount; // rows left to find

    ZblLogScanner::controlFlags flags = ZblLogScanner::controlFlags(0);

    if(loadMarkupColumn && searchParams->origin() != -1)
        flags = ZblLogScanner::HighlightSearchText;

    ZblLogScanner scanner(searchParams, flags, loadMarkupColumn);


    //static qint64 firstRecordPos = -1;

    //initializeMetadata();

    while(true)
    {
        // seek back from current pos by x bytes

        bool discard = true;

        qint64 startSeek = seekPos;

        seekPos = seekPos - chunkSize;

        zDebug() << "Seeking back - startSeek = " << startSeek
                    << ", chunkSize = " << chunkSize;

        if(seekPos <= 0)
        {
            zDebug() << "Seek at or past beginning of file: " << seekPos;
            seekPos = 0;
            moreData = false;
            discard = false;
            bof = true;
        }

        m_inputFile.seek(seekPos);

        // readline forward -  discard potentially incomplete lines, accumulate remainder

        while(seekPos < startSeek)
        {
            zDebug() << "Reading next line at seekPos:" << seekPos;

            ba = m_inputFile.readLine(m_maxLineSize);

            if(!ba.isEmpty() && !discard)
            {
                zDebug() << "Saving line at seekPos: " << seekPos;

                rowBuffer.push_back(ba);
                seekBuffer.push_back(seekPos);
            }
            else
            {
                zDebug() << "Discarding line at seekPos: " << seekPos;
                discard = false;
            }

            seekPos = m_inputFile.pos();
        }

        const int rowsFound = rowBuffer.size();

        zDebug() << "Rows found = " << rowsFound;
        zDebug() << "Rows needed = " << rowsNeeded;

        const int rowsStored = parseAndStoreViewportData(
                    rowBuffer, seekBuffer, rowsNeeded, viewport, scanner);

        // here

        foundCount += rowsFound;
        storedCount += rowsStored;

        if(rowsStored >= rowsNeeded)
            break;
        else if(!moreData)
            break;

        rowsNeeded -= rowsFound;

        zDebug() << "Rows left to fetch: " << rowsNeeded;

        chunkSize *= 2;

        if(rowsFound)
        {
            seekPos = seekBuffer.at(0);
            zDebug() << "Setting new seekPos: " << seekPos;
        }
        else
        {
            zDebug() << "Not setting new seekPos: " << seekPos;
        }

        rowBuffer.clear();
        seekBuffer.clear();

    }

    return errMsg;
}

void ZblLogReader::move(
        QObject *viewport,
        qint64 recordCount,
        qint64 seekIndex,
        bool forward,
        ZblLogSearchParams searchParams,
        bool loadMarkupColumn
        )
{
    ZLogViewport* zViewport = qobject_cast<ZLogViewport*>(viewport);

    QString errMsg;

    qint64 rowsFound = 0;
    qint64 rowsStored = 0;
    bool eod = false;

    if(!zViewport)
    {
        errMsg = "You must pass a ZLogViewport object as first argument.";
        emit zViewport->moveComplete(rowsFound, rowsStored, eod, errMsg);
        return;
    }

    if(forward)
    {
        //m_inputFile.seek(seekIndex);

        errMsg = loadRowsAhead(
                    zViewport,
                    seekIndex,
                    recordCount,
                    true,
                    &searchParams,
                    loadMarkupColumn,
                    rowsFound,
                    rowsStored,
                    eod
                    );
    }
    else
    {
        errMsg = loadRowsBehind(
                    zViewport,
                    seekIndex,
                    recordCount,
                    &searchParams,
                    loadMarkupColumn,
                    rowsFound,
                    rowsStored,
                    eod
                    );
        //zDebug() << errMsg;
    }

    // force blocking call to ensure model update complete
    zViewport->getZModel()->sync();

    emit zViewport->moveComplete(rowsFound, rowsStored, eod, errMsg);
}

void ZblLogReader::loadRecordLinkMessageText(
        QObject* searchmark,
        QVariant links)
{
    ZblLogSearch* search = qobject_cast<ZblLogSearch*>(searchmark);

    if(!search)
    {
        zWarning() << "Programming error: searchmark parameter must be "
                      "a ZLogSearch object.";
        return;
    }

    ZblLogLinkList logLinks = links.value<Zbl::ZblLogLinkList>();
    ZblLogLinkList results;

    QByteArray ba;
    QString errMsg;
    ZDataRow cellBuffer;
    ZblLogError logError;
    bool eof;

    for(int i=0; i < logLinks.m_links.count(); i++)
    {
        logError.errorType = ZblLogError::NO_ERROR;

        const ZblLogLinkList::LinkNode& nextNode = logLinks.m_links.at(i);

        zDebug() << "link message id = " << nextNode.m_index << ", seek = " << nextNode.m_value;

        qint64 seekPos = nextNode.m_value.toLongLong();


        if(seekPos == 0)
        {
            zDebug() << "Skipping log file metadata.";
            m_inputFile.seek(0);
            m_inputFile.readLine(m_maxLineSize);
        }
        else
        {
            m_inputFile.seek(seekPos);
        }

        ba = m_inputFile.readLine(m_maxLineSize);

        if(ba.isEmpty())
        {
            eof = m_inputFile.atEnd();
            break;
        }

        QJsonDocument doc = QJsonDocument::fromJson(ba, &logError.parseError);

        if(logError.parseError.error != QJsonParseError::NoError)
        {
            logError.errorType = logError.PARSE_ERROR;
            zWarning() << "JSON parse error reading log file at seekposition "
                       << seekPos << ": " << logError.parseError.errorString();
            continue;
        }
        else if(!doc.isArray())
        {
            logError.errorType = logError.NOTARRAY_ERROR;
            logError.formatErrorString =
                    "Each Zuble log record must be a JSON array "
                    "containing %1 cells per row.";
            logError.formatErrorString = logError.formatErrorString.arg(m_recordRoleCount);

            zWarning() << "JSON format error reading log file at seekposition "
                       << seekPos << ": " << logError.formatErrorString;
            continue;
        }

        QJsonArray ja = doc.array();

        const int arraySize = ja.size();

        if(arraySize != m_recordRoleCount)
        {
            logError.errorType = logError.FIELDCOUNT_ERROR;
            logError.formatErrorString =
                    "Can't load log record: Record size mismatch! Expecting %1 "
                    "cells per row but file has %2.";
            logError.formatErrorString.arg(m_recordRoleCount, arraySize);
            return;
        }

        QJsonValue messageValue = ja.at(ZblLogManager::LogFieldMessage);

        zDebug() << "link message text = " << messageValue.toString();

        results.addMessageText(nextNode.m_index, messageValue.toString());

    }

    QVariant vResults(QVariant::fromValue<ZblLogLinkList>(results));

    zDebug() << "Sending linkMessageText signal...";


    QMetaObject::invokeMethod(search, "onLinkTextComplete", Qt::QueuedConnection, Q_ARG(QVariant, vResults));

}


} // Zbl