Tuesday, March 8, 2016

Thick Client Event Logging

There are surprisingly few blog posts out there about vanilla options for logging in the thick client.  Perhaps this is because everyone knows how to do it and if so feel free to ignore this.  But perhaps it is because most people just struggle through using inefficient methodologies.

Here is a simple tip for troubleshooting when using the thick client.  There is an OS environment variable called SIEBEL_LOG_EVENTS (if it does not exist you can create it). Many developers know how to set this to an integer between 0 and 5, but values of 4 and 5 where good detail is provided create a file that unreasonably large and hard to parse.  When troubleshooting on the thin client you can set individual event log levels from the Administration - Server Configuration screen, component events view.  You can do the same when using a thick client though you need to do it using the SIEBEL_LOG_EVENTS variable.  You can use any combination of event aliases and levels, but the value I have found useful is the following:
StpExec=4,PrcExec=4,ObjMgrSqlLog=4,SQLParseAndExecute=4,ObjMgrBusServiceLog=4,EventContext=4,ProcessRequest=4,ObjMgrDBConnLog=5,SecAdpLog=5,ObjMgrSessionLog=5,ObjMgrBusCompLog=2
Basically you can enter any comma separated list of event aliases.

One coda is that if I were trying to troubleshoot a WF issue, I could open this log and do a find for the word 'Instantiating'.  The first instance I would find is the Start step of the WF Process followed by the values of the process properties being set by that step:
PrcExec Create 4 00000002569f1a98:0 2016-01-20 15:31:33 Instantiating process definition 'PPT Passport History Response Integration'.
PrcExec PropSet 4 00000002569f1a98:0 2016-01-20 15:31:33 Setting runtime value of property 'Namespace: 'USER' Name: 'ConfigItem' Datatype: 'String'' to:
PrcExec PropSet 4 00000002569f1a98:0 2016-01-20 15:31:33 Start
PrcExec PropSet 4 00000002569f1a98:0 2016-01-20 15:31:33 Setting runtime value of property 'Namespace: 'USER' Name: 'ObjectName' Datatype: 'String'' to:
PrcExec PropSet 4 00000002569f1a98:0 2016-01-20 15:31:33 Workflow - PPT Test Error Process
PrcExec PropSet 4 00000002569f1a98:0 2016-01-20 15:31:33 Setting runtime value of property 'Namespace: 'USER' Name: 'CurrentStep' Datatype: 'String'' to:
PrcExec PropSet 4 00000002569f1a98:0 2016-01-20 15:31:33 Convert Siebel Message PPH
Subsequent occurrences look like this:
StpExec Create 4 00000002569f1a98:0 2016-01-20 15:31:33 Instantiating step definition 'Start'.
StpExec End 4 00000002569f1a98:0 2016-01-20 15:31:33 Stopping step instance of 'Start' with a 'Completed' status.
In this way you can step through the WF.  The advantage of this logging level over say looking at the WF Instance Monitor or only using WF Simulator, is you will be able to see the SQL executed and the bind variables used, what BCs were instantiated along the way, and what BS methods might have been called.

Tuesday, February 9, 2016

EAI Integration Map expressions

While there are many posts I have seen that talk about expressions supported by 'EAI Data Transformation Engine', I have never seen an attempt to compile a list of supported functions and examples of there uses.  So this will be a humble beginning that will hopefully grow over time.  Note that these functions are mostly VB so if trying out one that is not listed, start with what is supported in VB.  They can also be found in Siebel Bookshelf as Siebel Query Language expressions

Transforming Dates (from 'YYYYMMDD' to 'MM/DD/YYYY'):
Right(Left([Source Field Name],7),2) +"/"+Right([Source Field Name], 2)+"/"+Left([Source Field Name], 4)

Conditional Logic:
IIF([Source Field Name] = "false", "N", "Y")

EAI Lookup for an Inbound Interface:

  • EAILookupSiebel("XXX",[Source Field Name])
    • XXX is the Type in the EAI Lookup table.  This needs also needs to be setup as a value under the EAI_LOOKUP_MAP_TYPE LOV type.
  • IIF([Source Field Name] IS NULL, "", EAILookupSiebel("XXX",[Source Field Name]))
    • EAILookupSiebel fails if no value is found so minimize this possibility unless an exception is desired


Extract the file name from a File Path:
Mid([Source Field Name], InStr([Source Field Name], "/", -1) + 1)

