Facilitor/APPL/Shared/logger.inc

<% /*
     $Revision$
     $Id$

     File:    shared/logger.inc
     Context: iframe vanuit appl/fac/Facilitor.asp

     Note:    SESSION must be started like: http://facws002/trunk/?logging=3
              param '&logging=getal'

              geen waarde-->In ieder geval serverside loggen zoals nu ook-->Identiek aan getal==1
              getal is bitwise:
                 &1->serverside loggen
                 &2->serverside logwindow openen op client
                 &8->Bewaar tempfiles van Facilitor Graphics
                &32->Facmgt loggen (deels)
*/

var __Logging = Session("logging") || 0;; // Wordt meestal in common.inc al gezet
var __LogMarker = null; // Caller kan die zetten voor extra markering
function us_timer()
{
    return hiresTimer?hiresTimer.usTimer:(new Date().getTime()*1000);
}
var _logger_time = 0;

var __LogfileName = null;
var __LogfileTitle = null;
htmlLogger =
{
    _padout3: function (number) { return (number < 100) ? '0' + padout(number) : number; },
    _lastclose : -1, // when was lastclose?
    // === Public functions ===
    log_tekst: function (safe_s, optionalColor, optionalCaller, leave_open) // de hoofd log functie
    {
        var startTime = us_timer();

        if (this._script_id == -1)
            this._script_id = this._log_script();

        var now = new Date();
        var sNow = padout(now.getHours())+":"+padout(now.getMinutes())+":"+padout(now.getSeconds());
        if (hiresTimer)
        {
            if (this._startDiff == null)
                this._startDiff = (new Date()).getTime() - (hiresTimer.usTimer / 1000);
            var endDiff = now.getTime() - (hiresTimer.usTimer / 1000);
            var ms = now.getTime()%1000 + (this._startDiff - endDiff);
            sNow += "<small>." + this._padout3(Math.floor(ms)) + "</small>";

            if (this._lastclose > 0)
            {
                var tm = (hiresTimer.usTimer - this._lastclose)/1000;
                tm = tm.toFixed(0);
                var style = "";
                if (tm > 30) // te veel tijd met processing bezig geweest
                    style = " style='background-color: #FF0000;'";
                else if (tm > 15)
                    style = " style='background-color: #FFFF00;'";
                if (tm > 5)
                    sNow += " (<span "+style+" title='Vorige statement was " + tm + " ms geleden al klaar.\nTrage processing?'>" + tm + "ms</span>)";
            }
        }
        else
            sNow += "<small>." + this._padout3(now.getMilliseconds()) + "</small>";

        var txt = safe_s;
        txt = txt.replace(/^INSERT /i,"<b>INSERT</b> ").replace(/^UPDATE /i,"<b>UPDATE</b> ")
                 .replace(/^DELETE /i,"<b>DELETE</b> ").replace(/^BEGIN /i,"<b>BEGIN</b> ")
                 .replace(/^DECLARE /i,"<b>DECLARE</b> ").replace(/END;$/i,"<b>END;</b> ");
        if (optionalColor)
            var td = "<td style=\"background-color:" + optionalColor + ";\">";
        else
            td = "<td>";
        this._do_write("<tr><td valign='top' class='tm'>\n\n"+sNow
                     +     "\n<div class='caller'>" + (optionalCaller||"&lt;global code&gt;") + "</div>"
                     + (__LogMarker?"<br>\n"+__LogMarker:"")
                     + "</td>"
                     + td + "\n" + txt +"</td>" + (leave_open?"":"</td></tr>"));
        this._do_close();
        __LogMarker = null;

        this._us_start = us_timer(); // zo laat mogelijk i.v.m. overhead niet meetellen

        _logger_time += (us_timer() - startTime) / 1000;

        return -1; // geen id
    },

    log_close: function (handle, s_extra, optionalColor) // extra toevoeging aan laatste 'openstaande' regel
    {
        var startTime = us_timer();

        if (this._script_id == -1)
            this._script_id = this._log_script();

        this.us_end = us_timer();

        var us_taken = (this.us_end - this._us_start) / 1000;

        var style = "";
        var txt = "";

        if (us_taken == 0)
            txt = "<1ms"
        else
            txt = us_taken.toFixed(us_taken<10?1:0) + "ms";
        if (us_taken > 250)
            style = " style=\"background-color: #FF0000;\"";
        else
            if (us_taken > 50)
                style = " style='background-color: #FFFF00;'";

        if (optionalColor)
            style = " style='background-color: "+optionalColor+";'";
        if (s_extra && s_extra != "") txt += "<br>\n<b>"+s_extra+"</b>";

        this._do_write("<td " + style + ">" + txt + "</td></tr>");
        this._do_close();

        _logger_time += (us_timer() - startTime) / 1000;
    },

    // === Private functions ===
    _script_id: -1,
    _file_handle: null,
    _us_start: -1,
    _startDiff : null,

    // Na do_write moet je altijd _do_close aanroepen!
    _do_write: function (tekst)
    {
        if (!this._file_handle)
        {
            if (!__LogfileName) // 500_error.asp zet hem zelf
                __LogfileName = shared.tempFolder() + "/log_" + customerId + ".html";
            var objFSO = Server.CreateObject("Scripting.FileSystemObject");
            var IsNew = (!objFSO.FileExists(__LogfileName))

            this._file_handle = objFSO.OpenTextFile(__LogfileName, 8, true, 0); // 8 ForAppending, true is create, 0 Opens the file as ASCII.
            objFSO = null;
            if (IsNew)
            {
                 __LogfileTitle = __LogfileTitle ||Session("customerId");
                 this._file_handle.WriteLine("<!DOCTYPE html>");
                 this._file_handle.WriteLine("<html>");
                 this._file_handle.WriteLine("<head>");
                 this._file_handle.WriteLine("<meta http-equiv=\"cache-control\" content=\"no-cache, no-store, must-revalidate\">");
                 this._file_handle.WriteLine("<meta http-equiv=\"pragma\" content=\"no-cache\">");
                 this._file_handle.WriteLine("<meta http-equiv=\"expires\" content=\"-1\">");
                 this._file_handle.WriteLine("<meta http-equiv=\"X-UA-Compatible\" content=\"IE=edge,chrome=1\">");
                 this._file_handle.WriteLine("<style>");
                 this._file_handle.WriteLine("td {");
                 this._file_handle.WriteLine("  font-family: Verdana;");
                 this._file_handle.WriteLine("  font-size: smaller;");
                 this._file_handle.WriteLine("  padding: 2px;");
                 this._file_handle.WriteLine("  background-color: #D6D8E8;");
                 this._file_handle.WriteLine("}");
                 this._file_handle.WriteLine(".script td { background-color: #C6C8C8; }");
                 this._file_handle.WriteLine("td.source,td.linenr,pre {");
                 this._file_handle.WriteLine("  padding: 0px; margin: 0px; font-size: 8pt; }");
                 this._file_handle.WriteLine(".querystring, .bodysize { color: #666; }");
                 this._file_handle.WriteLine("span.truncated { font-size: 7px; color: #d00; }");
                 this._file_handle.WriteLine(".important {"); // Voor AiAi's
                 this._file_handle.WriteLine("    font-weight: bold;");
                 this._file_handle.WriteLine("    background-color: #fee;");
                 this._file_handle.WriteLine("}");
                 this._file_handle.WriteLine("#clearform { display:none; position: fixed; top:5px; right:5px; border:2px solid white}");
                 this._file_handle.WriteLine(".orgurl { color: #666; }");
                 this._file_handle.WriteLine("div.caller { font-size:8pt; display: none; position:absolute;");
                 this._file_handle.WriteLine("             border-radius: 5px; padding:5px; min-width: 14em;");
                 this._file_handle.WriteLine("             box-shadow: 8px 8px 5px #a0a0a0;");
                 this._file_handle.WriteLine("             color: #222; background-color:#ffffe0;  }");
                 this._file_handle.WriteLine("div.caller:before {");
                 this._file_handle.WriteLine("  content: ' '; position: absolute;");
                 this._file_handle.WriteLine("  width: 0; height: 0;");
                 this._file_handle.WriteLine("  left: 10px; top: -16px;");
                 this._file_handle.WriteLine("  border: 8px solid;");
                 this._file_handle.WriteLine("  border-color: transparent transparent #ffffe0 transparent;");
                 this._file_handle.WriteLine("}");
                 this._file_handle.WriteLine("td.tm:hover div.caller, div.caller:hover { display:block; }");
                 this._file_handle.WriteLine("</style>");
                 this._file_handle.WriteLine("<title>*" + __LogfileTitle + (rooturl?" "+rooturl:"") + " Facilitor logger</title>");
                 if (Application("otap_environment") == "O")
                    this._file_handle.WriteLine("<script type='text/javascript' src='../shared/logger.js'></script>");
                 this._file_handle.WriteLine("</head>");
                 this._file_handle.WriteLine("<body>");
                 if (typeof __LogNoClear == "undefined")
                 {  // Form wordt in logger.js met JavaScript aangezet. Als je het bestand offline bekijkt blijft het form invisible
                    this._file_handle.WriteLine("<form id='clearform' action='../shared/wisLog.asp'>")
                    this._file_handle.WriteLine("    <input type='submit' accesskey='X' value='CLEAR this logfile ([Shift+]Alt+x)'>");
                    this._file_handle.WriteLine("</form>");
                }
                 this._file_handle.WriteLine("<table id='tabel'>"); // The closing </table> is never placed. IE doesn't care
                 this._file_handle.WriteLine("<tr><td colspan='3'>" + __LogfileTitle + " logfile " + __LogfileName + "</td></tr>");
            }
        }
        this._file_handle.WriteLine(tekst);
        return;
    },

    _do_close: function ()
    {
        this._file_handle.Close();
        this._file_handle = null;
        if (hiresTimer)
            this._lastclose = hiresTimer.usTimer;
    },

    _log_script: function ()
    {
        var startTime = us_timer();

        var now = new Date();
        var sDat = now.getDate()+"-"+padout(now.getMonth()+1)+"-"+padout(now.getFullYear());

        var pad = String(Request.ServerVariables("PATH_TRANSLATED")).replace(/\\/g, "/");
        var params = String(Request.ServerVariables("QUERY_STRING"));
        if (params!="")
        {
            var sparams = params.split("&");
            for (var i = 0; i < sparams.length; i++)
            {
                if (sparams[i].length > 60)
                {
                    sparams[i] = Server.HTMLEncode(sparams[i].substr(0, 20))
                               + "<span class='truncated' title='" + Server.HTMLEncode(sparams[i]) + "'>[&hellip;]</span>"
                               + Server.HTMLEncode(sparams[i].substr(sparams[i].length - 20));
                }
                else
                {
                    if (sparams[i].match(/^(my)?APIKEY\=/i))
                        sparams[i] = sparams[i].substr(0,11) + "<EFBFBD><EFBFBD><EFBFBD><EFBFBD>"; // 1e 4 karakters overlaten
                    sparams[i] = Server.HTMLEncode(sparams[i]);
                }
            }
            var safeparams = sparams.join("&amp;"); // alles is safe gemaakt
            pad += "<span class='querystring'>?" + safeparams + "</span>";
        }
        var y = String(Request.ServerVariables("APPL_PHYSICAL_PATH")); // Zoveel gaan we er af strippen
        pad = pad.substring(y.length);

        var ip = Request.ServerVariables("REMOTE_ADDR") + " " + Request.ServerVariables("REMOTE_USER");
        var method = Request.ServerVariables("REQUEST_METHOD");

        var orgurl = Request.ServerVariables("HTTP_X_REWRITE_URL");
        if (orgurl.Count)
            pad += "<br>\n<span class='orgurl'>" + method + " " + String(orgurl).substring(rooturl.length + 1) + "</span>";
        else
        {
            var orgurl = Request.ServerVariables("HTTP_X_ORIGINAL_URL"); // Origineel van IIS Rewriter
            if (orgurl.Count)
                pad += "<br>\n<span class='orgurl'>" + method + " " + String(orgurl).substring(rooturl.length + 1).replace(/\\/g, "/") + "</span>";
            else if (typeof THIS_FILE == "string")
                pad += "<br>\n<span class='orgurl'>Now in " + THIS_FILE + "</span>";
        }

        var linkdat = "<a href='#tm" + now.getTime() + "' name='tm" + now.getTime() + "'>\n\n<!-- -- -->\n" + sDat + "</a>";
        var usrtxt = (Session("user_key")||"");

        var txt =("</td></tr><tr class='script' title='"+ ip + " " + usrtxt + "'>"
                + "<td valign='top'>" + linkdat + "</td><td valign='top' colspan=2> " + method + " " + pad);
        if (method == "POST" || Request.TotalBytes > 0)
           txt += " <span class='bodysize'>(body " + Request.TotalBytes + " bytes)</span>";

        if (Session("userident"))
            txt += ("<br>\n<span class='orgurl'>User: " + Server.HTMLEncode(Session("userident")) + "</span>");
        if (Session("fclt_realuser"))
            txt += " Realuser: " + Server.HTMLEncode(Session("fclt_realuser"));
        var origin = Request.ServerVariables("HTTP_X_FCLT_CUST"); // Onze eigen putorders?
        if (origin.Count)
            txt += ("<br>\n<span class='orgurl'>Origin: Putorders " + String(origin) + "</span>");

        this._do_write(txt);
        // _do_close komt wel in log_tekst()

        _logger_time += (us_timer() - startTime) / 1000;

        return 1; // dummy id
    }
};

