Troubleshooting XML Validation in Access Manager

Novell Cool Solutions: Feature
By Neil Cashell

Digg This - Slashdot This

Posted: 15 Aug 2007


Whenever an XML validation occurs, it is often ignored because the message coming back does not appear to be too serious! However, if you look more closely at the configuration on the Linux Access Gateway (LAG), you will notice that none of the changes have been applied. When a change is applied via the UI, the configuration is written to both the configuration store on the Administration Server, as well as the /var/novell/cfgdb/vcdn/config.xml file. If this file passes the various schema checks on the LAG, the /var/novell/cfgdb/.current/config.xml file will be updated with the configuration. This is the file that the LAG reads when it loads or refreshes. If the config.xml file from /var/novell/cfgdb/vcdn/ and /var/novell/cfgdb/.current are not in sync, then all changes defined by the Administrator have NOT been applied to the LAG.

The goal of this article is to make administrators aware of the importance of the XML validation errors and to identify key steps required to solve such problems. There are two main scenarios that we will cover: one where the problem can be fixed by "touching" an existing configuration via the UI, and another where we will have to manually edit the configuration store before pushing changes back out to the devices.

Scenario 1 - Configuration referencing an object that has been removed

For example, a custom contract was created and assigned to a protected resource. The contract was then manually deleted from the IDP configuration, and the Access Gateway protected resources still reference it - even though it is NOT visible in the GUI. Once we can identify the missing link, we should be able to use the Access Manager UI to work around the problem.

Troubleshooting, Step 1

1. Search the /opt/novell/devman/share/logs/app_sc.0.log file on the Administration Server for the "#200904025: Error - XML VALIDATION FAILED" string.

2. Once you find the entry, work backwards to identify the start of the Java exception.

3. From this, locate the problem strings or entry from the configuration (e.g., 'authprocedure_NEIL___Name_Password___Form' below).

----- snippet from problem area of app_sc.0.log file ------

871(D)Wed May 23 15:45:06 BST 2007(L)webui.sc(T)26(C)com.volera.vcdn.webui.sc.di
spatcher.ConfigWorkDispatcher(M)A(E)org.jdom.input.JDOMParseException: Error on
line 1120: cvc-id.1: There is no ID/IDREF binding for IDREF 'authprocedure_NEIL_
        at org.jdom.input.SAXBuilder.build(SAXBuilder.java:468)
        at org.jdom.input.SAXBuilder.build(SAXBuilder.java:770)
        at com.volera.vcdn.platform.util.XmlUtil.validateXML(y:3304)
        at com.volera.vcdn.webui.sc.dispatcher.ConfigWorkDispatcher.A(y:793)
        at com.volera.vcdn.webui.sc.dispatcher.ConfigWorkDispatcher.do_deviceCon
        at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java
        at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.proce
        at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java
        at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadP
        at java.lang.Thread.run(Thread.java:534)
(Msg)<amLogEntry> 2007-05-23T15:45:06Z ERROR DeviceManager: AM#200904025: Error

----- end of snippet from problem area of app_sc.0.log file ------

Troubleshooting, Step 2

With the info regarding the problem identified from Step 1 above, the next step involves looking at the Linux Access Gateway (LAG) configuration.

1. On the LAG, cd to /var/novell/cfgdb/vcdn and open the config.xml file.

2. Search for the problem string and the corresponding protected resource.

The example below shows that the problem string is tied to the "ProtectedResourceID_svhttp_mylag_iMon_root" resource. This maps to the http reverse proxy called 'mylag', the service called 'iMon' and the protected resource 'root'.

Looking at the AuthenticationProcedureRef variable, which points to the contract assigned to the protected resource, you can see that the 'authprocedure_NEIL___Name_Password___Form' contract is assigned to it. Yet, when you look at the LAG configuration in iManager, you can see that the assigned contract is '[None]' and NOT the contract below! Changing it to another contract name, applying the change, and then setting the contract back to '[None]' clears the problem entry and gets the setup going again with no XML validation errors.