Thursday, October 22, 2015

Interesting Web Service approach

I was recently working on a client where all the integration used HTTP Web Services but were not implemented using what I think most Siebel Developers would think of as the "Best Practice".  Basically, the payloads were created using XSLT and the actual call to the Web Service was invoked using 'EAI HTTP Transport' rather than a custom WS Proxy BS created using the Tools wizard. 

The reasoning provided to me behind using XSLT to create the payload is that it was more flexible.  What do I mean by that?  Well assume an outbound interface is needed where the "Best Practice" alternative would be to use 'EAI Siebel Adapter' to query an Integration Objects , then to use 'EAI Data Transformation Engine' to transform the payload into an IO (that was initially created by consuming a WSDL) recognizable by the Web Service.  The limitation in this approach is around a couple pieces that Siebel Tools wizards have trouble with.  The first is that some modern standards compliant  WSDL definitions that use recursive data types cannot be imported at all.  The second is that the SOAP Header follows a standard that is somewhat outdated, is not configurable, and basically requires scripting to create a custom header anyway.  So the question is whether it is better to create the custom header using a scripted Filter Service, or to create the payload using XSLT.  Once you go down the path of using XSLT, you basically cant use a Proxy Service anymore (since the proxy would be adding the SOAP envelope) so 'EAI HTTP Transport' is used instead.

I can think of a number of downsides to this approach:
  • Deployment Complexity increases
    • XSLT files must be deployed to the File System and kept in sync across however many app servers (and failover servers) are used by EAI in the respective environments
    • No WSDL is actually consumed in this approach so web service end points must be stored somewhere which will likely be different in each environment
  • More Steps in the WF
    • 'EAI XSLT Service'  uses UTF-16 input so it is likely Encoding will need to occur both to and from using 'Transcode Service'
    • Reading the XSL File from the file system
  • Mainainability
    • Siebel resources that know XSLT are presumably more rare than Siebel resources familiar with more "Best Practice" approaches
  • Performance
    • Calls to the File System to get the XSLT file might add significant load to a high volume interface
  • Data Integrity
    • The integrity of the outbound message data structure is not really enforceable in Siebel. Using XSLT requires the developer to create a payload that is correct as only the external system would be able to validate it.  This is perhaps debateable because ultimately the developer will probably need to resolve this one way or the other during development.  While I personally believe it is easier to troubleshoot problems that are actually identified within Siebel due to the strict defintion of the messages maintained in Siebel, I will concede that might be personal preference.
I am curious what others think and whether developers that use this approach can defend it better than I can.  Ultimately, I think a scripted filter service is a better solution to the custom Soap Header issue, though I think this approach seems reasonable if the WSDL cannot be consumed, and modifying it is not possible.

Scriptless OK/Cancel popup

In the early days of configuring in Siebel, if a user wanted a confirmation or warning message before proceeding, it would require Browser Script to implement and most Siebel configurators would try to discourage the requirement on purely technical grounds.  And to be fair, an application littered with popup warnings may not be a great idea on functional grounds either, but there are probably good reasons to implement a warning message on occasion and it would be nice if it could be done in a way that does not have technical repercussions.  So here you go.

On a BC, configure a 'Named Method' user property with value:
"YourMethodName", "INVOKESVC", "FDNS IDENT Encounter", "LS Pharma Signature UI Service", "ShowConfirmDialog", "'Cancel Method Name'", "YourCancelMethodName", "'OK Method Name'", "YourOKMethodName", "'Confirm Text'", "'Are you sure you want to Proceed or some other message?'"

The method 'YourMethodName' would be invoked according to your requirements.  In a simple case, a custom action button on an applet could invoke this method but it could really be invoked anywhere.

The methods 'YourOKMethodName' and 'YourCancelMethodName' need to be callable methods, either that you also configured as additional Named Methods, or vanilla methods (or scripted ones defined in PreInvoke but that would sort of defeat the point). 

When 'YourMethodName' is invoked, a popup message containing the message parameter is shown with an Ok and Cancel button.  Clicking either button calls the methods defined.  Enjoy

Vanilla Merge Behavior

I recently encountered an issue when adding a DB View based EBC to a BO.  When I attempted to perform a MergeRecords operation on two records in the primary BC (Contact in this case), I got an error:

[1] An error has occurred writing to a record
Please continue or ask your system administrator to check your application configuration if the problem persists.(SBL-DBC-00111)
[2]ORA-06550: line 137, column 15:
PL/SQL: ORA-01031: insufficient privleges
ORA-06550: line 137, column 1:
PL/SQL: SQL Statement ignored

It turns out this error is caused because siebel is attempting to update a column in a DB View.  Why would it try to do that you might ask?

If we reverse engineer what is happening, we find that when performing a MergeRecords operation, Siebel determines the underlying table of the active business component and uses the SRF to find all links where the identified table is shared with the source business component of the Link and the source field is ‘Id’ (or null which is the same thing).  The merge algorithm then takes this list to write the SQL to update the appropriate destination field to the new value of the Id field on the Source BC.  Since merge is a data integrity operation, the use of Links using the ‘Id’ field is a proxy for those links configured to have a data integrity implication. 

Ideally, Siebel would provide a configurable mechanism to exclude a particular link from a Merge, or, at a minimum, to recognize that when a link points to a destination BC that is based on a table object whose type is ‘External View’, no update is possible and hence should not be attempted.  Alas that is not the case. 

Therefore a way to trick the algorithm into excluding this link is to define the link on one which is not based on data integrity, and instead make it just informational.  This can be done by making the Source field of the link something other than Id.  But since we do not want to actually change the definition of the view this link points to, a column whose value matches the ROW_ID column is desireable.  In the case of the Contact BC, there are a couple of potential options.  PERSON_UID defaults to the Id field but since this column might be populated by EIM to be a value other than it’s ultimate row id, the values may not match on that data set.  But since Contact is based on the Party model, the PAR_ROW_ID should always match since this points to the S_PARTY record and the same ROW_ID is always used. This column is not exposed on the Contact BC though so it needs to first be exposed and then the new BC field can be used in the links.

Friday, May 10, 2013

The XML Logger - Revieing 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 blck 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("CMI Utilities", "ConcatenateField", "bo.bc='CMI User Session.CMI User Session XML Detail', FieldName='Log Text', SearchExpr='[Parent Id]=""+[Id]+"" AND [Field]="Request"'", "Out")
where:
  • 'CMI 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
  • 'CMI User Session' is the name of the business object where my user sessions are stored
  • 'CMI 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 'CMI 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;
 }
}

Tuesday, May 7, 2013

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.

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 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) {
/* ***********************************
Created by Mik Branchaud on 09/20/11
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 'CMI Utilities'
  and the method to logRequest.  Clear the cache
Arguments: 1 - SoapMessage will implicily be passed as a child property set
**************************************** */
try {
    logStack("logRequest", 5);
    var soapEnv, soapBody, divePS;
    var bodyType="";
    var msgType="";
    var parseResults = new Object();
    var key = TheApplication().Utility.TimeStamp();
    var max = 3;
    var dives = 0;
    
    if(Inputs.GetChildCount() > 0) {
  try { // Try to process the message to get functional data 
         // Get the SOAP envelope from the SOAP hierarchy
         soapEnv = Inputs.GetChild(0);        //Like env:Envelope
         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 
                  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
  
    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 (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 (msgType != "") {
         msgType = msgType.replace(/_spc/g, "");
         key = msgType+"_"+key;
        }
        TheApplication().SetProfileAttr("InterfaceKeyInbound", key)
        logInterface(key, soapEnv, null, null, parseResults.recId, parseResults.recBC, "Pending", msgType, null, null, null, null, parseResults.ref1);
    } // Inputs.GetChildCount()
    Outputs.InsertChildAt(soapEnv,0);
} catch(e) {
    RaiseError(e);
} finally {
 divePS = null;
 soapBody = null;
 soapEnv = null;
 parseResults =  null;
 logUnstack(msgType, 5);
}
}

function logResponse(Inputs,Outputs) {
/* ***********************************
Created by Mik Branchaud on 09/20/11
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 'CMI Utilities'
  and the method to logResponse.  Clear the cache
Arguments: 1 - SoapMessage will implicily be passed as a child property set
**************************************** */
try {
    logStack("logResponse", 5);
//TheApplication().TraceOn("/opt/siebel81/siebsrvr/enterprises/SBA_81/edad669/log/XTrace-Resp-"+TheApplication().LoginName()+".log", "Allocation", "All");
    var soapEnv, soapBody, divePS;
    var bodyType="";
    var msgType="";
    var parseResults = new Object();
    var fault=null;
    var key = TheApplication().GetProfileAttr("InterfaceKeyInbound");
    var max = 3;
    var dives = 0;

    if(Inputs.GetChildCount() > 0) {
  try { // Try to process the message to get functional data
         // Get the SOAP envelope from the SOAP hierarchy
         soapEnv = Inputs.GetChild(0);
         logVars("soapEnv Child Count", soapEnv.GetChildCount(), 5);
         for (var i=0; i < soapEnv.GetChildCount(); i++) {
             bodyType = soapEnv.GetChild(i).GetType();
             logVars("soapEnv Child Type", bodyType, 5);
             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();
                  logVars("Body Child Type", msgType, 5);
                  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 {
       divePS = soapBody.GetChild(j);
       while (divePS.GetType().indexOf("ListOf") < 0 && dives <= max) {
                    logVars("Current Dive Type", divePS.GetType(), 5);
        if (divePS.GetChildCount() > 0) {
         divePS = divePS.GetChild(0);
         dives++;
        } else dives = max + 1;
       }
 
       if (divePS.GetType().indexOf("ListOf") >= 0) parseInterface(divePS, parseResults);
                  }
     }
                 break;
             }
         }
  } catch(e) {
   //If an error occurs while parsing, just try to write the message whole
  }
        
        logVars("key", key, "Fault", fault, 5);
        if (key == "") {
            key = TheApplication().Utility.TimeStamp();
         if (msgType != "") {
          msgType = msgType.replace(/_spc/g, "");
          key = msgType+"_"+key;
         }
        }
        
        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);
            logInterface(key, null, soapEnv, null, recId, recBC, "Complete", msgType, null, null, null, null, ref1);
        }
    } // Inputs.GetChildCount()
    Outputs.InsertChildAt(soapEnv,0);
} catch(e) {
    RaiseError(e);
} finally {
 divePS = null;
 soapBody = null;
 soapEnv = null;
 parseResults =  null;
    logUnstack(msgType, 5);
}
}