function __Logstd(tekst, severity)
{
    try
    {
        var objFSO = Server.CreateObject("Scripting.FileSystemObject");
        var stdLogfileName = __LogfileName.replace(".html", ".log");
        var file_handle = objFSO.OpenTextFile(stdLogfileName, 8, true, 0); // 8 ForAppending, true is create, 0 Opens the file as ASCII.
        file_handle.WriteLine("{0};{1};{2}".format(toISODateTimeString(new Date(), true), severity||"I", tekst));
        file_handle.Close();
    }
    catch(e)
    {  // Waarschijnlijk een permission denied omdat twee processen tegelijk proberen te schrijven
        __LogError = e.description;
        debugger;
        return false;
    }
}

theLogger = htmlLogger; // ooit geexperimenteerd met sqliteLogger

// Return true als we de logging parameter gevonden hebben in qtstring
function CheckForLogging(qstring)
{
    if (qstring && qstring.Count>0)
    {
        var lg = parseInt(qstring(1), 10)||0;
        if (lg != 0 && Application("otap_environment") != "O")
            user.checkAutorisation("WEB_FACTAB"); // Minimaal

        __Logging = Session("logging") = lg;
        return true;
    }
    return false;
}

function __LogCloseLine(handle, s_extra, optionalColor)
{
    if (__Logging & 1)
    {
        return __DoLogCloseLine(handle, s_extra, optionalColor)
    }
}

