The XML Logger - Reviewing the Payload

In my last post, I talked about how to capture XML Payloads by splitting large values across a series of DB records. In order to look at the data, we need to reassemble the payloads into a single text block again. I expose my Payload BC in a view tied to either the User's session:

or to the record on which the interface was executed:

The latter is accomplished through the payload parsing I talked about which allows us to create a view which links an object record to the payload record once the transaction id is stored on the payload record. On these views, I expose I nice looking form applet which displays both the request and response sides of the interface. The form fields are actually calculated fields, defined as DTYPE_TEXT, with the following expression:

InvokeServiceMethod("XXX Utilities", "ConcatenateField", "bo.bc='XXX User Session.XXX User Session XML Detail', FieldName='Log Text', SearchExpr='[Parent Id]=""+[Id]+"" AND [Field]="Request"'", "Out")

where:

• 'XXX Utilities' is my eScript framework service with many commonly used functions
• 'ConcatenateField' is a method on that service 'bo.bc' is a parameter name for that method
• 'XXX User Session' is the name of the business object where my user sessions are stored
• 'XXX User Session XML Detail' is the name of the business component containing the split up log data 'FieldName' is another parameter for this method
• 'Log Text' is the name of the field on the 'XXX User Session XML Detail' BC where the split payload text is stored defined as DTYPE_CLOB
• 'SearchExpr' is another parameter for this method

Finally the search expression looks a bit complicated as passing quotes to the InvokeServiceMethod is difficult. I have improvised by using a commonly used XML expression of " which the method then recognizes and converts back to a quote. Here is the method:

function ConcatenateField(Inputs, Outputs) {
//Inputs: bo.bc  "boName.bcName"
//   FieldName
//   SearchExpr BC Search Expression (Optional)
 var retValue = "";
 var found = false;
 var search = Inputs.GetProperty("SearchExpr");
 try {
  var arSplit = Inputs.GetProperty("bo.bc").split(".");
  var bcQuery:BusComp;
  if (arSplit[0] == "ACTIVE") 
   bcQuery = TheApplication().ActiveBusObject().GetBusComp(arSplit[1]);
  else 
   bcQuery = TheApplication().GetBusObject(arSplit[0]).GetBusComp(arSplit[1]);
   
  var delimeter = (Inputs.GetProperty("delimeter") != "" ? Inputs.GetProperty("delimeter") : "\n");
 
  with (bcQuery) {
   if (search != "") {
    ClearToQuery();
    arSplit = Inputs.GetProperty("SearchExpr").split(""");
    search = arSplit.join("'");
    SetSearchExpr(search);
    ActivateField(Inputs.GetProperty("FieldName"));
    SetViewMode(AllView);
    ExecuteQuery(ForwardOnly);
   }
  
   found = FirstRecord();
   while(found) {
    retValue += GetFieldValue(Inputs.GetProperty("FieldName"));
    found = NextRecord();
    if (found) retValue += delimeter;
   }

      Outputs.SetProperty("Out", retValue);
  }
 } catch(e) {
  TheApplication().RaiseError(e);
 } finally {
  bcQuery = null;
  arSplit = null;
 }
}

The XML Logger

In my last post, I promised to try to bring us up to date on the current implementation of the logging framework, and specifically the XML Logger component of it.  The framework is initialized on the Application Start event making all these methods available from script.  From an XML Logging perspective, it can be initiated in one of two ways:

• As a standard business service from within the Integration WF (or business service).  In this approach, just before the outbound WS or HTTP call, you would call the logRequest or logResponse methods of the framework business service, passing in at a minimum the property set about to be interfaced.  There are many other attributes of the payload record which can be optionally used which I won't go into detail over.  You can always add attributes to meet your needs and you don't need to populate any of them really.
• As a Filter Service.  This is used for Web Services and is useful in that it can be turned on or off without modifying any existing Integration WFs.  On the Web Service admin views, for each web service operation that you want to log, just specify the Request/Response Filter Service as the Framework business service and the Request/Response Filter Method as logRequest/logResponse respectively.
• Can be implemented to capture other payloads as needed, for instance before and after messages of the EAI Data Transformation Service

Ok, now for the nitty gritty.  What do the logRequest/logResponse methods do?  Both are similar and different only in that all interface logging records have a placeholder for a request and a response payload, which the two methods are differentiated to populate.  The main input to these methods is an XML payload.  At a high level, here is the algorithm:

1. Navigate the property set until the first 'ListOf*' tag is found which is assumed to be the beginning of the Integration Object data.
2. Call a method to Parse the remaining child data to correctly name and categorize the interface based on the IO Type and iddentify the record id and unique identifier attributes.  This allows for optional scripting to tailor the logging service to your client's unique needs
3. Call the logInterface method which:
1. Checks if in an EAI Transaction.  If so, add the payload to an array, otherwise continue (This is currently only implemented to support outbound interfaces when using the Filter service implementation)
2. Creates a session record if one does not already exist (Inbound interfaces executed by an EAI OM typically)
3. Deal with anonymous logins (when used on an inbound interface the request method will be executed under the Anonymous login but the response method with be performed by the interface user id)
4. Creates a payload record to store the attributes extracted from the payload parsing
5. Split the payload into chunks no larger than the BLOB length and create detail records for each chunk

First the PreInvoke method.  This mostly speaks for itself but since we may want to save processing overhead the calling of the parseInterface method is parameterized and controlled by which method is actually invoked.

function Service_PreInvokeMethod (MethodName, Inputs, Outputs){
  var retValue      = CancelOperation;

  switch(MethodName) {
  case "logInterface":     
    var key = logInterface(Inputs, Outputs);
    Outputs.SetProperty("key", key)
    break;
  case "logParseRequest":     
    logRequest(Inputs, Outputs, true, "");
    break;
  case "logParseResponse":     
    logResponse(Inputs, Outputs, true, "");
    break;
  case "logRequest":     
    logRequest(Inputs, Outputs, false, "");
    break;
  case "logResponse":     
    logResponse(Inputs, Outputs, false, "");
    break;
  case "logTransformRequest":     
    logRequest(Inputs, Outputs, false, "Transform");
    break;
  case "logTransformResponse":     
    logResponse(Inputs, Outputs, false, "Transform");
    break;
  }
  return (retValue);
}

Next the logRequest and logResponse Methods.  Like I said they are very similar except for which field the payload is passed to.  Also the logResponse method has some additional logic for parsing SOAP faults.

function logRequest(Inputs, Outputs, parse, mode) {
/* ***********************************
Purpose: Log interface request from/to an external interface in the session log
Usage: In Web Service definition, operations applet, set the Request Filter BS to 'PPT Utilities'
  and the method to logRequest.  Clear the cache
Arguments: 1 - SoapMessage will implicily be passed as a child property set
**************************************** */
try {
  var soapEnv, soapBody, divePS, direction, progress;
  var bodyType="";
  var msgType="";
  var parseResults = new Object();
  var key = TimeStamp("DateTimeMilli");
  var max = 3;
  var dives = 0;

  if(Inputs.GetChildCount() > 0) {
    // Get the SOAP envelope from the SOAP hierarchy.  If payload is passed as an input property set, skip down an extra level
    soapEnv = Inputs.GetChild(0);        //Like env:Envelope

    //Minimize processing if payloads/logging information will not be stored
    if (gHoldBufferDump == true || gsTraceIntfaceReqResp == "TRUE") {
      //if called from EAI Data Transformation Engine and user logging level is 5 capture passing specific props
      if (mode=="Transform" && (gHoldBufferDump == true || gCurrentLogLvl >= 5)) {
        parseResults.recId = soapEnv.GetChild(0).GetChild(0).GetProperty("Id");
        parseResults.recBC = soapEnv.GetChild(0).GetChild(0).GetType();
        msgType = Inputs.GetProperty("MapName");
        parseResults.funcName = Inputs.GetProperty("MapName");
        direction = "EAI Transform";
      } else {
        try { // Try to process the message to get functional data 
          if (soapEnv.GetType().toUpperCase().indexOf("ENVELOPE") <0 ) soapEnv = soapEnv.GetChild(0);
          direction = Inputs.GetProperty("WebServiceType")+" "+Inputs.GetProperty("Direction");
          for (var i=0; i < soapEnv.GetChildCount(); i++) {   
            bodyType = soapEnv.GetChild(i).GetType();    //Like env:Body
            if (bodyType.toUpperCase() == "BODY" || bodyType.substr(bodyType.indexOf(":")+1).toUpperCase() == "BODY") {
              soapBody = soapEnv.GetChild(i);
              for (var j=0; j < soapBody.GetChildCount(); j++) {   
                msgType = soapBody.GetChild(j).GetType();  //Full Port name of the WS 
  
                //Parse to check for faults and create a text string to be used in the key
                if (msgType.indexOf(":") >= 0)  msgType = msgType.substr(msgType.indexOf(":")+1); //strip namespace
                if (msgType.indexOf(" ") >= 0)  msgType = msgType.substr(0, msgType.indexOf(" ")); //strip namespace declaration
                if (msgType.indexOf("_") >= 0)  msgType = msgType.substr(0, msgType.lastIndexOf("_"));//strip port operation
  
                //if true, attempt to find Row Id in payload to stamp on log record so log can be linked to Siebel record  
                if (parse == true) {
                  divePS = soapBody.GetChild(j); //.GetChild(0)
                  while (divePS.GetType().indexOf("ListOf") < 0 && dives <= max) {
                    if (divePS.GetChildCount() > 0) {
                      divePS = divePS.GetChild(0);
                      dives++;
                    } else dives = max + 1;
                  }
   
                  //If a ListOf... container is found, this is a SiebelMessage generated by Siebel. Otherwise parse the SOAP Body
                  if (divePS.GetType().indexOf("ListOf") >= 0) parseInterface(divePS, parseResults);
                  else parseInterface(soapBody, parseResults);
                }
              } 
        
              break;
            }
   }         
 } catch(e) {
          //If an error occurs while parsing, just try to write the message whole
        }
            
      } //SOAP Message scenario

      //If msgType is identified then insert a log for this payload
      if (msgType != "") {
        msgType = msgType.replace(/_spc/g, "").replace(/\s/g, "");
        key = msgType+"_"+key;

        TheApplication().SetProfileAttr("InterfaceKeyInbound", key);
        progress = logInterface(key, soapEnv, null, direction, parseResults.recId, parseResults.recBC, "Pending", msgType, parseResults.funcName, null, null, null, parseResults.ref1, null, null, parseResults.refField);
      }
    } else if (gsTraceIntfaceReqResp == "FALSE") {
      //Do Nothing
    } else { //Store payloads in case an error occurs
      //var holdPayload = ["Request", Inputs, parse, mode];
      gHoldReqResp.push(["Request", Inputs, parse, mode]);
      if (gHoldBufferMax > 0 && gHoldReqResp.length > gHoldBufferMax) gHoldReqResp.shift();
    }
  } // Inputs.GetChildCount()
  Outputs.InsertChildAt(soapEnv,0);
} catch(e) {
  RaiseError(e);
} finally {
  divePS = null;
  soapBody = null;
  soapEnv = null;
  parseResults =  null;
}

}

function logResponse(Inputs, Outputs, parse, mode) {
/* ***********************************
Purpose: Log interface response from/to an external interface in the session log
Usage: In Web Service definition, operations applet, set the Response Filter BS to 'PPT Utilities'
  and the method to logResponse.  Clear the cache
Arguments: 1 - SoapMessage will implicily be passed as a child property set
**************************************** */
try {
  var soapEnv, soapBody, divePS, direction, progress;
  var bodyType="";
  var msgType="";
  var parseResults = new Object();
  var fault=null;
  var key = TheApplication().GetProfileAttr("InterfaceKeyInbound");
  var max = 3;
  var dives = 0;
  var dump = false;

  if(Inputs.GetChildCount() > 0) {
    // Get the SOAP envelope from the SOAP hierarchy
    soapEnv = Inputs.GetChild(0);

    //Minimize processing if payloads/logging information will not be stored
    if (gHoldBufferDump == true || gsTraceIntfaceReqResp == "TRUE") {
      if (mode=="Transform" && (gHoldBufferDump == true || gCurrentLogLvl >= 5)) {
        dump = true;
        direction = "EAI Transform";
        if (soapEnv.GetChild(0).GetChild(0).PropertyExists("Id")) {
          parseResults.recId = soapEnv.GetChild(0).GetChild(0).GetProperty("Id");
          parseResults.recBC = soapEnv.GetChild(0).GetChild(0).GetType();
        }
      } else if (mode=="") {
        dump = true;
        try { // Try to process the message to get functional data
          direction = Inputs.GetProperty("WebServiceType")+" "+Inputs.GetProperty("Direction");
          //Soap Envelope Request may have a Header and a Body so loop to the Body
          for (var i=0; i < soapEnv.GetChildCount(); i++) {
            bodyType = soapEnv.GetChild(i).GetType();
            if (bodyType.toUpperCase() == "BODY" || bodyType.substr(bodyType.indexOf(":")+1).toUpperCase() == "BODY") {
              soapBody = soapEnv.GetChild(i);
  
              //Soap Body typically has a container for the Message
              for (var j=0; j < soapBody.GetChildCount(); j++) {   
                msgType = soapBody.GetChild(j).GetType();
   
                //Parse to check for faults and create a text string to be used in the key
                if (msgType.indexOf(":") >= 0)  msgType = msgType.substr(msgType.indexOf(":")+1)
                if (msgType.indexOf(" ") >= 0)  msgType = msgType.substr(0, msgType.indexOf(" "))
                if (msgType.indexOf("_") >= 0)  msgType = msgType.substr(0, msgType.lastIndexOf("_"))
  
                if (msgType.toUpperCase() == "FAULT") fault = soapBody.GetChild(j).GetProperty("faultstring");
                else if (parse == true) { 
                  //if true, attempt to find Row Id in payload to stamp on log record so log can be linked to Siebel record  
                  divePS = soapBody.GetChild(j); //focus on the Message level
                  while (divePS.GetType().indexOf("ListOf") < 0 && dives <= max) {
                    if (divePS.GetChildCount() > 0) {
                      divePS = divePS.GetChild(0);
                      dives++;
                    } else dives = max + 1;
                  }
   
                  //If a ListOf... container is found, this is a SiebelMessage generated by Siebel. Otherwise parse the child of the Body
                  if (divePS.GetType().indexOf("ListOf") >= 0) parseInterface(divePS, parseResults);
                  else parseInterface(soapBody, parseResults);
                }
              }
              break;
            }
          }
        } catch(e) {
          //If an error occurs while parsing, just try to write the message whole
        }
      }
 
      if (key == "") {
        key = TimeStamp("DateTimeMilli");
        if (msgType != "") {
          msgType = msgType.replace(/_spc/g, "");
          key = msgType+"_"+key;
        }
      }
         
      if (dump == true) {
        if (fault != null) {
          logInterface(key, null, soapEnv, null, parseResults.recId, parseResults.recBC, "error", null, null, fault);
        } else {
          var recId = (parseResults.recId != "" ? parseResults.recId : null);
          var recBC = (parseResults.recBC != "" ? parseResults.recBC : null);
          var ref1 = (parseResults.ref1 != "" ? parseResults.ref1 : null);
          var funcName = (parseResults.funcName != "" ? parseResults.funcName : null);
          progress = logInterface(key, null, soapEnv, direction, recId, recBC, "Complete", msgType, funcName, null, null, null, ref1);
        }
      }
    } else if (gsTraceIntfaceReqResp == "FALSE") {
      //Do Nothing
    } else { //Store payloads in case an error occurs
      gHoldReqResp.push(["Response", Inputs, parse, mode]);
      if (gHoldBufferMax > 0 && gHoldReqResp.length > gHoldBufferMax) gHoldReqResp.shift();
    }
  } // Inputs.GetChildCount()
  Outputs.InsertChildAt(soapEnv,0);
} catch(e) {
  RaiseError(e);
} finally {
  divePS = null;
  soapBody = null;
  soapEnv = null;
  parseResults =  null;
  TheApplication().SetProfileAttr("InterfaceKeyInbound", "");
}
}

The parseInterface method passes the ListOf container of the Integration Object to a switch statement where each BC type can be evaluated.  This is useful only when using the Filter Service triggering mechanism otherwise the Record Id and Interface Name attributes can just be explicitly passed as parameters.  A case section should be created for each Integration Object being processed. This function really needs to be manually manipulated for every implementation and integration point to explicitly specify how to find the record id for a particular integration.

function parseInterface(ListOfIC, oReturn) {    //Input ListOfIC is a ListOf...
//Called from logRequest and logResponse to parse a message and get the row id or reference ids of different
//objects
try {
  if (ListOfIC.GetChildCount() > 0) {
    var IC = ListOfIC.GetChild(0);   //Integration Component Instance
    var icNameSpace = "";
    var intCompType = IC.GetType();
    var propName;
    var stop = false;
    var childIC;
    var childFlds;
      
    if (intCompType.indexOf(":") >= 0) {
      icNameSpace = intCompType.substr(0, intCompType.indexOf(":")+1);
      intCompType = intCompType.substr(intCompType.indexOf(":")+1);
    }

    //For these types, dive an additional level
    switch(intCompType) {
    case "ATPCheckInterfaceRequestOrders":
      IC = IC.GetChild(0);
      intCompType = IC.GetType();
      if (intCompType.indexOf(":") >= 0) {
        icNameSpace = intCompType.substr(0, intCompType.indexOf(":")+1);
        intCompType = intCompType.substr(intCompType.indexOf(":")+1);
      }
      break;
    }
 
    for (var flds = 0; flds < IC.GetChildCount(); flds++) { //Loop through Fields
      propName = IC.GetChild(flds).GetType();
      switch (intCompType) {
      case "Quote":
      case "SWIQuote":
        oReturn.recBC = "Quote";
        if (propName == icNameSpace+"Id") {
          oReturn.recId = IC.GetChild(flds).GetValue();
          stop = true;
        }
        break;

      case "ProductIntegration":
        oReturn.recBC = "Internal Product";
        if (propName == icNameSpace+"ListOfProductDefinition") {
          childIC = IC.GetChild(flds).GetChild(0);
          for (childFlds = 0; childFlds < childIC.GetChildCount(); childFlds++) { //Loop through Fields
            propName = childIC.GetChild(childFlds).GetType();
            if (propName == icNameSpace+"Id" || propName == icNameSpace+"ProductId") {
              oReturn.recId = childIC.GetChild(childFlds).GetValue();
              stop = true;
            }
            if (stop) break;                              
          }
        }
        break;
     
      default:
        if (propName.indexOf("Id") >= 0) {
          oReturn.recId = IC.GetChild(flds).GetValue();
          stop = true;
        }
        oReturn.recBC = intCompType;
        stop = true;
      }
      if (stop) break;                              
    }
  }
} catch(e) {
  RaiseError(e);
} finally {
  childIC = null;
  IC = null;
}
}

The logInterface method is called by both logRequest and logResponse to manage the session records for inbound interfaces and create the actual payload record.  I will have to go into more detail about the Anonymous login processing at some other time.  Suffice to say this works under a variety of web service setups.

function logInterface() {
if (gHoldBufferDump == true || gsTraceIntfaceReqResp == "TRUE") {
  try {
    var key, dir, recId, recBC, status, srcObj, name, logText, userText, retCode, ref1, ref2, ref3, refField, findResponseMethod;
    var request:PropertySet, response:PropertySet;
    var progress = "";

    //if attributes passed as an input property set, set variables from them
    if (typeof(arguments[0]) == "object") {
      progress = progress+"\n"+"REF1: typeof(arguments[0]) == object";
      var Inputs:PropertySet = arguments[0];
      name = Inputs.GetProperty("FunctionalName");
      key = Inputs.GetProperty("Key");
   
      for (var i=0;i < Inputs.GetChildCount();i++) {
        if (Inputs.GetChild(i).GetType() == "Request") request = Inputs.GetChild(0);
        if (Inputs.GetChild(i).GetType() == "Response") response = Inputs.GetChild(0);
      }
      dir = Inputs.GetProperty("Direction");
      recId = Inputs.GetProperty("LinkId");
      recBC = Inputs.GetProperty("LinkBC");
      status = Inputs.GetProperty("Status");
      srcObj = Inputs.GetProperty("SourceObject");
      logText = Inputs.GetProperty("LogText");
      userText = Inputs.GetProperty("UserText");
      retCode = Inputs.GetProperty("ReturnCode");
      ref1 = Inputs.GetProperty("Reference1");
      ref2 = Inputs.GetProperty("Reference2");
      ref3 = Inputs.GetProperty("Reference3");
      refField = Inputs.GetProperty("RefField");
    } else {
      progress = progress+"\n"+"REF1: else typeof(arguments[0])";
      key = arguments[0];
      request = arguments[1];
      response = arguments[2];
      dir = arguments[3];
      recId = arguments[4];
      recBC = arguments[5];
      status = arguments[6];
      srcObj = arguments[7];
      name = arguments[8];
      logText = arguments[9];
      userText = arguments[10];
      retCode = arguments[11];
      ref1 = arguments[12];
      ref2 = arguments[13];
      ref3 = arguments[14];
      refField = arguments[15];
    }
  
    //When called though WF as Payload logger, generate the key if not provided
    if (key == "" || key == undefined || key == null) {
      if (name == "" || name == undefined || name == null) name = "None";
      key = name.replace(/_spc/g, "").replace(/\s/g, "")+TimeStamp();
    }

    var found:Boolean = false;
    var sessionId:String = "";
    var guestSessionId:String = "";
    var guestSessionFound = false;
    var createSession = false;
    var firstMessage = false;
    var boSessionFlat;
    var bcSessionXMLFlat;
    var useGuestSession = (response != null && gsMergeGuestSessions=="TRUE" && gsGuest != "" ? true : false);
    var boSession:BusObject = TheApplication().GetBusObject("PPT User Session");
    var bcSession:BusComp;
 
    if (gHoldBuffer == true) {
      progress = progress+"\n"+"REF2: gHoldBuffer == true";
      //If in a EAI Txn, store all payloads in an array so they can be written after the commit or rollback
      gHoldPayloads[gHoldPayloads.length] = arguments;
    } else {
      progress = progress+"\n"+"REF2: gsTraceIntfaceReqResp == TRUE & key == "+key;
      //If an interface is being logged for the first time, need to instantiate the session
      if (gSessionId == "") {
        progress = progress+"\n"+"REF3: gSessionId == ''";
        //If Guest connections are not used, a simplified session management can be used 
        if (gsGuest == "" && key != "") {
          progress = progress+"\n"+"REF4: gsGuest == '' & key == "+key;
          bcSession = boSession.GetBusComp("PPT User Session");
          with (bcSession) {
            NewRecord(NewBefore);
            SetFieldValue("Employee Id",TheApplication().LoginId());
            SetFieldValue("Session Stamp",gsLogSession);
            WriteRecord();
            gSessionId = GetFieldValue("Id");
          }
          createSession = false; //skip logic below to create/merge a guest session
          firstMessage = true; //will always insert the input message rather than querying to update
          //Reset the variable to check whether to merge the guest session.  This allows a log buffer dump
          gsMergeGuestSessions = "FALSE";
        } else {
          progress = progress+"\n"+"REF4: else: gsGuest == '' & key == "+key;
          createSession = true;
  
          //confirm that current session has not been created yet
          bcSession = boSession.GetBusComp("PPT User Session");
          with (bcSession) {
            ClearToQuery();
            SetSearchSpec("Session Stamp", gsLogSession);
            ExecuteQuery(ForwardOnly);
            found = FirstRecord();
 
            if (found == true) {
              gSessionId = GetFieldValue("Id");
              createSession = false;
            } else {
              firstMessage = true;
            }
          }
        }
      }
 
      if (createSession == true || useGuestSession == true) {
        progress = progress+"\n"+"REF5: createSession == true || useGuestSession == true";
        bcSession = boSession.GetBusComp("PPT User Session");
 
        //Because EAI logins can trigger logging from the anonymous login, the response logging will trigger
        //from a different session. Query for the most recent corresponding request log and update it
        if (useGuestSession) {
          progress = progress+"\n"+"REF6: useGuestSession";
          boSessionFlat = TheApplication().GetBusObject("PPT User Session Flat");
          bcSessionXMLFlat = boSessionFlat.GetBusComp("PPT User Session XML");
          bcSessionXMLFlat.ActivateField("Parent Id");
          bcSessionXMLFlat.ClearToQuery();
          if (typeof(srcObj) != "undefined" && srcObj != null) bcSessionXMLFlat.SetSearchSpec("Source Object", srcObj);
          if (typeof(ref1) != "undefined" && ref1 != null) bcSessionXMLFlat.SetSearchSpec("Reference Id 1", ref1);
          bcSessionXMLFlat.SetSearchSpec("Response", "IS NULL");
          bcSessionXMLFlat.SetSearchSpec("Employee Login", gsGuest);
          bcSessionXMLFlat.SetSortSpec("Created (DESC)");
          bcSessionXMLFlat.ExecuteQuery(ForwardBackward);
          guestSessionFound = bcSessionXMLFlat.FirstRecord();
    
          if (guestSessionFound == true) guestSessionId = bcSessionXMLFlat.GetFieldValue("Parent Id");
        }
    
        if (guestSessionFound == false && createSession == true) {
          progress = progress+"\n"+"REF7: guestSessionFound == false & createSession == true";
          //Anonymous login session not found and there is no current session.  Create a new one
          with (bcSession) {
            NewRecord(NewBefore);
            SetFieldValue("Employee Id",TheApplication().LoginId());
            SetFieldValue("Session Stamp",gsLogSession);
            WriteRecord();
            gSessionId = GetFieldValue("Id");
          }
        } else if (guestSessionFound == true && createSession == false) {
          progress = progress+"\n"+"REF7: guestSessionFound == true & createSession == false";
          //Anonymous login session found and there is a current session. 
          //Link child records to the parent session for the Interface User and delete the guest session (faster than a merge)
          while (guestSessionFound) {
            bcSessionXMLFlat.SetFieldValue("Parent Id",gSessionId);
            bcSessionXMLFlat.WriteRecord();
            guestSessionFound = bcSessionXMLFlat.NextRecord();
          }
          with (bcSession) {
            ClearToQuery();
            SetSearchSpec("Id", guestSessionId);
            SetSortSpec("");
            ExecuteQuery(ForwardOnly);
            guestSessionFound = FirstRecord();
     
            if (guestSessionFound == true) DeleteRecord();
            ClearToQuery();
            SetSortSpec("");
            SetSearchSpec("Id", gSessionId);
            ExecuteQuery(ForwardOnly);
          }
        } else if (guestSessionFound == true && createSession == true) {
          progress = progress+"\n"+"REF7: guestSessionFound == true & createSession == true";
          //Anonymous login session found and there is no current session.  Update the guest session to EAI values
          with (bcSession) {
            ActivateField("Employee Id");
            ActivateField("Session Stamp");
            ClearToQuery();
            SetSearchSpec("Id", guestSessionId);
            SetSortSpec("");
            ExecuteQuery(ForwardBackward);
            found = FirstRecord();
     
            if (found == true) {
              SetFieldValue("Employee Id",TheApplication().LoginId());
              SetFieldValue("Session Stamp",gsLogSession);
              WriteRecord();
            }
          }
        } else {
          progress = progress+"\n"+"REF7: Anonymous login session not found and there is a current session.  Do Nothing";
          //Anonymous login session not found and there is a current session.  Do Nothing
        }
 
        //Reset the variable to check whether to merge the guest session.  This allows a log buffer dump
        gsMergeGuestSessions = "FALSE";
      }
      var bcSessionXML = boSession.GetBusComp("PPT User Session XML");
      var bcSessionXMLDtl = boSession.GetBusComp("PPT User Session XML Detail");
 
      with (bcSessionXML) {
        if (firstMessage) {
          progress = progress+"\n"+"REF8: firstMessage";
          //This is an insert so no query needed to update an existing record
          found = false;
          findResponseMethod = "Do Not Search";
        } else if (useGuestSession && guestSessionFound) {
          progress = progress+"\n"+"REF8: useGuestSession & guestSessionFound";
          //If this is the first update after a guest session is used, the key will not match but there should only be one XML record
          ClearToQuery();
          SetSearchSpec("Created By Login", gsGuest);
          SetSearchSpec("Parent Id", gSessionId);
          SetSearchSpec("Request", "IS NOT NULL");
          SetSearchSpec("Response", "IS NULL");
          ExecuteQuery(ForwardBackward);
          found = FirstRecord();
          findResponseMethod = "Session/Guest Login: "+gSessionId+"/"+gsGuest;
        } else if ((typeof(response) != "undefined" && response != null) ||
          (typeof(ref1) != "undefined" && ref1 != null && typeof(request) != "undefined" && request != null && gsReplaceSyncResponseWAsyncRequest == "TRUE")) {
          progress = progress+"\n"+"REF8: normal response update OR inbound request to a previously sent asynchronous request";
          //This is a normal response update to an existing message record or 
          //it is an inbound request to a previously sent asynchronous request with a matching Reference Id AND we want to log the Async request as the response
          ClearToQuery();
          SetSearchSpec("Parent Id", gSessionId);
 
          //If this is an Inbound request and Ref1 is provided, lookup by Ref1 
          if (typeof(ref1) != "undefined" && ref1 != null && typeof(request) != "undefined" && request != null) {
            SetSearchSpec("Reference Id 1", ref1.substring(0, 100));
            findResponseMethod = "Reference 1: "+ref1.substring(0, 100);
          } else {
            SetSearchSpec("Name", key);
            findResponseMethod = "Key: "+key;
          }
          SetSortSpec("");
          ExecuteQuery(ForwardBackward);
          found = FirstRecord();
        }
    
        //This is a normal request or an existing record could not be found for some reason
        if (found == false) {
          progress = progress+"\n"+"REF9: This is a normal request or an existing record could not be found for some reason ("+findResponseMethod+")";
          NewRecord(NewBefore);
          SetFieldValue("Name",key);
          SetFieldValue("Parent Id",gSessionId);
        }
    
        if (useGuestSession == true) {
          progress = progress+"\n"+"REF10: Set Name Key: "+key.substring(0, 100);
          SetFieldValue("Name", key.substring(0, 100));
        }
 
        //Since payloads can be any size, very large ones greater than CLOB size 131k need to be split with the text being 
        //put into multiple records
        if (typeof(request) != "undefined" && request != null) {
          progress = progress+"\n"+"REF11: Set Request";
          SetFieldValue("Request Time", TimeStamp("DateTimeFormatted"));
          splitPayload(bcSessionXML, bcSessionXMLDtl, "Request", request, 131072)
        }
        if (typeof(response) != "undefined" && response != null) {
          progress = progress+"\n"+"REF12: Set Response";
          SetFieldValue("Response Time", TimeStamp("DateTimeFormatted"));
          splitPayload(bcSessionXML, bcSessionXMLDtl, "Response", response, 131072)
        }
  
        if (typeof(dir) != "undefined" && dir != null && dir != "")   SetFieldValue("Direction", dir.substring(0, 30));
        if (typeof(recId) != "undefined" && recId != null && recId != "") SetFieldValue("Record Id", recId.substring(0, 15));
        if (typeof(recBC) != "undefined" && recBC != null && recBC != "") SetFieldValue("Record BC", recBC.substring(0, 50));
        if (typeof(status) != "undefined" && status != null && status !="") SetFieldValue("Status", status.substring(0, 30));
        if (typeof(srcObj)!="undefined" && srcObj != null && srcObj !="") SetFieldValue("Source Object", srcObj.substring(0, 50));
        if (typeof(name) != "undefined" && name != null && name != "")  SetFieldValue("Functional Name", name.substring(0, 50));
        if (typeof(logText)!= "undefined" && logText != null && logText !="") SetFieldValue("Log Text", logText.substring(0, 131072));
        if (typeof(userText)!= "undefined" && userText != null && userText !="") SetFieldValue("User Text", userText.substring(0, 255));
        if (typeof(retCode) != "undefined" && retCode != null && retCode != "")  SetFieldValue("Return Code", retCode.substring(0, 30));
        if (typeof(refField) != "undefined" && refField != null && refField!="") {
          SetFieldValue(refField, ref1);
          SetFieldValue("Reference Id 2", refField);
        } else {
          if (typeof(ref1) != "undefined" && ref1 != null)   SetFieldValue("Reference Id 1", ref1.substring(0, 100));
          if (typeof(ref2) != "undefined" && ref2 != null)   SetFieldValue("Reference Id 2", ref2.substring(0, 100));
        }
        if (typeof(ref3) != "undefined" && ref3 != null)   SetFieldValue("Reference Id 3", ref3.substring(0, 100));
        progress = progress+"\n"+"REF13: PreWrite";
        WriteRecord();
      }
      if (gsLogMode == "FILE") {
        progress = progress+"\n"+"REF14: gsLogMode == FILE";
        if (typeof(request) != "undefined" && request != null)  PropSetToFile(key+"_Request", request);
        if (typeof(response) != "undefined" && response != null) PropSetToFile(key+"_Response", response);
      }
    }
  } catch(e) {
    RaiseError(e, progress);
  } finally {
    request = null;
    response = null;
    Inputs = null;
    bcSessionXML = null;
    bcSessionXMLFlat = null;
    boSessionFlat = null;
    bcSession = null;
    boSession = null;
    TheApplication().SetProfileAttr("C1 Session Id", gSessionId);
  }
  return(progress);
}
}

The trimPS method is actually deprecated in my service but I include it in case it is useful to anyone.  I basically just takes a property set, converts it to text, then sets a specified field on an instantiated BC passed as an input to the converted text of the property set.  The assumption in using this method is that there is a limit to how large the stored payload can be.

function trimPS(ps, fieldName, bc, maxLength){
try {
  var psIn      = TheApplication().NewPropertySet();
  var psOut     = TheApplication().NewPropertySet();
  var bsService = TheApplication().GetService ("XML Converter (Data in Child PropSet)");
  psIn.SetProperty("EscapeNames", "False");
  var text:String = "";

  psIn.AddChild(ps);
  bsService.InvokeMethod("PropSetToXML", psIn, psOut);
  bc.SetFieldValue(fieldName, ToString(psOut).substring(0, maxLength));
  bc.SetFieldValue(fieldName+" Time", TimeStamp("DateTimeFormatted"));
  text = bc.GetFieldValue(fieldName);
  text = text.lTrim();
  if (text.substring(0, 14) == "PropertySet [ ") text = text.substring(14);
  text = text.rTrim("]");
  bc.SetFieldValue(fieldName,text);
} catch (e) {
  throw(e);
} finally { 
  psOut = null;
  psIn = null;
  bsService = null;
}
}

The splitPayload method is what replace the trimPS method.  It is no longer limited in being able store only a certain character length of payload as this method splits the payload into chunks of a specified size and inserts records into the instantiated BC passed as an input.

function splitPayload(parentbc, detailbc, fieldName, ps, maxLength) {
try {
  var psIn      = TheApplication().NewPropertySet();
  var psOut     = TheApplication().NewPropertySet();
  var bsService = TheApplication().GetService ("XML Converter (Data in Child PropSet)");
  psIn.SetProperty("EscapeNames", "False");
  var text:String = "";
  var stripPS = false;
  var textPS = "";
  
  psIn.AddChild(ps);
  bsService.InvokeMethod("PropSetToXML", psIn, psOut);
  textPS = ToString(psOut);

  if (textPS.length > maxLength) {
    while (textPS.length > 0) {
      detailbc.NewRecord(NewAfter);
      detailbc.SetFieldValue("Field", fieldName);
      detailbc.SetFieldValue("Log Text", textPS.substring(0, maxLength));
 
      //Service adds a Prefix that needs to be removed
      text = detailbc.GetFieldValue("Log Text");
      text = text.lTrim();
      if (text.substring(0, 14) == "PropertySet [ ") {
        stripPS = true;
        text = text.substring(14);
      }
 
      textPS = textPS.substring(maxLength, textPS.length); 
 
      //If the Text is broken up across multiple records, need to remove the trailing ] from the last record
      if (stripPS && textPS.length < maxLength) {
        text = text.rTrim("]");
      }
      detailbc.SetFieldValue("Log Text",text);
      detailbc.WriteRecord();
    }
  } else {
    parentbc.SetFieldValue(fieldName, textPS);
    text = parentbc.GetFieldValue(fieldName);
    text = text.lTrim();
    if (text.substring(0, 14) == "PropertySet [ ") {
      stripPS = true;
      text = text.substring(14).rTrim("]");
      parentbc.SetFieldValue(fieldName, text);
    }
//  parentbc.WriteRecord();
  }
} catch (e) {
  RaiseError(e);
} finally { 
  psOut = null;
  psIn = null;
  bsService = null;
}
}

Next: Viewing the Payload

State of Logging - An Introduction

I was reading Jason Le's recent post about XML Logging and I realized the problem statement he was describing was intimately familiar to me because it is something I have been dealing with over the years and have evolved a solution for it.  I say evolved because it has gone though so many iterations by this point I am not sure where to begin.  So let me start with a verbal explanation, and then I will get into the details.

I built an eScript Logging Service back in the day to help with tracing processing through custom script.  This was written out to a text file in the file system.  I don't recall the sequence of events after that but at some point I added an XML logging utility to this so that the XML files would be written to the file system as well. This was initially an explicit call to a business service within the integration WF to pass an XML Property Set  so it could be written out.  I then moved to a client which was using a business service to create custom SOAP headers so I modified the logging service so that it could be called as a custom filtering service itself.  This allowed the exact payload to be captured as it was leaving/returning to the Siebel application.

At some point I ended up on a client that had UNIX Application servers, needed me to do production support post go-live AND was very restrictive about granting access to the production file system.  Rather than deal with the UNIX and access issues, I opted to modify the service so it could operate in two modes.  When using a thick client, it would continue to write all information out to the local file system as defined by the SIEBEL_LOG_DIR environment variable.  But I allowed thin client users to output logging data to a new set of custom tables.  Basically when a user logs in, a session record is created.  All escript logging data is written out to a 1:M detail table in buffered chunks to minimize performance hits.  XML Logging does the same (though in a slightly different way).  Each detail record has the opportunity to store a row id which allows a session to be linked to a particular record that was logged, like an Order Id.  This allows for audit views to be created which show all the user sessions with logging information tied to a particular record.

The other problem I needed to solve was that when an error occurs, Siebel rolls back transactions.  Therefore all interfaces use the EAI Transaction Service and I have modified this service to set a flag so that when in a transaction, all XML payloads are stored in memory until the transaction is either aborted or committed, at which point all the messages are written to the DB in the order they were executed.

To view logging information, whether XML or escript, requires the many detail records to be reassembled into a viewable format.  There is a method of the service that basically just queries all the detail records for a particular session or XML Payload and concatenates the text into a single value.  This method can be invoked from a calculated field and the calculated field exposed on a form applet.  Because form applet fields are not the best way to see the data, I typically copy the data out of the field and into a text editor of choice.  For instance I use Notepad++  with a Pretty Print add on to view XML payloads.

It will take several posts to go over the implementation in detail, but hopefully this whets people's appetites

Next: The XML Logger

eScript Framework on 8.1

Converting the eScript framework to 8.1 proved a bit troublesome for me as the Siebel strong type engine has apparently dropped support for prototyping Siebel objects, such as a Business Service.  This makes the implementation a bit less clean since without being able to declare a prototype of the Log or Frame objects on application start, we are left with having to have every framework function be a child of the Application object.  This being the case, I consolidated the Frame and Log objects from the 7.8 framework into a single Utility object since there was not as much advantage in separating them.  Instead of the elegant 7.8 calls:

Log.Stack("MyMethod",1);
Log.Step("Log the time as "+Frame.Timestamp("DateTimeMilli"),3);
Log.Vars("VariableName", varValue,3)
Log.Unstack("",1);

we instead do this:

TheApplication().logStack("Write",this)
TheApplication().Utility.logStep("Log the time as "+
    TheApplication().Utility.Timestamp("DateTimeMilli"));
TheApplication().Utility.logVars("VariableName", varValue)
TheApplication().Unstack("");

Oh well.  To mitigate this somewhat, I have added a number of enhancements since the initial series of posts, which I will try to discuss sometime soon.

• Automatically tie log level to the function doing the logging (Stack/Unstack vs variables for instance), hence no need for the numeric last parameter to all logging functions (though it is still optional as an override)
• Added support for unix file systems
• Standardize the identification of logging record Ids (by passing the 'this' reference it will append the row id for methods with Write, Delete and Invoke in the name)

To implement the basic framework in 8.1, you need something like this in the Application Start event:
        this.Utility = TheApplication().GetService("ETAR Utilities");
        this.Utility.Init();

Here is the Declarations section:

var gsOutPutFileName;
var gsFileName;
var gsLogMode;
var giIndent = 2; //Indent child prop sets this many spaces to the right for each level down.
var giPSDepth = 0; // How deep in the property set tree, what level
var gaFunctionStack = new Array(); //used in debugStack function to store called functions
var giStackIndex = 0; //Where in the function stack the current function resides
var gsIndent = ''; //used in debug methods to identify stack indents
var giLogBuffer = 0;
var giLogLines = 0;
var gsLogPath = "";
var gsLogCache = "";
var gsLogSession = "";
var giErrorStack = 0;
var ge = new Object();
var gStack = new Object();
var gCurrentLogLvl;

The Utilities business service is a cached service in tools.  It's Init function looks like this:

giErrorStack = 0;
ExtendObjects();
gsLogMode = GetSysPref("Framework Log Mode");
gsLogMode = (gsLogMode == "" ? "FILE" : gsLogMode.toUpperCase());
gsLogSession = TimeStamp("DateTimeMilli");

if (TheApplication().GetProfileAttr("ETAR User Log Level") != "")
    gCurrentLogLvl = TheApplication().GetProfileAttr("ETAR User Log Level");
else gCurrentLogLvl = GetSysPref("CurrentLogLevel");
giLogBuffer = GetSysPref("Log Buffer");
gsLogPath = GetSysPref("Framework Log Path");
try {
     var os;
     os = Clib.getenv("OS");
} catch(e) { os = "UNIX Based"; }
try {
   gsFileName = "Trace-"+TheApplication().LoginName()+"-"+gsLogSession+".txt"
  //A Windows OS indicates a thick client. Assume the path is the dynamicly
  //determined Siebel_Home\Log directory, or ..\log
  if (os.substring(0, 7) == "Windows") {
//  gsLogPath = gsLogPath.replace(/\\$/, "");  //Remove trailing backslash if used
//  gsLogPath = gsLogPath.replace(/\x47/, "\\");  //switch invalid OS directory seperators
    gsLogPath = "..\\Log\\";
    gsOutPutFileName = gsLogPath+gsFileName;
  } else {
    gsLogPath = gsLogPath.replace(/\x47$/, "");  //Remove trailing backslash if used
    gsLogPath = gsLogPath.replace(/\\/, "/");  //switch invalid OS directory seperators
    gsLogPath = gsLogPath+"/";
    gsOutPutFileName = gsLogPath+gsFileName;
 }
} catch(e) {
  gsLogPath = "";
  gsOutPutFileName = gsFileName;
}

eScript Framework - GetRecords

Matt has launched YetAnotherSiebelFramework, a blog about... you get the idea. This is an important step forward in this community's attempt to create a true open source Siebel eScript framework. He adds flesh to the skeleton I have assembled here. He will shortly be adding his own posts to explain his functions in more detail but I thought I would get a head start with starting a discussion about one of his most important pieces, the GetRecords function. I say one of the most important pieces, as the real driver behind this solution is to replace the many plumbing steps, as Matt calls them, that sit in so much of our script. So for instance to query an Account by Id (sId) to get the Location for instance, you would write something like this:

var boAccount = TheApplication().GetBusObject("Account");
var bcAccount = boAccount.GetBusComp("Account");
with (bcAccount) {
 ActivateField("Location");
 ClearToQuery();
 SetViewMode(AllView);
 SetSearchSpec("Id", sId);
 ExecuteQuery(ForwardOnly);

 if (FirstRecord()) {
     var sLoc = GetFieldValue("Location");
 }
}

You get the idea. His function essentially replaces this with:

var sLoc = oFramework.BusComp.GetRecord("Account.Account", sId, ["Location"]).Location;

So that is pretty cool. What follows is mostly quibbling but I think attracting criticism from our peers is the best way to make this framework the most usable it can be. On a technical note, I am using 7.8 and the T engine for my personal sandbox so have not yet been able to get Matt's entire framework up and running. Nevertheless, I have gotten his individual functions running so I will limit my discussion to that scope. Here are my thoughts:

(1) My biggest point is to think about whether it makes more sense to return a handle of the BC rather than filling an array. I am thinking about this in terms of performance. There are times when having the array would be useful, like say when I want to perform array operations on the data, like doing a join. But often, I may just need to test a field value(s) and perform operations on other values conditionally. In this case, I would only be using a small percentage of the data I would have filled an array with. It may also be useful to have a handle in order to use other Siebel BC functions like GetAssocBusComp or GetMVGBusComp. I do not claim to be a java guru, but I am curious about the performance implications. What I have done with my own framework is to build three functions:

• Bc_GetArray (this is basically the same as Matt's)
• Bc_GetObject (stops before filling the array and just returns the handle to the BC)
• Bc_GetInvertedArray (Same as Matt's but makes the fields the rows and the record the column)

(2)I took out the following two lines:

aRow[aFields[i][0]] = vValue;
if (aFields[i][0].hasSpace()) aRow[aFields[i][0].spaceToUnderscore()]= vValue;

that checks if the field name has a space and if so changes it to an underscore and replaced them with a single line:

aRow[aFields[i][0].spaceToUnderscore()]= vValue;

I think this should be more efficient since a regular expression search is being done regardless, I think just doing the replace in one step saves an operation.

(3) I like the first argument, "Account.Account" syntax for most situations. I think we can make this even more robust though by allowing us to pass in an already instantiated BC. This is probably infrequently necessary moving forward with the pool concept Matt has introduced, but there is a low cost way to handle either. What I have done is to add a test of the data type:

if (typeof(arguments[0])=="string") {

before starting the pool logic. I then added an else to allow us to pass a BC object in and add it to the pool:

else {
  oBc  = arguments[0];
  this.aBc[oBc.Name()] = oBc;
}

(4) I think I understand where Matt is going with the pool as a mechanism to instantiate BCs less frequently. His bResetContext argument, the flag indicating that the pool be flushed, is I think unnecessarily too drastic. If I understand it correctly, setting this flag to true would flush the entire pool. While this may sometimes be desired, it seems more useful to just flush the BO/BC in play. This would allow you to write code for instance in nested loops that jumps between BCs without clearing context when it is not necessary too. I may not be thinking of a situation where this would be necessary though so if anyone can think of one I am all ears. My recommendation would be to make the flush just clear the passed BO/BC but if the "Full flush" is necessary, then perhaps a code indicating one or the other can be used. This could be accomplished by just removing the reference to the FlushObjects function, as the following if/else condition effectively resets the BO/BC variables in the array after evaluating the bResetContext argument.

eScript Framework - Logging Variables

Here is another entry into the logging framework previously discussed. The idea behind this function is to Log multiple variable values to separate lines of our log file using a single line of script. This keeps our script pristine and makes the log file well organized and easy to read. The script to call the function is as follows:

Log.stepVars("Record Found", bFound, " Account Id", sId);

The expected arguments are name/value pairs where the name is a descriptive string (could just be the name of the variable) and the value is the variable itself that we want to track. There is no limit to the number of pairs. There is an optional last parameter to indicate the enterprise logging level (stored in system parameters) above which this line should be written.

The results will be written to the log file as:

06/29/2010 13:33:53 ................Record Found: Y
06/29/2010 13:33:53 ..................Account Id: 1-ADR45

The script to implement follows. This is meant to be added as a new method in the 'eScript Log Framework' business service.

function stepVars () {
  var Args = arguments.length;
  var iLvl = (Args % 2 == 0 ? 0 : arguments[Args - 1]);
  var iParams = (Args % 2 == 0 ? Args : Args - 1;
  var sProp, sValue;

  for (var i=0; i < iParams; i++) {
    sProp = arguments[i++]+": ";
    sValue = arguments[i];
    Log.step(sProp.lPad(30, ".")+sValue, iLvl);
  }
}

Also, a new line will need to be added to the Init section to instantiate this function on Application start:

Log.prototype.stepVars = stepVars;

I want to draw particular attention to two java features which may be useful in other applications. The first is how to reference a variable number of arguments in a function call. Notice the special array variable, 'arguments'. This array is defined as all of the arguments passed to this function with no special declarations. It can be referenced just like any other array. There are some exceptions with how this array can be manipulated though with push() and pop() not working as you might expect.

The second, is how to assign a variable using an inline if, ( condition ? value if true : value if false). The condition is any expression that will evaluate to either true or false. The first expression after the ? is the value returned if the condition evaluates to true, and the last expression is what is returned if the consition evaluates to false.

The Framework - Revised

After some fits and starts, I finally got around to a data dump of my Siebel eScript Framework with some rough instructions on how to implement it. After a very worthwhile back and forth on Jason Le's LinkedIn group I have some structural modifications to make. The new framework will be implemented as a pair of business services. The main advantage of this is the code is more centrally located in a single repository. Multiple applications can reference it there. A fairly good case has been made that the logic can all sit in a single business service underneath one object, TheApplication. I think there are decent reasons to do either but preferences may vary.

Create a new BS, called 'eScript Framework' and check the Cache flag.
It's PreInvoke should have the following:

try {
  var bReturn = ContinueOperation;
    switch (MethodName) {
      case "Init":
        bReturn = CancelOperation;
        break;
    }
    return (bReturn);
}
catch(e) {
  throw(e);
}

Then create a method for each function in the framework from the previous post. So far the Methods I have are:
AddToDate
DateToString
StringToDate
DiffDays
GetLocalTime
GetSysPref
SetSysPref
QueryExprArrayReturn

Now, create the Logging BS. Create a new Business Service named, 'eScript Log Framework', and check the Cache flag. Its PreInvoke should have the following:

try {
  var bReturn = ContinueOperation;
  switch (MethodName) {
    case "Init":
      var sPath = Frame.GetSysPref("Framework Log Path");
      sPath = sPath.replace(/\\$/, "");  //Remove trailing backslash if used
      gsOutPutFileName = sPath+"\\Trace-"+
   TheApp.LoginName()+"-"+
   Frame.GetLocalTime("%02d%02d%d%02d%02d%02d")+".txt";
  
      //Get the System Preference Log Level.  Get the Log Level set for this user (if provided) 
      //and then set the log level for this session
      var sLogLevel = Frame.GetSysPref("CurrentLogLevel");
      if (TheApp.GetProfileAttr("User Log Level") != "")
      TheApp.SetProfileAttr("CurrentLogLevel", TheApp.GetProfileAttr("User Log Level"));
      else TheApp.SetProfileAttr("CurrentLogLevel", sLogLevel);
      Log.step("Session Logging Level: "+TheApp.GetProfileAttr("CurrentLogLevel"), 1);
      bReturn = CancelOperation;
      break;
  }
  return (bReturn);
}
catch(e) {
  throw(e);
}

Set the Declarations section to the following:

var gsOutPutFileName; 
var giIndent = 2; //Indent child prop sets this many spaces for each level down.
var giPSDepth = 0; // How deep in the property set tree, what levelvar CurrentLogLevel = 2;
var gaFunctionStack = new Array(); //used in debugStack function to store called functions
var giStackIndex = 0; //Where in the function stack the current function resides
var gsIndent = ''; //used in debug methods to identify stack indents
var giLogBuffer = Frame.GetSysPref("Log Buffer");
var giLogLines = 0;
var gsLogCache = "";

Then create a method for each function in the framework from the previous post. So far the Methods I have are:
step
StartStack
Stack
Unstack
RaiseError
PropSet
DumpBuffer

Now open up the Server script for the Application object you are using (this should be done in every Application being used where framework functions may be referenced). Add this to the Declarations section:

Object.prototype.TheApp = this;
Object.prototype.Frame = TheApp.GetService("eScript Framework");
Object.prototype.Log = TheApp.GetService("eScript Log Framework");

Frame.InvokeMethod("Init", NewPropertySet(), NewPropertySet());
Log.InvokeMethod("Init", NewPropertySet(), NewPropertySet());

Your done. Log and Frame functions can now be referenced from anywhere in your scripts.

Framework Logging Performance

I have been working with my eScript logging framework for a couple of months now and it has been extremely helpful with debugging complicated script procedures. What keeps it from being truly useful in a production environment though is it is too damn slow. In an ideal world, I could leave logging on at all times, or at least for long periods of times for users or groups I want to keep track of. In order to do this, I need to make sure they do not notice a significant degradation in their work day.

The way the logging object functions work in the framework is basically to send one line at a time to the step function which then opens a file, writes the content along with a timestamp, and closes the file. It is these file operations that take the great majority of performance time. A given complicated script takes about 7 seconds with logging turned up to 5 which outputs a 63kb log file on my thick client. While I could expect server performance to be a bit faster, just turning logging off, reduces the performance time to under 2 seconds. What to do...

Buffer the output. It strikes me that I will do the exact same thing Siebel does with its own log files. Ever notice that the SQL Spool file or server log files are not always completely up to date with what you are executing in the GUI? This is because the application keeps a buffer of output and only writes the buffer when it is full. So I will do the same thing. I will store a new system parameter called 'Log Buffer' which will equal the number of lines to buffer. I will then create some new global variables to keep a running line count and one to buffer the output.

var giLogBuffer = Frame.GetSysPref("Log Buffer");
var giLogLines = 0;
var giLogCache = "";

All I have to do is modify my step function to leverage these values. Here is my step function again from the framework Log object with my mods:

step : function ( text, Lvl ) {
if (((Lvl == null)||(TheApp.GetProfileAttr("CurrentLogLevel") >= Lvl))&&
 (giLogLines >= giLogBuffer)) {
  var fp = Clib.fopen(OutPutFileName, "a");
  Clib.fputs(giLogCache, fp);
  Clib.fputs(Frame.GetLocalTime()+" "+gsIndent + text + "\n", fp);
  Clib.fclose(fp);
  giLogLines = 0;
  giLogCache = "";
}
else {
  giLogLines++;
  giLogCache += Frame.GetLocalTime()+" "+gsIndent + text + "\n"
}
}

After setting the new buffer parameter to 20, performance improved drastically. My old 7 second run went down to 2 seconds. Could not even notice that logging was ramped up. My only concern is that things I really want to see don't appear in the log right away, like errors. So I need to modify the RaiseError function to artificially fill the buffer and force a log dump. Here is the new line I inserted (followed by the existing line):

giLogLines = giLogBuffer; //insure errors gets written to log file
Log.step("---End Function "+sFunction+"\n");

I would probably need to do something similar on the Application Close event. Not sure if user's hitting windows X will trigger this though. Something to think about.

eScript Framework - Query return Array

In my post introducing my eScript Framework, I glossed over the functional content of the functions I included so let me go into some more detail before proceeding. The last function in the declaration was called QueryExprArrayReturn. This function will execute a query against the business component whose string name is passed to the function using a complete expression also passed. The last parameter is an array of fields whose values will be returned, via an associative array.

QueryExprArrayReturn : function( sBO, sBC, sExpr, aFields) {
// Use : Frame.QueryExprArrayReturn (sBO : string nsme of Business
Object,
// sBC : string nsme of Business Component,
// sExpr : search expression to be applied,
// aFields : array of fields to be returned)
// Returns : string replacing fields and parameters from the lookup BC and/or property set
  var aFnd, bFound, iRecord, sField;
  var aValues = new Array();
  var rePattern = /(?<=\[)[^[]*(?=\])/g; 
  with (TheApp.GetBusObject(sBO).GetBusComp(sBC)) { 
    while ((aFnd = rePattern.exec(sExpr)) != null) ActivateField(aFnd[0]); 
    for (var c=0; c < aFields.length; c++) ActivateField(aFields[c]); 
    ClearToQuery(); 
    SetViewMode(AllView); 
    SetSearchExpr(sExpr); 
    ExecuteQuery(ForwardOnly); 
    if (FirstRecord()) { 
      iRecord = 0; 
      for (var i=0; i < aFields.length; i++) { 
        aValues[aFields[i]] = new Array(); 
        aValues[aFields[i]][iRecord] = GetFieldValue(aFields[i]); 
      } 
      while (NextRecord()) { 
        iRecord++; 
        for (var i=0; i < aFields.length; i++) { 
          aValues[aFields[i]][iRecord] = GetFieldValue(aFields[i]); 
        } 
      } 
    } 
    return(aValues) 
  } 

What is occurring here is pretty straightforward:

1. Instantiate a BC using the passed BO/BC strings
2. Activate any fields used in the Search Expression
3. Activate the fields needing to be returned
4. Query using the passed search expression
5. If at least one record is found, create an associtive array of field values where the first index is the field name and the second index is the record number
6. Continue populating this array for each record found

Probably the most interesting aspect of this query is the use of a regular expression search of the passed in expression to activate and BC fields present there by identifying them in enclosing square brackets [].

eScript Framework - Logging

The ABS Framework apparently has a logging module that Jason describes. This is interesting because I have been building my own logging technique over the past couple of years that largely parallels what I believe the framework does. Understanding object prototyping redirected my thoughts a bit and helped me centralize the effort. My previous post introduced the Frame and TheApp objects. This post will introduce a new object: Log. The following script will also be added to the Application declarations section.

Object.prototype.Log = function() {
return {
  step : function ( text, Lvl ) {
    if ((Lvl == null)(TheApp.GetProfileAttr("CurrentLogLevel") >= Lvl)) {
      var fp = Clib.fopen(OutPutFileName, "a");
      Clib.fputs(Frame.GetLocalTime()+" "+gsIndent + text + "\n", fp);
      Clib.fclose(fp);
    }
  },
  RaiseError : function ( e ) {
    if(!defined(e.errText)) e.errText = e.toString();
    var sFunction = gaFunctionStack.pop();

    Log.step("".rPad(100, "*"));
    Log.step("*** - ERROR - "+sFunction+" - "+e.errCode);
    Log.step("***           "+e.errText.replace(/\n/g, "\n"+gsIndent+"".rPad(20," ")+"***           "));
    Log.step("".rPad(100, "*")+"\n");
    Log.step("---End Function "+sFunction+"\n");

    var sLength = gaFunctionStack.length;
    gsIndent = "".rPad(giIndent*sLength, ' ');

    if (sLength>0) Log.step("<<-Returning to Function "+gaFunctionStack[sLength-1]+"\n");     throw(e);   },   StartStack : function ( sType, sName, sMethod, Lvl ) {     gaFunctionStack.push(sName+"."+sMethod);     gsIndent = "".rPad(giIndent*gaFunctionStack.length, ' ');     if (TheApp.GetProfileAttr("CurrentLogLevel") >= Lvl) {
      Log.step(" ");
      Log.step("".rPad(100, "-"));
      Log.step("".rPad(100, "-"));
      Log.step(sType+": "+sName);
      Log.step("Method: "+sMethod+"\n");
    }
  },
  Stack : function ( sFunction, Lvl ) {
    gaFunctionStack.push(sFunction);
    gsIndent = "".rPad(giIndent*gaFunctionStack.length, ' ');

    if (TheApp.GetProfileAttr("CurrentLogLevel") >= Lvl) {
      Log.step(" ");
      Log.step(">".rPad(100, "-"));
      Log.step("Function: "+sFunction+"\n");
    }
  },
  Unstack : function ( sReturn, Lvl ) {
    var sFunction = gaFunctionStack.pop();
    if (TheApp.GetProfileAttr("CurrentLogLevel") >= Lvl) {
      var sString = "";
      if (sReturn != "") sString = " - Return: "+sReturn;
      Log.step("---End Function "+sFunction+sString+"\n");
    }
    var sLength = gaFunctionStack.length;
    gsIndent = "".rPad(giIndent*sLength, ' ');

    if ((TheApp.GetProfileAttr("CurrentLogLevel") >= Lvl)&&(sLength>0))
         Log.step("<<-Returning to Function "+gaFunctionStack[sLength-1]+"\n");   },   PropSet : function (Inputs, Lvl) {         // Print out the contents of a property set.     if (TheApp.GetProfileAttr("CurrentLogLevel") >= Lvl) {
      PSDepth++; // Dive down a level
      var InpChildCount, inprop, inpropval, inpropcnt;
      var BlankLine = ' ';
      var Indent = "".lPad(giIndent*PSDepth, " ") + ToString(PSDepth).lPad(2, "0") + '  ';

      Log.step(BlankLine);
      Log.step(Indent + '---- Starting a new property set ----');
      InpChildCount = Inputs.GetChildCount();
      Log.step(Indent + 'Value is ........ : "' + Inputs.GetValue() + '"');
      Log.step(Indent + 'Type is  ........ : "' + Inputs.GetType() + '"');
      Log.step(Indent + 'Child count ..... : ' + ToString(InpChildCount));

      var PropCounter = 0;
      inprop = Inputs.GetFirstProperty();
      while (inprop != "") { // Dump the properties of this property set
        PropCounter++;
        inpropval = Inputs.GetProperty(inprop);
        Log.step(BlankLine);

        var PropCountStr = ToString(PropCounter).lPad(2, "0");
        Log.step(Indent+'Property '+PropCountStr+'  name : <'+inprop    + '>');
        Log.step(Indent+'Property '+PropCountStr+' value : <'+inpropval    + '>');
        inprop = Inputs.GetNextProperty();
      }

      // Dump the children of this PropertySet
      if (InpChildCount != 0) {
        for (var ChildNumber = 0; ChildNumber < InpChildCount; ChildNumber++) {
          Log.step(BlankLine);
          Log.step(Indent + 'Child Property Set ' + ToNumber(ChildNumber + 1) + ' of ' + ToNumber(InpChildCount) + ' follows below.');
          Log.step(Indent + 'This child is on level ' + ToNumber(PSDepth));
    
          // Recursive call for children, grandchildren, etc.
          Log.PropSet(Inputs.GetChild(ChildNumber), Lvl);
        }
      }
      PSDepth--; // Pop up a level
    }
  }
}
}();
var OutPutFileName;
//Indent child prop sets this many spaces to the right for each level down.
var giIndent = 2;
var PSDepth = 0; // How deep in the property set tree, what level
var CurrentLogLevel = 2;
//used in debugStack function so store called functions
var gaFunctionStack = new Array();
var giStackIndex = 0; //Where in the function stack the current function resides
var gsIndent = ''; //used in debug methods to identify stack indents

In addition, I added the following to the Application Start event. The prerequisite for this is the new profile attribute I created in this post, and the creation of a new system parameter, 'Framework Log Path':

  var sPath = Frame.GetSysPref("Framework Log Path");
  sPath = sPath.replace(/\\$/, "");  //Remove trailing backslash if used
  OutPutFileName = sPath+"\\Trace-"+
         TheApp.LoginName()+"-"+
         Frame.GetLocalTime("%02d%02d%d%02d%02d%02d")+".txt";
  try {
    Log.step("Log Application Start Event", 1);
  }
  catch(e) {
    //default to OOTB Log File Location:
    OutPutFileName = "Trace-"+TheApp.LoginName()+"-"+
             Frame.GetLocalTime("%02d%02d%d%02d%02d%02d")+".txt";
    Log.step("Invalid Preference - Framework Log Path: "+sPath, 0);
  }
  //Get the System Preference Log Level. Get the Log Level set for this user (if provided) and
  //then set the log level for this session
  var sLogLevel = Frame.GetSysPref("CurrentLogLevel");
  if (TheApp.GetProfileAttr("User Log Level") != "")
    TheApp.SetProfileAttr("CurrentLogLevel", TheApp.GetProfileAttr("User Log Level"));
  else TheApp.SetProfileAttr("CurrentLogLevel", sLogLevel);
  Log.step("Session Logging Level: "+TheApp.GetProfileAttr("CurrentLogLevel"), 1);

Here is an example of these functions in use in a PreInvokeMethod event of a BC:

function BusComp_PreInvokeMethod (MethodName) {
try {
  Log.StartStack("Business Component", this.Name(), MethodName, 1);
  var bReturn;
  var sVar1 = "TEST"
  switch(MethodName) {
    case "TestMethod":
      Log.step("Variable 1: "+sVar1 ,1);
      TestMethod(sVar1 );
      bReturn = CancelOperation;
      break;
  }

  Log.Unstack(bReturn,0);
  return(bReturn);
}
catch(e) {
  Log.RaiseError(e);
}
}

And this is how it would be used in a method:

function TestMethod (sVar1) {
try {
  Log.Stack("TestMethod", 1);
  Log.step("sVar1: ".lPad(30,".")+sVar1+"\n", 2);
  sVar1 += sVar1 + sVar1;
  Log.Unstack("N", 2);
}
catch(e) {
  Log.RaiseError(e);
}
}

The result of this provides an individual log file placed in the directory specified by the system parameter. Each method call is indented 2 spaces.

UPDATE: I am no HTML wizard but am learning. I updated tags to make code easier to read

The Framework

It has been a while but I want to return to the eScript Framework. I have already put up a couple of posts about some potential functions the Framework should include. So lets put a wrapper around this based on Jason's post. My thinking is that this code will all be placed in the Application declarations sections. I am still working on understanding the Object prototypes for modifying BCs which I hope will add significantly more functionality. Here is the script so far:

Object.prototype.TheApp = this;
Object.prototype.Frame = function() {
  return {
  AddToDate : function ( srcDate, iDays, iHrs, iMin, iSec, nSign ) {
  //Use : Frame.AddToDate ( srcDate : Date Object
  // iDays, iHrs, iMin, iSec : Integer Numbers
  // nSign : 1 or -1 {1 to ADD to the srcDate
  // -1 to SUBTRACT from the srcDate } )
  //Returns : date object, after adding/subtracting iDays, iHrs, iMin and iSec to the srcDate
    var retDate = srcDate;
    retDate.setDate(retDate.getDate()+nSign*iDays);
    retDate.setHours(retDate.getHours()+nSign*iHrs);
    retDate.setMinutes(retDate.getMinutes()+nSign*iMin);
    retDate.setSeconds(retDate.getSeconds()+nSign*iSec);
    return(retDate);
  },
  DateToString : function (dDate) {
  //Use: Frame.DateToString ( dDate : Date Object )
  //Returns: A string with the format "mm/dd/yyyy" or "mm/dd/yyyy hh:mi:ss"
    var sMon = ToString(dDate.getMonth()+1);
    if (sMon.length==1) sMon = "0" + sMon;
    var sDay = ToString(dDate.getDate());
    if (sDay.length==1) sDay = "0" + sDay;
    var sHrs = ToString(dDate.getHours());
    if (sHrs.length==1) sHrs = "0" + sHrs;
    var sMin = ToString(dDate.getMinutes());
    if (sMin.length==1) sMin = "0" + sMin;
    var sSec = ToString(dDate.getSeconds());
    if (sSec.length==1) sSec = "0" + sSec;
    if (sHrs == "00" && sMin == "00" && sSec == "00")
      return(sMon+"/"+sDay+"/"+dDate.getFullYear());
    else return(sMon+"/"+sDay+"/"+dDate.getFullYear()+" "+sHrs+":"+sMin+":"+sSec);
  },
  StringToDate : function ( sDate ) {
  //Use: Frame.StringToDate(sDate: A string with format "mm/dd/yyyy" or "mm/dd/yyyy hh:mi:ss"
  //Returns: a Date Object
    var aDateTime = sDate.split(" ");
    var sDate = aDateTime[0];
    var aDate = sDate.split("/");
    if (aDateTime.length==1) 
      return (new Date(ToNumber(aDate[2]), 
                      ToNumber(aDate[0])-1, 
                      ToNumber(aDate[1])));
    else {
      var ArTime = aDateTime[1];
      var aTime = ArTime.split(":");
      if (aTime[0]=="00" && aTime[1]=="00" && aTime[2]=="00")
        return (new Date(ToNumber(aDate[2]), 
                         ToNumber(aDate[0])-1, 
                          ToNumber(aDate[1])));
      else {
        return (new Date(ToNumber(aDate[2]),
                        ToNumber(aDate[0])-1, 
                        ToNumber(aDate[1]),
                        ToNumber(aTime[0]), 
                        ToNumber(aTime[1]), 
                        ToNumber(aTime[2])));
      }
    }
  },
  GetSysPref : function ( sPreference ) {
  //Use: Frame.GetSysPref( sPreference: the preference name in the system preference view )
  //Returns: the value in the system preference view for this preference name
    var boPref = TheApp.GetBusObject("System Preferences");
    var bcPref = boPref.GetBusComp("System Preferences");
    with (bcPref) {
      ClearToQuery();
      SetSearchSpec("Name", sPreference);
      ActivateField("Value");
      ExecuteQuery(ForwardOnly);
      if (FirstRecord()) return(GetFieldValue("Value"));
      else return("");
    }
  },
  SetSysPref : function ( sPreference, sValue ) {
  //Use: Frame.SetSysPref( sPreference: the preference name in the system preference view,
  // sValue: the value of the preference )
    var boPref = TheApp.GetBusObject("System Preferences");
    var bcPref = boPref.GetBusComp("System PreferencesUpd");

    with (bcPref) {
      ClearToQuery();
      ActivateField("Value");
      SetSearchSpec("Name", sPreference);
      ExecuteQuery(ForwardOnly);

      if (FirstRecord()) SetFieldValue("Value", sValue);
      else {
        NewRecord(NewBefore);
        SetFieldValue("Name", sPreference);
        SetFieldValue("Value", sValue);
        WriteRecord();
      }
    }
  },
  DiffDays : function (date1, date2) {
  // Use : Frame.DiffDays ( date1 : Starting Date object, date2 : Another Date object )
  // Returns : Number of days between date1 and date2
    return ((date2.getTime()-date1.getTime())/(1000*60*60*24));
  },
  GetLocalTime : function (sFormat) {
  // Use : Frame.GetLocalTime ()
  // Returns : string of the current timestamp
    var dNow = new Date();
    var sNow;
    if (sFormat != null)
      Clib.sprintf(sNow, sFormat, dNow.getMonth()+1, dNow.getDate(), 
        dNow.getFullYear(), dNow.getHours(), dNow.getMinutes(), dNow.getSeconds());
    else Clib.sprintf(sNow, "%02d/%02d/%d %02d:%02d:%02d", dNow.getMonth()+1,
      dNow.getDate(), dNow.getFullYear(), dNow.getHours(), dNow.getMinutes(),
      dNow.getSeconds());
    return (sNow);
  },
  QueryExprArrayReturn : function( sBO, sBC, sExpr, aFields) {
  // Use : Frame.QueryExprArrayReturn (sBO : string nsme of Business Object,
  // sBC : string nsme of Business Component,
  // sExpr : search expression to be applied,
  // aFields : array of fields to be returned)
  // Returns : string replacing fields and parameters from the lookup BC and/or property set
    var aFnd, bFound, iRecord, sField;
    var aValues = new Array();
    var rePattern = /(?<=\[)[^[]*(?=\])/g; 
    with (TheApp.GetBusObject(sBO).GetBusComp(sBC)) { 
      while ((aFnd = rePattern.exec(sExpr)) != null) ActivateField(aFnd[0]);
      for (var c=0; c < aFields.length; c++) ActivateField(aFields[c]); 
      ClearToQuery(); 
      SetViewMode(AllView); 
      SetSearchExpr(sExpr); 
      ExecuteQuery(ForwardOnly); 
      
      if (FirstRecord()) { 
        iRecord = 0; 
        for (var i=0; i %lt; afields.length; i++) {
          aValues[aFields[i]] = new Array();
          aValues[aFields[i]][iRecord] = GetFieldValue(aFields[i]);
        }
        while (NextRecord()) {
          iRecord++;
          for (var i=0; i < afields.length; i++) 
            aValues[aFields[i]][iRecord] = GetFieldValue(aFields[i]);
        }
      }
    }
    return(aValues)
  }
}
}();

This is in addition to the string prototype modifications discussed in earlier posts.

Escript Framework - lTrim & rTrim

I want to make sure I am making regular contributions to our open source eScript framework function library, so today's theme will be to continue with some tools for the string object not included in the standard escript string library. Last time I talked about lPad and rPad, so let's continue with their inverse, lTrim and rTrim. These are pretty basic concepts, present in VB and SQL, but the idea is simply to remove all spaces from either the front or back of a string. Metalink actually provides a couple of approaches to this, on based on regular expressions from Siebel 7.5 and earlier (before the replace function),

String.prototype.lTrim = function() {
var aReturn = this.split(/^\s*/);
return(aReturn.join(""));
}
String.prototype.rTrim = function() {
var aReturn = this.split(/\s*$/);
return(aReturn.join(""));
}

And here is a looping approach:

String.prototype.rTrim = function() {
var iCount = 0;
var iLength = this.length;
while ((iCount<iLength)&&(this.substring(iLength-iCount-1, iLength-iCount)==" ")) iCount++;
return(this.substring(0, iLength - iCount));
}
String.prototype.lTrim = function() {
var iCount = 0;
var iLength = this.length;
while ((iCount<iLength)&&(this.substring(iCount, iCount+1)==" ")) iCount++;
return(this.substring(iCount, iLength));
}

But if you are using Siebel 7.5 or later, using the replace function with regular expressions that find end of string anchored and beginning of string anchored white space, respectively, should be the best approach:

String.prototype.rTrim = function() {
//Use: String.rTrim()
//Returns string trimmed of any space characters at the end of it
return(this.replace(/\s*$/, ""));
}
String.prototype.lTrim = function() {
//Use: String.lTrim()
//Returns string trimmed of any space characters at the beginning of it
return(this.replace(/^\s*/, ""));
}

Escript Framework - lPad & rPad

So I have been following the discussion that started on Impossible Siebel 2.0: Introduction to the ABS Framework, which actually started earlier than that on other siebel blogs, to use the escript prototype feature to create a more robust siebel scripting framework. This got me pretty excited as I think it has a lot of potential for a lot of clients that use extensive script. Jason at Impossible Siebel is in the process of elaborating on defining this but I want to jump right in and start posting about some real world examples that could become part of an eventual library. For instance, since escript does not have an lpad or rpad function, I think those are pretty good starts. These are relevant to strings, so we need to modify the String prototype. Here is the script I came up with:

String.prototype.lPad = function(PadLength, PadChar) {
//Use: String.lPad(Number of Characters, Character to Pad)
//Returns: string with the PadChar appended to the left until the string is PadLength in length
return Array((PadLength + 1) - this.length).join(PadChar)+this;
}
String.prototype.rPad = function(PadLength, PadChar) {
//Use: String.rPad(Number of Characters, Character to Pad)
//Returns: string with the PadChar appended to the right until the string is PadLength in length
return this + Array((PadLength + 1) - this.length).join(PadChar);
}

Usage:
var s = "Short";
var r = s.rPad(10, "_"); // "Short_____"
var l = s.lPad(10, "_"); // "_____Short"

UPDATE: Thanks to commenter Jason who points out a more efficient algorithm. I have updated the original post.