How to troubleshoot formfill issues on Novell Access Manager's Linux Access Gateway

  • 7002780
  • 20-Mar-2009
  • 26-Apr-2012

Environment

Novell Access Manager 3.1 Linux Access Gateway
Novell Access Manager 3.1 Access Administration
Novell Access Manager 3.1 Linux Novell Identity Server

Situation

The goal of the following tips if to Access Manager Administrators with some details on formfill troubleshooting tips and tools

Common FormFill issues:

   1.     Make sure the 'Enable JavaScript Handling' flag is enabled if your application is using javascript. By default, formfill injects it's own javascript method to submit the form and all other javascript is not preserved.

   2.      For performance reasons, try and avoid enabling formfill policies on protected resources with wildcards. If wildcards are used, define the form Criteria to be as specific as possible (formname, cgi criteria or page matching criteria).

   3.      To avoid human error causing the form policy not to get triggered, always copy and paste the form criteria details into the formfill policy . This avoids any tipos that result in no matching profile found for the URL.

   4.     Make sure that the input type fields defined in the formfill policy match those included within the application HTML form.

   5.      Form Fill does not preserve the input for type="image". Check the <form> tag in the application login page to make sure that this type does not exist. If it does, try and modify it is possible. If not, it may be possible to use the custom rewriter can be used to substitute the required data although this is not recommended.

   6.      Check if the login page you are trying to single sign on to includes multiple <form> statements (see bottom of item 1. under Tools below). If this is the case, use the <formnum> tag in your formfill profile to POST the right credentials to that form. If the formname is unique, use this in the policy.

   7.      Make sure that the login page credentials match what formfill is configured to look for. The key entries are the name fields. The HTML forms follow the HTML specifications defined in     http://www.w3.org/TR/1998/REC-html40-19980424/interact/forms.html. For any queries regarding the login page, consult the HTML form specifications. The ics_dyn.log file on the Linux Access     Gateway (/var/log directory) will throw an alert in debug mode if the HTML form being parsed does not confirm to the specification.

    "Alert: SSO (Form Fill) Failed Due to Malformed HTML"

    If this occurs, check the <form> entry and make sure it is compliant with the above specs.

   8.      Make sure that the LDAP proxy user defined in the User store profile has enough rights to read and write attributes to the directory.

   9.     Make sure that the input field value selected includes the correct credential information. With the 'Shared Secrets' entries, the users can confirm their attributes by hitting the Identity Server portal page (https://<$idp_base_url>:8443/nidp) and looking at their shared secret profiles. Users can only view this shared secret information when the 'Allow End Users to See Credential Profile' option is enabled at the credential profile setting on the IDP server (Liberty -> Web Service Provider -> Credential profile option on IDP server)

   10.    Verify that the healthcheck settings on the IDP server and LAG are green. Novell secret store must be setup correctly (requires SSL) and if the trusted root has not been imported for example, the healthcheck will report a warning.

    11.    To avoid browser looping issues, make sure that you have a 'Login Failure' case to handle scenarios where the users credentials being auto posted by the LAG formfill module are invalid. If the application redirects the user back to the application login page when credendials submitted are incorrect, then formfill will keep sending the invalid credenatials over if we have auto submit enabled for the login page.


Common FormFill Tools:


   1.      Gathering traces using tcpdump. This tool prevents administrators from having to replicate a port on a switch to gather a LAN trace of traffic in and out of the Linux Access Gateway server. This trace may be saved and viewed with Ethereal. If the proxy or Web server uses the HTTPS scheme, the private key will be required to decrypt the HTTP requests and responses. Check out https://www.novell.com/coolsolutions/appnote/19321.html for more details on how to do this. tcpdump can be used to trace the traffic over the loopback interface, thus showing the data exchanged between the proxy and the service provider (TCP port 8080). This communication channel will show the SOAP requests and responses, including the values of the input fields.

   2.     Enable more verbose log levels at the Novell Identity Server (IDP) setup in the Admin Console. Go to the IDP Logging TAB and enable verbose settings for the Applicationa nd Liberty component levels. Also enable trace logging below that, but do NOT select any components. The resulting catalina.out log file with include details on the SOAP requests generated by formfill. These SOAP requests include the users sessionID (available by looking at the JSESSIONID cookie on the browser when user first accesses the /nesp link). Searching for the users JSESSIONID in the log files will show the request and response. Using Firefox LiveHTTPHeader plug ins on the browser for example, the following exchange at authentication time shows the setting of the JSESSIONID cookie (value is 3F9CE46785C940B3C987CABF515F1DD4):

GET /nesp/app/plogin?c=secure/name/password/uri&%22https: //lag129.lab.novell.com:443/%22 HTTP/1.1
Accept: image/gif, image/x-xbitmap, image/jpeg, image/pjpeg, application/x-shockwave-flash, application/x-ms-application, application/x-ms-xbap, application/vnd.ms-xpsdocument, application/xaml+xml, */*
Accept-Language: en-US,en-IE;q=0.5
UA-CPU: x86
Accept-Encoding: gzip, deflate
User-Agent: Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; .NET CLR 2.0.50727; .NET CLR 3.0.04506.648; .NET CLR 3.5.21022)
Cookie: IPCZQX03a36c6c0a=000000009302249389c1a0ca3a3d28bcd0a7a1a8
Connection: Keep-Alive
Host: lag129.lab.novell.com

HTTP/1.1 302 Moved Temporarily
Server: Apache-Coyote/1.1
Set-Cookie: JSESSIONID=3F9CE46785C940B3C987CABF515F1DD4; Path=/nesp
Location: https://idp126.lab.novell.com:8443/nidp/idff/sso?RequestID=idyvJD3IZ1ItUCfxl1xoe6L46tY0g&MajorVersion=1&MinorVersion=2&IssueInstant=2009-03-16T11%3A40%3A40Z&ProviderID=https%3A%2F%2Flag129.lab.novell.com%3A443%2Fnesp%2Fidff%2Fmetadata&RelayState=MA%3D%3D&consent=urn%3Aliberty%3Aconsent%3Aunavailable&ForceAuthn=false&IsPassive=false&NameIDPolicy=onetime&ProtocolProfile=http%3A%2F%2Fprojectliberty.org%2Fprofiles%2Fbrws-art&target=https%3A%2F%2Flag129.lab.novell.com%3A443%2F&AuthnContextStatementRef=secure%2Fname%2Fpassword%2Furi
Date: Mon, 16 Mar 2009 11:40:40 GMT
Content-Length: 0
        Via: 1.1 lag129.lab.novell.com (Access Gateway 3.1.0-425)

   
    Once we have identified the JSESSIONID for this user, we can search for this token in the catalina.out file. The corresponding 'GetAttrRequest' SOAP request to evaluate the formfill policy, and retrieve the attributes, will look as follows:

    <amLogEntry> 2009-03-16T12:20:49Z NIDS Trace: Method: BaseHandler.getSOAPDocument()
    Thread: http-127.0.0.1-8080-Processor23
    SOAP EndpointRequest
    <?xml version="1.0" encoding="UTF-8"?><SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/"><SOAP-EN
    V:Body><GetAttrRequest correlationId="4865" sessionId="4F9AFF8EAC3CECC1D1AA29B8A038421E" pId="y,6y3;3:n8SM7ez.q.HI3t2a[" stri
    ngify="true" fillFromCache="true"><Attribute id="NEPXurn~3Anovell~3Acredentialprofile~3A2005-03~2Fcp~3ASecrets~2Fcp~3ASecret
    ~2Fcp~3AEntry~40~40~40~40WSCQSSToken~40~40~40~40~2Fcp~3ASecrets~2Fcp~3ASecret~5Bcp~3AName~3D~22LDAPCredentials~22~5D~2Fcp~3A
    Entry~5Bcp~3AName~3D~22UserName~22~5D"/><Attribute id="NEPXurn~3Anovell~3Aldap~3A2006-02~2Fldap~3AUserAttribute~40~40~40~40W
    SCQLDAPToken~40~40~40~40~2FUserAttribute~5B~40ldap~3AtargetAttribute~3D~22title~22~5D"/><Attribute id="NEPXurn~3Anovell~3Acr
    edentialprofile~3A2005-03~2Fcp~3ASecrets~2Fcp~3ASecret~2Fcp~3AEntry~40~40~40~40WSCQSSToken~40~40~40~40~2Fcp~3ASecrets~2Fcp~3
    ASecret~5Bcp~3AName~3D~22LDAPCredentials~22~5D~2Fcp~3AEntry~5Bcp~3AName~3D~22UserPassword~22~5D"/></GetAttrRequest></SOAP-EN
    V:Body></SOAP-ENV:Envelope>
     </amLogEntry>

    Each SOAP request has a correlationID (4865 above). By tracing this correlationID, one can retrieve the SOAP response and verify it's status. In the above case, we can see

    <amLogEntry> 2009-03-16T12:20:50Z NIDS Trace: Method: BaseHandler.sendSOAPResponse()
    Thread: http-127.0.0.1-8080-Processor23
    SOAP EndpointResponse:
       <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">
          <SOAP-ENV:Body>
             <GetAttrResponse correlationId="4865">
                <Attribute format="0" id="NEPXurn~3Anovell~3Acredentialprofile~3A2005-03~2Fcp~3ASecrets~2Fcp~3ASecret~2Fcp~3AEnt
    ry~40~40~40~40WSCQSSToken~40~40~40~40~2Fcp~3ASecrets~2Fcp~3ASecret~5Bcp~3AName~3D~22LDAPCredentials~22~5D~2Fcp~3AEntry~5Bcp~
    3AName~3D~22UserName~22~5D" locationCookie="com.novell.nidp.liberty.wsc.WSCResourceOffering:fsd4jd6mu0s3e" maxCardinality="-
    1" minCardinality="0" status="OK" statusMessage="" syntax="3">
                   <StringValue>
                    XX
                   </StringValue>
                </Attribute>

   2.      Disable the Auto Submit option in the formfill policy. This allows the administrator to confirm whether the credentials were available via LDAP, or the store the credentials are being pulled from.     Assuming that this works, then one can be sure that LDAP has been setup correctly.

      If the formfill works without the auto submit option enabled, and fails with it enabled, then it is a good indicator that there may be some Java related problems. The LAG formfill injects the document.forms[0].submit() javascript code to have the browser auto submit the credentials LAG formfill passed back to the browser. If there is any other javascript methods defined in the login page, they will not get executed unless additional javascript related formfill tags are added.

      3.   The DebugMode formfill tag under the Submit options. When this tag is active and we hit the URL that matches what we have defined in our formfill policy, we will get following page before the credentials are sent by the browser.

At this page, one can select the browser option to View source (View -> Source). This displays the variable names and values that the LAG will inject into the login form. It is also very useful for checking the javascript methods sent back to the browser.

The example below shows the values that LAG  will inject for a form that requests the users name, password and domain fields. The appendix below includes both the formfill script and the application login page. Note the addition of the function LAGSubmitForm() to have the browser auto submit the credentials.


<html>
<HEAD>
<META http-equiv="Expires" Content="-1">
<META http-equiv="Cache-control" Content="no-cache">
<META http-equiv="Pragma" Content="no-cache">
</HEAD>
<body>
<b>Please look at HTML Source for Formfill modifications</b>
<SCRIPT LANGUAGE="JavaScript">
function setCookie(){
document.cookie="myCookieName=myCookieValue";
}
function validate(){
if(document.mylogin.title.ldap.length == 0){
alert("You must provide the title for the user you wish to login with!");
return false;
}
return true;
}
</SCRIPT><script language="JavaScript">
function setLDAPServer()
{
    mylogin.ldap.value = "CONSTANT_LDAP_SERVER";
}
</script><SCRIPT LANGUAGE="JavaScript">
function doCookie(){
document.cookie="myCookieName=myCookieValue";
}
return true;
}
</SCRIPT><form NAME="mylogin" ACTION="bootcamp.php" METHOD="post" ONLOAD="setCookie()"><input TYPE="hidden" NAME="username" SIZE="30" value="ncashell"><input TYPE="hidden" NAME="title" SIZE="30" value="Manager,Employee"><input TYPE="hidden" NAME="password" SIZE="30" value="novell"><input TYPE="hidden" NAME="ldap"><input TYPE="hidden" VALUE="Login" ONCLICK="setLDAPServer();"></form>
<script language="JavaScript">
<!--
function executeJavaScript()
{

}

function LAGSubmitForm()
{
executeJavaScript();
document.forms[0].submit();
}
//-->
</script>
<a href="JavaScript:LAGSubmitForm()">Click to submit</a>

</body>
</html>

   4. The ics_dyn.log file on the LAG can also be used to make sure that the formfill policy has been triggered by the protected resource. When we enable the debug setting on the LAG /etc/laglogs.conf file to be the following:

    LOG_LEVEL=7
    DEBUG_HTTP_HEADERS=0
    DEBUG_SOAP_MESSAGES=0

We can then check our protected resource to see whether the formfill policy has been triggered. In the example used above, the following protected resource URL had the formfill policy enabled (https://lag129.lab.novell.com/formfill/bootcamp.htm). Looking at the ics_dyn.log file for this particular URL, we can see the following key entries:

// Incoming request for the formfill enabled URL - validates cookie initially

Mar 16 12:38:25 lag129 : AM#504503000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#49: Process request 1 'lag129.lab.novell.com:443:/formfill/bootcamp.htm' [147.2.36.147:2592 -> 147.2.16.129:443]
Mar 16 12:38:25 lag129 : AM#504517000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#49: Search success for /formfill/bootcamp.htm  (0xa5f486e4:0xa5cdc664:64)
Mar 16 12:38:25 lag129 : AM#504504000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#49: protected-resource
Mar 16 12:38:25 lag129 : AM#504504000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#49: Got   valid Cookie[3971742362 0 2263957005 3300221945  147.2.36.147 0.0 CIP:147.2.36.147] COOKIE_VALIDATION
Mar 16 12:38:25 lag129 : AM#504504000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#B21D01404DB60267E816EC780DE54254: AMEVENTID#49: COOKIE_VALIDATION - Success
Mar 16 12:38:25 lag129 : AM#504504000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#B21D01404DB60267E816EC780DE54254: AMEVENTID#49: AuthServerRequestDS - handleRequestAfterEventProcessing with request state = 0, action = 0

// Formfill is enabled for this protected resource - process response from web server and make sure that the form criteria match what we have in the policy

Mar 16 12:38:25 lag129 : AM#504507000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#B21D01404DB60267E816EC780DE54254: AMEVENTID#49: Scheduling Formfill, policies matched 1
Mar 16 12:38:25 lag129 : AM#504503000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#49: Start Response to Browser 'cache_hit' [L4Health pending:0]
Mar 16 12:38:25 lag129 : AM#504507000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#B21D01404DB60267E816EC780DE54254: AMEVENTID#49: Content-Type () Formfill is interested in this response.
Mar 16 12:38:25 lag129 : AM#504507000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#B21D01404DB60267E816EC780DE54254: AMEVENTID#49: Processing response corresponding to url (https://lag129.lab.novell.com:443/formfill/bootcamp.htm)

// Form matches criteria specified in policy - need to retrieve the valued for the form fields by sending GetAttribute request to policy engine. The AMAUTHID is the JSESSIONID for the users session to the LAG ESP.

Mar 16 12:38:25 lag129 : AM#504507000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#B21D01404DB60267E816EC780DE54254: AMEVENTID#0: Sending a GetAttribute request to the eSP.
Mar 16 12:38:25 lag129 : AM#504515000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#0: Connection Established with peer 127.0.0.1:8080 (src 127.0.0.1:0)
Mar 16 12:38:25 lag129 : AM#504512000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#2844: sent soapRequest 2844  app a5dc5644  FF
Mar 16 12:38:25 lag129 : AM#504512000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#2844: backchannel receivedResp (app   a5dc5644  FF )   (2844)[seg:0xa5dc8e30:0xa59636c0:1545]
Mar 16 12:38:25 lag129 : AM#504507000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#0: Received a GetAttribute Response from eSP.

// After retrieving the values of the formfill input fields in the SOAP response, we need to inject these into the form and send back to the browser

Mar 16 12:38:25 lag129 : AM#504517000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#49: The content header before replace (      1199) new len (1363)(1363)
Mar 16 12:38:25 lag129 : AM#504517000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#49: FF replaceEntity with contents (1363)
Mar 16 12:38:25 lag129 : AM#504507000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#B21D01404DB60267E816EC780DE54254: AMEVENTID#49: Completed Formfill processing.(hit)
Mar 16 12:38:25 lag129 : AM#504517000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#49: The content length header is (      1363)
Mar 16 12:38:25 lag129 : AM#504520000: AMDEVICEID#ag-7AA324FFCBA4D4E: AMAUTHID#0: AMEVENTID#49: Browser req/resp[1765, 1765, 1765] [timeToResp:0 respDuration:0]     curTime:1765 FinishTransmit [auth:0 acl:0 II:0] [rewrite 0 :0 0 0] [origin: 0, 0, 0,0 retry:0 0]


Note too that, should any syntax issue exist with the app login page, the alert will also be thrown in this file.