It turns out that there had, at one stage, been a custom contract assigned to that protected resource. This custom contract had been removed from the IDP server list of Contracts and the cleanup was never done properly at the LAG.

----- snippet from problem area of config.xml ------

<ProtectedResource Name="root" Enable="1" Description="" LastModified="116973455
5995" LastModifiedBy="cn=admin,o=novell" UserInterfaceID="ProtectedResourceID_sv
http_mylag_iMon_root" ProtectedResourceID="ProtectedResourceID_svhttp_mylag_iMon

        <URLPathList LastModified="4294967295" LastModifiedBy="String">

                <URLPath URLPath="/*" UserInterfaceID="/*"/>


        <PolicyEnforcementList LastModified="1168947602067" schemaVersion="1.34"
 LastModifiedBy="cn=admin,o=novell" RuleCombiningAlgorithm="DenyOverridesWithPri

                <PolicyRef ElementRefType="ExternalWithIDRef" ExternalDocRef="ou
Doc" UserInterfaceID="PolicyID_xpemlPEP_AGFormFill_1168947167634" ExternalElemen


        <AuthenticationProcedureRef AuthProcedureIDRef="authprocedure_NEIL___Nam

----- end of snippet from problem area of config.xml ------

Scenario 2 - Configuration UI writes out incorrect information to the local config store

For example, the administrator applies the same change twice in quick succession (double- apply), and the information written to the config store is invalid. Subsequent schema checks detect this invalid configuration, and an XML validation error is returned. This scenario is more complex, as it involves making changes to the configuration store on the Administration server.

Troubleshooting, Step 1

1. Search the /opt/novell/devman/share/logs/app_sc.0.log file on the Administration Server for the "#200904025: Error - XML VALIDATION FAILED" string.

2. Once you find the entry, work backwards to identify the start of the Java exception.

3. From this, locate the problem strings or entry from the configuration (e.g., "ProtectedResourceID_svhttp_sjh_portal_sjh_portal_1179933619340").

This message also hints at the fact that a defined protected resource may not be unique. The configuration shows before the Java exception doesn't give enough info to narrow down the problem, so more troubleshooting will be required.

----- snippet from problem area of app_sc.0.log file ------

Caused by: org.xml.sax.SAXParseException: cvc-id.2: 
There are multiple occurrences of ID value 'ProtectedResourceID_svhttp_sjh_portal_sjh_portal_1179933619340'.
	at org.apache.xerces.util.ErrorHandlerWrapper.createSAXParseException(Unknown Source)
	at org.apache.xerces.util.ErrorHandlerWrapper.error(Unknown Source)
	at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source)
	at org.apache.xerces.parsers.XMLParser.parse(Unknown Source)
	at org.apache.xerces.parsers.AbstractSAXParser.parse(Unknown Source)
	at org.jdom.input.SAXBuilder.build(SAXBuilder.java:453)
	at org.jdom.input.SAXBuilder.build(SAXBuilder.java:770)
	at com.volera.vcdn.platform.util.XmlUtil.validateXML(y:3304)
	at com.volera.vcdn.webui.sc.dispatcher.ConfigWorkDispatcher.A(y:793)
	at com.volera.vcdn.webui.sc.dispatcher.ConfigWorkDispatcher.do_deviceConfig(y:648)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:324)
	at com.volera.vcdn.webui.sc.dispatcher.DefaultDispatcher.invoke(y:469)
	at com.volera.vcdn.webui.sc.dispatcher.DefaultDispatcher.processRequest(y:1732)
	at com.volera.roma.app.handler.DispatcherHandler.processRequest(y:3168)
	at com.volera.roma.servlet.GenericController.doPost(y:53)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:716)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:809)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:200)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:146)
	at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:594)
	at com.novell.accessmanager.tomcat.SynchronizationValve.invoke(y:297)
	at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:433)
	at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:948)
	at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:152)
	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:705)
	at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
	at java.lang.Thread.run(Thread.java:534)
(Msg)<amLogEntry> 2007-05-23T13:22:15Z ERROR DeviceManager: AM#200904025: Error - XML VALIDATION FAILED. 
----- end of snippet from problem area of app_sc.0.log file ------