function __DoLogCloseLine(handle, s_extra, optionalColor)
{
    if (typeof Logging_disable != "undefined")
        return;
    try
    {
        theLogger.log_close(handle, s_extra?String(s_extra):null, optionalColor);
        return true;
    }
    catch(e)
    {  // Waarschijnlijk een permission denied omdat twee processen tegelijk proberen te schrijven
        __LogError = e.description;
        debugger;
        return false;
    }
}

// Voor als je HTML wilt gebruiken in s
function __SafeLog(s, optionalCaller, leave_open)
{
    if (__Logging & 1)
    {
        return __SafeDoLog(s, null, optionalCaller||__SafeLog.caller, leave_open)
    }
}

function __Log(s, optionalCallerOrColor, leave_open)
{
    if (__Logging & 1)
    {
        var optionalColor = optionalCallerOrColor;
        var optionalCaller;
        if (typeof optionalCallerOrColor == "function")
        {
            var optionalColor = null;
            var optionalCaller = optionalCallerOrColor;
        }
        return __DoLog(s, optionalColor, optionalCaller||__Log.caller, leave_open)
    }
}

function __callerTekst(clr, nesting)
{
    if (!clr)
        return "";
    var cl = clr.toString().match(/function\s*(\w*)/)[1];
    cl = cl?"{"+cl+"}":"";
    if (!clr.caller)
        return cl;
    if (clr === clr.caller)
        return cl  + "<br>" + "&nbsp;&nbsp;&lt;Recursive&gt;"
    nesting = nesting || 0;
    if (nesting > 20)
        return "&lt;Nesting to deep??&gt;"; // Onverklaard. Gezien op GET appl\mgt\prs_perslid.asp?mode=list&model=custom_fields&flexparentkey=55559

    var prnt = __callerTekst(clr.caller, nesting + 1);
    if (prnt != "")
        return (cl||"&lt;anonymous&gt;") + "<br>" + prnt;
    else
        return cl + prnt;
}