The parseInterface method passes the ListOf container of the Integration Object to a switch statement where each BC type can be evaluated.  This 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.
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 {
     logStack("parseInterface", 5);
  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);
   }
   logVars("Integration Component", intCompType, "Namespace", icNameSpace, 5);

   //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);
     }
     logVars("Integration Component", intCompType, "Namespace", icNameSpace, 5);
        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:
      logVars("Integration Component", intCompType, "Default", icNameSpace+"Id", 4);
      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;
     logUnstack("", 5);
 }
}

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(key, request, response, dir, recId, recBC, status, srcObject, name, logText, userText, retCode, ref1, ref2, ref3)
{
try {
 logStack("logInterface", 5);
 logVars("key", key, "Record Id", recId, "Record BC", recBC, "Global Session Row Id", gSessionId, "Hold Buffer", gHoldBuffer, "Guest Login", gsGuest, 5);
 
 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("CMI User Session");
 var bcSession:BusComp;

 if (gHoldBuffer) {
  //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 if (gsTraceIntfaceReqResp == "TRUE" && key != "") {
  //If an interface is being logged for the first time, need to instantiate the session
  if (gSessionId == "") {
   //If Guest connections are not used, a simplified session management can be used 
   if (gsGuest == "" && key != "") {
    bcSession = boSession.GetBusComp("CMI 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 {
    createSession = true;
 
    //confirm that current session has not been created yet
    bcSession = boSession.GetBusComp("CMI User Session");
    with (bcSession) {
     ClearToQuery();
     SetSearchSpec("Session Stamp", gsLogSession);
     ExecuteQuery(ForwardOnly);
     found = FirstRecord();
  
     if (found == true) {
      gSessionId = GetFieldValue("Id");
      createSession = false;
     } else {
      firstMessage = true;
     }
    }
   }
  }

  logVars("CreateSession", createSession, "useGuestSession", useGuestSession, "First Message", firstMessage, 5);
  if (createSession == true || useGuestSession == true) {
   bcSession = boSession.GetBusComp("CMI 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) {
    boSessionFlat = TheApplication().GetBusObject("CMI User Session Flat");
    bcSessionXMLFlat = boSessionFlat.GetBusComp("CMI User Session XML");
    bcSessionXMLFlat.ActivateField("Parent Id");
    bcSessionXMLFlat.ClearToQuery();
    if (typeof(srcObject) != "undefined" && srcObject != null) bcSessionXMLFlat.SetSearchSpec("Source Object", srcObject);
    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");
   }
   
   logVars("guestSessionFound", guestSessionFound, 5);
   if (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");
     logVars("New Global Session Row Id", gSessionId, 5);
    }
   } else if (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) {
    //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 {
    //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("CMI User Session XML");
  var bcSessionXMLDtl = boSession.GetBusComp("CMI User Session XML Detail");

  with (bcSessionXML) {
   if (firstMessage) {
   //This is an insert so no query needed to update an existing record
    found = false;
   } else if (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();
   } else {
   //This is a normal response update to an existing message record
    ClearToQuery();
    SetSearchSpec("Parent Id", gSessionId);
    SetSearchSpec("Name", key);
    SetSortSpec("");
    ExecuteQuery(ForwardBackward);
    found = FirstRecord();
   }
   
   if (found == false) {
    NewRecord(NewBefore);
    SetFieldValue("Name",key);
    SetFieldValue("Parent Id",gSessionId);
    logVars("XML Record Id", GetFieldValue("Id"), 5);
   }
   
   if (useGuestSession == true)         SetFieldValue("Name", key.substring(0, 100));

   if (typeof(request) != "undefined" && request != null) {
    SetFieldValue("Request Time", TimeStamp("DateTimeFormatted"));
    splitPayload(bcSessionXMLDtl, "Request", request, 131072)
   }
   if (typeof(response) != "undefined" && response != null) {
    SetFieldValue("Response Time", TimeStamp("DateTimeFormatted"));
    splitPayload(bcSessionXMLDtl, "Response", response, 131072)
   }
 
//   if (typeof(request) != "undefined" && request != null)  trimPS(request, "Request", bcSessionXML, 131072);
//   if (typeof(response) != "undefined" && response != null) trimPS(response, "Response", bcSessionXML, 131072);
   if (typeof(dir) != "undefined" && dir != null)    SetFieldValue("Direction", dir.substring(0, 30));
   if (typeof(recId) != "undefined" && recId != null)   SetFieldValue("Record Id", recId.substring(0, 15));
   if (typeof(recBC) != "undefined" && recBC != null)   SetFieldValue("Record BC", recBC.substring(0, 50));
   if (typeof(status) != "undefined" && status != null)  SetFieldValue("Status", status.substring(0, 30));
   if (typeof(srcObject) != "undefined" && srcObject != null) SetFieldValue("Source Object", srcObject.substring(0, 50));
   if (typeof(name) != "undefined" && name != null)   SetFieldValue("Functional Name", name.substring(0, 50));
   if (typeof(logText) != "undefined" && logText != null)  SetFieldValue("Log Text", logText.substring(0, 131072));
   if (typeof(userText) != "undefined" && userText != null) SetFieldValue("User Text", userText.substring(0, 255));
   if (typeof(retCode) != "undefined" && retCode != null)  SetFieldValue("Return Code", retCode.substring(0, 30));
   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));

   WriteRecord();
  }
  if (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);
} finally {
 bcSessionXML = null;
 bcSessionXMLFlat = null;
 boSessionFlat = null;
 bcSession = null;
 boSession = null;
    logUnstack("", 5);
}

}

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 tripPS 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(bc, fieldName, ps, maxLength) {
 try {
  logStack("splitPayload", 5);
  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);

  logVars(fieldName+" textPS.length", textPS.length);
  while (textPS.length > 0) {
   bc.NewRecord(NewAfter);
   bc.SetFieldValue("Field", fieldName);
   bc.SetFieldValue("Log Text", textPS.substring(0, maxLength));

   //Service adds a Prefix that needs to be removed
   text = bc.GetFieldValue("Log Text");
   text = text.lTrim();
   if (text.substring(0, 14) == "PropertySet [ ") {
    stripPS = true;
    text = text.substring(14);
   }

   textPS = textPS.substring(maxLength, textPS.length); 
   logVars(fieldName+" textPS.length", 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("]");
   }
   bc.SetFieldValue("Log Text",text);
   bc.WriteRecord();
  }
 } catch (e) {
  throw(e);
 } finally { 
  psOut = null;
  psIn = null;
  bsService = null;
     logUnstack("", 5);
 }
}

Next: Viewing the Payload