Troubleshooting, Step 2

Confirm that the change has not been applied at the LAG. To do this, the following steps must be executed:

1. Enable most verbose level of debugging in /etc/laglogs.conf (LOG_LEVEL=7).

2. Restart vmc services.

3. Search for 'in-memory' errors in ics_dyn log file. When these errors are displayed, then the working LAG configuration will NOT be updated with the latest changes!

4. Identify the protected resource with these issues. In the case below, the protected resource is the same so we need to look at the config.xml file and search for this specific protected resource.

May 23 13:22:14 chw-amtlag1-176 : 404502  0: 7168: 0: 0: VcpConfiguration::reconfigure starting AafLog  
May 23 13:22:14 chw-amtlag1-176 : 404502  0: 7168: 0: 0: VcpConfiguration::reconfigure finished  
Error at file "in-memory", line 328, column 306
   Message: Datatype error: Type:InvalidDatatypeValueException, 
Message:ID 'ProtectedResourceID_svhttp_sjh_portal_sjh_portal_1179933619340' is not unique .
ERROR: Error retrieving config.xml: No data available

Troubleshooting, Step 3

1. Search the config.xml file for the above string in /var/novell/cfgdb/vcdn directory. Doing this, you get two hits:

      <ProtectedResource Name="sjh_redirect" Enable="1" Description="" LastModified="1179934022767"
    <URLPathList LastModified="4294967295"
      <URLPath URLPath="/*"
LastModified="1179934011081" schemaVersion="0.1"


<ProtectedResourceList LastModified="1179949051828" 
  <ProtectedResource Name="sjh_redirect" Enable="1"
Description="" LastModified="1179949051828"
    <URLPathList LastModified="4294967295"
      <URLPath URLPath="/*"
LastModified="1179949047445" schemaVersion="0.1"

This is the duplicate entry that was causing the problem - you need to clear one of the entries from the configuration. If you clear it from the /var/novell/cfgdb/vcdn/config.xml file, then any change applied in the UI will rewrite the info to the config.xml file. The real solution is to remove the duplicate entry from the configuration store on the Administration Server.

Troubleshooting, Step 4

Remove the duplicate entry from the Administration Server. To do this, we will need an LDAP browser and run the following steps:

1. Get an LDAP browser (I downloaded the java based tool from http://www-unix.mcs.anl.gov/~gawor/ldap/).

2. Log in to the Administration Console LDAP server. It must be a secure LDAP session!

3. Browse to AccessManagerContainer: VCDN_Root > PartitionsContainer > Partitions > AppliancesContainer.

Figure 1 - Browsing the Appliances Container

4. Locate the ag-xxxx that matches the LAG you are having problems with. The easiest way of doing this is to go to the Auditing > General Logging tab of the Access Manager Administration Console and identifying your LAG ID from there (12AA below). This ID corresponds to the first 4 digits of the ag-xxxx in the LDAP browser.

Figure 2 - Finding the problem LAG

5. Go into the ag-xxxx container. You should see CurrentConfig and WorkingConfig containers within this ag container.

Figure 3 - Browsing to the CurrentConfig container

6. Select the CurrentConfig > RomaAGConfigurationXMLDoc attribute and cut and paste the attribute value into any editor ... this is the config from the LAG!

Figure 4 - Editing the RomaAGConfigurationXMLDoc attribute

7. Search for the above string and remove the entire section on one of the hits, starting with <ProtectedResourceList> and ending with </ProtectedResourceList>.

8. Select and save the modified text.

9. Paste the saved text back into the RomaAGConfigurationXMLDoc attribute value.

10. Do the same for the WorkingConfig > RomaAGConfigurationXMLDoc attribute - remove the duplicate entry that is causing the XML validation errors.

11. Restart Tomcat on the Admin Console.

12. Log in to the Admin Console again.

13. Make any small change to the setup and apply that change, then confirm that the XML validation error has disappeared.

Novell Cool Solutions (corporate web communities) are produced by WebWise Solutions. www.webwiseone.com

© Micro Focus