// Als de Normale log maar dan geforceerd, onafhankelijk van logging settings
// optionalColor bijvoorbeeld "#FF0000" voor rood
// __DoLog("Very bad situation", "#FF0000")
function __DoLog(s, optionalColor, optionalCaller, leave_open)
{
    if (s !== null && typeof s == "object")
    {
        s = JSON.stringify(s, null, '\xa0\xa0\xa0\xa0');
    }
    s = Server.HTMLEncode(String(s)).replace(/\n/g, "<br>\n");
    return __SafeDoLog(s, optionalColor, optionalCaller||__DoLog.caller, leave_open);
}

// Veronderstel dat s HTML-safe is
var __LogError = "";
function __SafeDoLog(s, optionalColor, optionalCaller, leave_open)
{
    if (typeof Logging_disable != "undefined")
        return;
    try
    {
        return theLogger.log_tekst(String(s), optionalColor, __callerTekst(optionalCaller||__SafeDoLog.caller), leave_open)
    }
    catch(e)
    {  // Waarschijnlijk een permission denied omdat twee processen tegelijk proberen te schrijven
        //throw(e);
        if (typeof theLogger == "undefined")
        {
		    Response.Write(String(s) + "<br>");
            Response.Write("Vreemd, theLogger is nog niet gedefinieerd in logger.inc."
                         + "<br>Heb je misschien logging <b>voor</b> de include van common.inc/logger.inc geplaatst?"
                         + "<br>Dat werkt namelijk niet.");
            Response.End;
        }
        __LogError = e.description;
        debugger;
        return false;
    }
}

function __DumpCollection(pCollection, params)
{
    params = params || {}
    var sLog = params.title + " ("+pCollection.Count+" items):";
    if (params.optionalColor)
    {
        sLog = "<div style=\"background-color: "+params.optionalColor+";\">"+sLog+"</div>";
    }
    sLog += "<table class='inside'>";
    var i;
    for (i=1; i<=pCollection.Count; i++)
    {
        var itemname = String(pCollection.key(i));
        if (params.exclude && itemname.match(params.exclude))
            continue;
        sLog += "<tr><td>" + Server.HTMLEncode(itemname); // + " type: " + typeof pCollection(i) + " cons: " + pCollection(i).constructor
        if (itemname.match(/password|pwd|pswd|apikey|myapikey/i))
        {
            sLog += "</td><td><em>hidden</em>"
        }
        else if (typeof pCollection(i) != "object" || pCollection(i) === null)
        {
            sLog += "</td><td>" + Server.HTMLEncode(pCollection(i));
            var v = pCollection.item(i);
            var numv = parseInt(v);
            if (!isNaN(numv))// Als de keynaam een datum lijkt dan datum parsen. Leest gemakkelijker
            {
                if (itemname.match(/(^date|van$|tot$|datum)/)
                    || (numv > 946684800000 && numv < 2145916800000)) // 2000-2038
                    sLog += "&nbsp;<em style='font-size:smaller'>" + toISODateTimeString(new Date(parseInt(v)), true) + "</em>";
                if (itemname == "devicebits")
                    sLog += "&nbsp;<em style='font-size:smaller'>0b" + numv.toString(2) + "</em>";
            }
        }
        else
        {
            if (pCollection(i).Count>1)
                sLog += "("+pCollection(i).Count+"x)"
            sLog += "</td><td>"
            var j;
            for (j=1; j<=pCollection(i).Count; j++)
            {
                if (j>1)
                    sLog += "<br>\n"
                if (typeof pCollection(i).key == "object")
                    sLog += Server.HTMLEncode(pCollection.item(i).key(j)) + ": ";
                sLog += Server.HTMLEncode(pCollection.item(i)(j));
                var v = pCollection.item(i)(j);
                var numv = parseInt(v);
                if (!isNaN(numv))// Als de keynaam een datum lijkt dan datum parsen. Leest gemakkelijker
                {
                    if (itemname.match(/(^date|date$|van$|tot$|datum)/)
                        || (numv > 946684800000 && numv < 2145916800000)) // 2000-2038
                        sLog += "&nbsp;<em style='font-size:smaller'>" + toISODateTimeString(new Date(parseInt(v)), true) + "</em>";
                }
            }
        }
        sLog += "</td></tr>";
    }
    sLog += "</table>";
    return (sLog);
}

// Log alle Request.Form variabelen in een tabel onvoorwaardelijk
function __DoLogForm(optionalColor)
{
    return __SafeDoLog(__DumpCollection(Request.Form, { title: "Request.Form", optionalColor: optionalColor }));
}

function __LogForm()
{
    if (!(__Logging & 1)) return; // Don't bother
    return __DoLogForm();
}

// Noot: altijd jaar vooraan, goed voor logfiles, niet bedoeld voor presentatie
// padout herhalen voor 500_error.asp
function padout(number) { return (number < 10) ? "0" + number : number; }
function toISODateString(jsDate)
{
    return padout(jsDate.getFullYear())  + "-" + padout(jsDate.getMonth() + 1) + "-" + padout(jsDate.getDate());
}

function toISODateTimeString(jsDate)
{
    if (typeof jsDate == "number")
        jsDate = new Date(jsDate);

    if (typeof jsDate == "object" && jsDate.type == 135/*adDBTimeStamp, oRs("datum")*/)
        jsDate = new Date(jsDate.value);

    if (typeof jsDate == "date") // een oRs("datum").value
        jsDate = new Date(jsDate);

    return toISODateString(jsDate) + " "
         + padout(jsDate.getHours()) + ":" + padout(jsDate.getMinutes())   + ":" + padout(jsDate.getSeconds());
}

// Als logfile groter is dan whenSize dan beginnen we een nieuwe
// Maximaal een keer per dag
function rotateLogfile(whenSize)
{
    var fso = Server.CreateObject("Scripting.FileSystemObject");
    var oldname = shared.tempFolder() + "/log_" + customerId + ".html";
    if (!fso.FileExists(oldname))
        return;
    var f = fso.getFile(oldname);
    if (f.Size > whenSize)
    {
        var today = toISODateString(new Date());
        var newname = oldname.replace(/\.html$/, "") + "_" + today + ".html";
        if (fso.FileExists(newname))
        {
            __DoLog("Oversized logfile but new file {0} already exists".format(newname), "#0ff");
        }
        else
        {
            __DoLog("Logfile over {0} bytes, starting new file".format(whenSize), "#0f0"); // laatste regel in oude file
            try
            {
                fso.MoveFile(oldname, newname);
                __DoLog("Oversized logfile was archived in {0}".format(newname), "#0f0");
            }
            catch(e)
            {
                __DoLog("Could not rename logile to {0}: {1}".format(newname, e.description), "#f00")
            }
        }
    }

}

function __Log2FileName(postfix, extension)
{
    var fso = Server.CreateObject("Scripting.FileSystemObject");
    var folder = shared.tempFolder();
    if (!fso.FolderExists(folder))
        fso.CreateFolder(folder);
    var log_file = folder + "/" + postfix + "_";
    var jsDate = new Date();
    var s = String(jsDate.getFullYear()) + padout(jsDate.getMonth() + 1) + padout(jsDate.getDate())
          + padout(jsDate.getHours()) + padout(jsDate.getMinutes()) + padout(jsDate.getSeconds())
          + "_" + jsDate.getMilliseconds()
    log_file = log_file + s + (extension || ".xml");
    return log_file;
}

function __Log2File(data, postfix, extension)
{
    var log_file = "??";
    try
    {
        var log_file = __Log2FileName(postfix, extension);
        var fs  = Server.CreateObject("Scripting.FileSystemObject");
        var ts  = fs.CreateTextFile(log_file, true);
        // Als je op de volgende regel een 'Invalid procedure call or argument' krijgt
        // heb je mogelijk/waarschijnlijk unicode in data staan? Daar kunnen we niet
        // tegen
        ts.WriteLine (data);
        ts.Close();
        __Log("Saved in " + log_file);
    }
    catch (e)
    {
        __DoLog("__Log2File failed writing to {0}. Perhaps Unicode?\n{1}".format(log_file, e.description));
    }
}
%>