Error Codes for Identity Governance - Part 3

As is my habit, I like to collect errors I see go by into a file, and when I get enough of them, write about them. This I have been told is very helpful, since the documentation rarely documents error messages in this fashion and thus a Google search of the specific error message only ever turns up an article I might have written.

I have done this for many different drivers (Active Directory, JDBC, SOAP, SAP HR, eDir) and have lots more snippets I still need to turn into articles. If you happen to have any good ones, as always feel free to write your own article. It will no doubt help someone along the way.

This is the third in my series on Identity Governance. I started with IDG 3.0 and 3.01 and have since progressed to using 3.5.1 which is very similar, just with new features and of course all sorts of new errors. Some of these will likely apply back to 3.0.x but some may be only 3.5.x and I am not sure I can tell which those would be. The joys of figuring it all out on your own. In general the changes between the two applications are not quite clear in error messages.

The first two articles in this particular series are:

/cyberres/idgovernance/w/identity_gov_tips/3660/error-codes-for-identity-governance---part-1
/cyberres/idgovernance/w/identity_gov_tips/4822/error-codes-for-identity-governance---part-2

Some of these error messages are fairly repetitive and long, since they include Java error stacks, but I specifically want to leave those in, since sometimes you get a portion of the stack, and not the exact same complete stack or exact error I got, but the complete stack shows you something pretty close. Or else someone reports a problem and you do not get the entire stack, and get expected to troubleshoot the problem with one hand tied behind your back.

Database Goes Down:

This one was interesting, and was from 3.01. We were running along and suddenly we started getting errors in the logs.

[SEVERE] 2018-07-25 03:27:02 com.netiq.iac.server.dtp.DPMediatorService$ClaimableMediatorTask anyUnclaimedProductions - [IG-SERVER] Encountered unexpected error: The TCP/IP connection to the host sqlServer.acme.edu, port 1433 has failed. Error: "Connection refused. Verify the connection properties. Make sure that an instance of SQL Server is running on the host and accepting TCP/IP connections at the port. Make sure that TCP connections to the port are not blocked by a firewall.".

com.netiq.common.i18n.LocalizedException: Encountered unexpected error: The TCP/IP connection to the host sqlServer.acme.edu, port 1433 has failed. Error: "Connection refused. Verify the connection properties. Make sure that an instance of SQL Server is running on the host and accepting TCP/IP connections at the port. Make sure that TCP connections to the port are not blocked by a firewall.".

at com.netiq.iac.common.IacException.<init>(IacException.java:105)
at com.netiq.iac.persistence.spi.exception.IacPersistenceException.<init>(IacPersistenceException.java:118)
at com.netiq.iac.persistence.dao.ops.ResultTransactor.execute(ResultTransactor.java:127)
at com.netiq.iac.server.dtp.DPMediatorService$ClaimableMediatorTask.anyUnclaimedProductions(DPMediatorService.java:339)
at com.netiq.iac.server.dtp.ManageCertPolicyCalculationTask.handler(ManageCertPolicyCalculationTask.java:65)
at com.netiq.iac.server.dtp.DPMediatorService$MediatorTask.run(DPMediatorService.java:464)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: com.netiq.persist.PersistenceException: The TCP/IP connection to the host sqlServer.acme.edu, port 1433 has failed. Error: "Connection refused. Verify the connection properties. Make sure that an instance of SQL Server is running on the host and accepting TCP/IP connections at the port. Make sure that TCP connections to the port are not blocked by a firewall.".

at com.netiq.persist.HibernateUtil.begin(HibernateUtil.java:345)
at com.netiq.iac.persistence.dao.ops.ResultTransactor.execute(ResultTransactor.java:111)
... 10 more
Caused by: org.hibernate.exception.JDBCConnectionException: Could not open connection
at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:132)
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:126)
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:112)
at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:235)
at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.getConnection(LogicalConnectionImpl.java:171)
at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.doBegin(JdbcTransaction.java:67)
at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.begin(AbstractTransactionImpl.java:162)
at org.hibernate.internal.SessionImpl.beginTransaction(SessionImpl.java:1471)
at sun.reflect.GeneratedMethodAccessor60.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.hibernate.context.internal.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:356)
at com.sun.proxy.$Proxy171.beginTransaction(Unknown Source)
at com.netiq.persist.HibernateUtil.begin(HibernateUtil.java:331)
... 11 more
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: The TCP/IP connection to the host sqlServer.acme.edu, port 1433 has failed. Error: "Connection refused. Verify the connection properties. Make sure that an instance of SQL Server is running on the host and accepting TCP/IP connections at the port. Make sure that TCP connections to the port are not blocked by a firewall.".
at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDriverError(SQLServerException.java:228)
at com.microsoft.sqlserver.jdbc.SQLServerException.ConvertConnectExceptionToSQLServerException(SQLServerException.java:285)
at com.microsoft.sqlserver.jdbc.SocketFinder.findSocket(IOBuffer.java:2437)
at com.microsoft.sqlserver.jdbc.TDSChannel.open(IOBuffer.java:641)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectHelper(SQLServerConnection.java:2245)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.login(SQLServerConnection.java:1921)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.connectInternal(SQLServerConnection.java:1762)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.connect(SQLServerConnection.java:1077)
at com.microsoft.sqlserver.jdbc.SQLServerDriver.connect(SQLServerDriver.java:623)
at org.apache.tomcat.dbcp.dbcp2.DriverConnectionFactory.createConnection(DriverConnectionFactory.java:38)
at org.apache.tomcat.dbcp.dbcp2.PoolableConnectionFactory.makeObject(PoolableConnectionFactory.java:257)
at org.apache.tomcat.dbcp.pool2.impl.GenericObjectPool.create(GenericObjectPool.java:888)
at org.apache.tomcat.dbcp.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:430)
at org.apache.tomcat.dbcp.pool2.impl.GenericObjectPool.borrowObject(GenericObjectPool.java:359)
at org.apache.tomcat.dbcp.dbcp2.PoolingDataSource.getConnection(PoolingDataSource.java:134)
at org.apache.tomcat.dbcp.dbcp2.BasicDataSource.getConnection(BasicDataSource.java:1543)
at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:139)
at org.hibernate.internal.AbstractSessionImpl$NonContextualJdbcConnectionAccess.obtainConnection(AbstractSessionImpl.java:380)
at org.hibernate.engine.jdbc.internal.LogicalConnectionImpl.obtainConnection(LogicalConnectionImpl.java:228)
... 21 more

What had happened was the DBA had taken the database down to do an upgrade. In his defense he had been asked to do so, and we knew he would eventually, but we did not think he was going to do it right away. No complaints, he got us fixed fast, but it was a scary moment as it happened.

What is interesting in this one is you can see a TCP error. You can see a SQL Server error. You can see a Hibernate error. In all three of these cases it is really the same thing, just different aspects of the same issue. Which really helps showing all the errors I think.

In general you can skip to the Caused By: lines in a Java stack trace. Here you can see what we got in the Caused by lines:

Errors:

Caused by: com.netiq.persist.PersistenceException: The TCP/IP connection to the host sqlServer.acme.edu, port 1433 has failed. Error: "Connection refused. Verify the connection properties. Make sure that an instance of SQL Server is running on the host and accepting TCP/IP connections at the port. Make sure that TCP connections to the port are not blocked by a firewall.".

Caused by: org.hibernate.exception.JDBCConnectionException: Could not open connection

Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: The TCP/IP connection to the host sqlServer.acme.edu, port 1433 has failed. Error: "Connection refused. Verify the connection properties. Make sure that an instance of SQL Server is running on the host and accepting TCP/IP connections at the port. Make sure that TCP connections to the port are not blocked by a firewall.".

This is sometimes confusing since at different levels in the stack you can get slightly different messages. Thus it is worthwhile to check them all out.

JSON Parsing error:

Here I want to revisit an idea I had mentioned in earlier articles here:
/cyberres/idgovernance/w/identity_gov_tips/5068/getting-started-with-identity-governance---part-3
/cyberres/idgovernance/w/identity_gov_tips/3405/getting-started-with-identity-governance---part-4

I described an ECMA function that I use in data fields during collection, where the Database syntax is single valued, but the data source (eDirectory, AD or other) allows multi valued. A great example is CN in eDirectory. This is a naming attribute and normally you would not expect to have two values in your naming attribute. But eDirectory does actually allow it. Similarly, Given Name and Surname can be multi valued. If you collected Surname into the standard IDG field, you actually get an error during Collection that looks a bit like this example where employeeType is internally single valued, but my data source had two values.

Multiple values for single value attribute. Refer to 'employeeType' in the following data:

{"userId":"cn=a1234567,ou=Users,o=acme","firstName":"John","lastName":"Smith","workforceId":"1001811837","dn":"cn=a1234567,ou=Users,o=acme","ext_MyAccountType":"Affiliate","employeeType":["Affiliate","Summer"],"guid":"A6811194D745494891B3A6811194D745","ext_cN":"a1234567","employeeStatus":"Active","fullName":"Smith, John"}

You can see that the data looks like this:
"employeeType":["Affiliate","Summer"]

That is, you get a JSON array returned instead of a single value. In order to flatten it, I suggested an ECMA that checks the first character of the value to see if it is an open square bracket ( [ ). If so, JSON Parse it, and take the first value. If not, return the string. Stupid, simplistic, but gets me going until someone can explain a better way to decide which value to take.

However, real world data proved that my approach really was simplistic and assumptive, because I started getting this error on real world data:

Exception javax.script.ScriptException occurred while processing transformation: SyntaxError: Invalid JSON: <json>:1:1 Expected json literal but found r [root] in <eval> at line number 1.

I could not make heads or tails of this one. JSON is invalid. Ok. What does the found "r [root]" mean? That confused me. Someone else looking at it (Thanks a ton Steve, appreciate it) noticed that I had 35 groups with the DN of something like [root].Admins.groups.acme.edu so when I tried to get CN and make sure it was single valued, the value of [root] was being passed into my ECMA. Then, yes, the first character was an open square bracket, so tried to JSON Parse it and failed with invalid ECMA, and in hindsight it returned the value [root] as the error.

Of course without knowing that the [root] was coming from the data itself it was hard to understand the error. Anyway, the key here would be to be more clever in detecting JSON. I am still playing around with it, and will update the other two articles with a slightly more sophisticated test when I am done. But the error is instructive, since it was actually kind of useful and accurate, but I could not quite see it at the time.

Another 486 error:

This one is a bit generic, since I did not properly enable the logging to figure it out properly, but I think it is worth calling it out. The DAAS (damned if I know what that stands for. Data Acquisition Access Service? Dudes Always Ask Second? The mind boggles. I know DTP is data transformation processing/processor but not sure what DAAS means. Directory As A Service, probably that one.).

I had enabled REST tracing, so I can see what the IG Client is sending into the IG-Server. (I forget the exact class I enabled for logging this, so save your question. Look at the ig-server-logging.xml file for something obvious).

I think I was just trying the Test Connection button for a Database connection. You can see it is trying to collect an ACCOUNT, via JDBC template, and the configuration was not quite correct so 486 here just means the DB connection failed.

[FINE] 2018-08-21 12:20:19 com.netiq.iac.server.common.rest.RestCallExecutor$Request <init> - [IG-SERVER]
PUT https://id-gov1.acme.edu:8443/daas/rest/service
Credentials: iac-service:********
Token: 21Aug2018 12:21:46 CDT eH8AIIPeMI0eGjG2V5gSbl@rQyp6R@tVs5DveOPw0AhopXK302tqHTHgsMQ1TrZ8ZJWCdstsD/amVSRD1u7rffIVrCUmMn8s85PxZsD3wrm0hU3ZVAm2s9TVIXBIIvhdxmEm2pPP1WV8Fd4dmBZKHfXgOgGzuE6oF
hFERX9emwoo@vvp
Headers:
X-Authorization : Bearer eH8AIIPeMI0eGjG2V5gSbl@rQyp6R@tVs5DveOPw0AhopXK302tqHTHgsMQ1TrZ8ZJWCdstsD/amVSRD1u7rffIVrCUmMn8s85PxZsD3wrm0hU3ZVAm2s9TVIXBIIvhdxmEm2pPP1WV8Fd4dmBZKHfXgOgGzuE
6oFhFERX9emwoo@vvp
{"data-source-name":"SomeApp Database Connection","collector-type":"ACCOUNT","service-identifier":"JDBCSQLServerAccountTemplate-1534867912037-gromitid-8","class":"com.netiq.daas.nativejdbcservice.NativeJDBCService","allow-connection-test":true,"allow-collection-test":true,"service-parms":[{"name":"database-type","display-name":"Database Type","description":"Database Type","data-type":"string","default-value":"sqlserver","value":"sqlserver","required":true,"hidden":true},{"name":"server","display-name":"Host Server","description":"SQLServer Database Host Server","data-type":"string","default-value":"localhost","value":"dbServer1.acme.edu","required":true},{"name":"port","display-name":"Host Server Port","description":"SQLServer Database Host Server Port","data-type":"string","default-value":"1433","value":"1433","required":true},{"name":"database-name","display-name":"Database Instance Name","description":"Name of Database Instance","data-type":"string","default-value":"","value":"Test","required":true},{"name":"chunk-request-ttl","display-name":"Batch Collection Session Timeout Value","description":"Number of seconds of idle time before a batched collection session is terminated","data-type":"numeric","default-value":60,"value":60,"required":true}

After receiving the REST data at the main server endpoint, it looks like it passes it to a specific endpoint referencing the Template configuration and the test node.

[FINE] 2018-08-21 12:20:20 com.netiq.iac.server.common.rest.RestCallExecutor$Request <init> - [IG-SERVER]
GET https://id-gov1.acme.edu:8443/daas/rest/service/JDBCSQLServerAccountTemplate-1534867912037-gromitid-8/test
Credentials: iac-service:********
Token: 21Aug2018 12:21:46 CDT eH8AIIPeMI0eGjG2V5gSbl@rQyp6R@tVs5DveOPw0AhopXK302tqHTHgsMQ1TrZ8ZJWCdstsD/amVSRD1u7rffIVrCUmMn8s85PxZsD3wrm0hU3ZVAm2s9TVIXBIIvhdxmEm2pPP1WV8Fd4dmBZKHfXgOgGzuE6oF
hFERX9emwoo@vvp
Headers:
X-Authorization : Bearer eH8AIIPeMI0eGjG2V5gSbl@rQyp6R@tVs5DveOPw0AhopXK302tqHTHgsMQ1TrZ8ZJWCdstsD/amVSRD1u7rffIVrCUmMn8s85PxZsD3wrm0hU3ZVAm2s9TVIXBIIvhdxmEm2pPP1WV8Fd4dmBZKHfXgOgGzuE
6oFhFERX9emwoo@vvp
Authorization : Basic dXRob3VzdG9uXGxh12345bWFuOkp1bmUwNl8yMDE4
[FINE] 2018-08-21 12:20:20 com.netiq.iac.persistence.dcs.dce.daas.DaaSService testConnection - [IG-SERVER] DaaS Service Test response code: 486

With little other logging enabled, just get a 486 error, which is the generic cannot connect error. I have a couple more better 486 errors with DAAS logging enabled that will come later and show much more interesting information.

[FINE] 2018-08-21 12:20:20 com.netiq.iac.server.common.rest.RestCallExecutor$Request <init> - [IG-SERVER]
DELETE https://id-gov1.acme.edu:8443/daas/rest/service/JDBCSQLServerAccountTemplate-1534867912037-gromitid-8
Credentials: iac-service:********
Token: 21Aug2018 12:21:46 CDT eH8AIIPeMI0eGjG2V5gSbl@rQyp6R@tVs5DveOPw0AhopXK302tqHTHgsMQ1TrZ8ZJWCdstsD/amVSRD1u7rffIVrCUmMn8s85PxZsD3wrm0hU3ZVAm2s9TVIXBIIvhdxmEm2pPP1WV8Fd4dmBZKHfXgOgGzuE6oF
hFERX9emwoo@vvp
Headers:
X-Authorization : Bearer eH8AIIPeMI0eGjG2V5gSbl@rQyp6R@tVs5DveOPw0AhopXK302tqHTHgsMQ1TrZ8ZJWCdstsD/amVSRD1u7rffIVrCUmMn8s85PxZsD3wrm0hU3ZVAm2s9TVIXBIIvhdxmEm2pPP1WV8Fd4dmBZKHfXgOgGzuE6oFhFERX9emwoo@vvp

Then it bubbles up an error to the testConnection call. Alas, this is simply the 486 error code which is not super helpful, all by itself.

[FINE] 2018-08-21 12:20:20 com.netiq.iac.persistence.service.***.DataCollectionService testConnection - [IG-SERVER] Encountered unexpected error: DAAS_ERROR: 486 : Target Connection failure.
com.netiq.common.i18n.LocalizedException: Encountered unexpected error: DAAS_ERROR: 486 : Target Connection failure.
at com.netiq.iac.common.IacException.<init>(IacException.java:105)
at com.netiq.iac.persistence.spi.exception.DaaSServiceException.<init>(DaaSServiceException.java:55)
at com.netiq.iac.persistence.dcs.dce.daas.DaaSService.testConnection(DaaSService.java:522)
at com.netiq.iac.persistence.service.***.DataCollectionService.testConnection(DataCollectionService.java:213)
at com.netiq.iac.server.rest.ConnectionService.testConnection(ConnectionService.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$ResponseOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:205)
at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1542)
at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1473)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419)
at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409)
at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:409)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:558)
at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:733)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.netiq.iac.common.j2ee.NoCacheFilter.doFilter(NoCacheFilter.java:65)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.netiq.common.i18n.impl.BestLocaleChooserFilter.doFilter(BestLocaleChooserFilter.java:234)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.netiq.iac.server.common.audit.AuditLogFilter.doFilter(AuditLogFilter.java:134)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.netiq.iac.server.j2ee.RestApiAuthFilter.doFilter(RestApiAuthFilter.java:145)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.netiq.iac.server.j2ee.AuthFilter.doFilter(AuthFilter.java:239)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.netiq.iac.server.j2ee.CORSFilter.doFilter(CORSFilter.java:80)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:199)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:650)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:803)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.Exception: DAAS_ERROR: 486 : Target Connection failure.
at com.netiq.iac.persistence.dcs.dce.daas.DaaSService.testConnection(DaaSService.java:505)
... 62 more

Then finally it returns the JSON back to redraw the client user interface with the error code.

[SEVERE] 2018-08-21 12:20:20 com.netiq.iac.server.rest.ConnectionService testConnection - [IG-SERVER] Test Connection error: DAAS_ERROR: 486 : Target Connection failure.
[FINE] 2018-08-21 12:20:20 com.netiq.iac.server.common.audit.AuditLogFilter logRequestOutcome - [IG-SERVER] API server request{"user":{"userName":"Geoffrey Carman","userId":"gcarman","uniqueUserId":"dfea2b8c40394db293eeaa7ef9066fc4"},"headers":{"referer":"https://id-gov1.acme.edu:8443/","content-length":"1685","accept-language":"en-US,en;q=0.5","host":"id-gov1.acme.edu:8443","content-type":"application/json","connection":"keep-alive","dnt":"1","accept-encoding":"gzip, deflate, br","user-agent":"Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:61.0) Gecko/20100101 Firefox/61.0","accept":"application/json"},"body":"{\"data-source-name\":\"SomeApp Database Connection\",\"collector-type\":\"ACCOUNT\",\"service-identifier\":\"JDBCSQLServerAccountTemplate-1534867912037-gromitid-8\",\"class\":\"com.netiq.daas.nativejdbcservice.NativeJDBCService\",\"allow-connection-test\":true,\"allow-collection-test\":true,\"service-parms\":[{\"name\":\"database-type\",\"display-name\":\"Database Type\",\"description\":\"Database Type\",\"data-type\":\"string\",\"default-value\":\"sqlserver\",\"value\":\"sqlserver\",\"required\":true,\"hidden\":true},{\"name\":\"server\",\"display-name\":\"Host Server\",\"description\":\"SQLServer Database Host Server\",\"data-type\":\"string\",\"default-value\":\"localhost\",\"value\":\"dbServer1.acme.edu\",\"required\":true},{\"name\":\"port\",\"display-name\":\"Host Server Port\",\"description\":\"SQLServer Database Host Server Port\",\"data-type\":\"string\",\"default-value\":\"1433\",\"value\":\"1433\",\"required\":true},{\"name\":\"database-name\",\"display-name\":\"Database Instance Name\",\"description\":\"Name of Database Instance\",\"data-type\":\"string\",\"default-value\":\"\",\"value\":\"Test\",\"required\":true},{\"name\":\"user\",\"display-name\":\"User Name\",\"description\":\"User name used to connect to SQLServer Database Server\",\"data-type\":\"string\",\"value\":\"acme\\\\myUserName\",\"required\":true,\"credential-type\":\"user\",\"credential-position\":0},{\"name\":\"chunk-request-ttl\",\"display-name\":\"Batch Collection Session Timeout Value\",\"description\":\"Number of seconds of idle time before a batched collection session is terminated\",\"data-type\":\"numeric\",\"default-value\":60,\"value\":60,\"required\":true}","sender":"10.1.158.23","params":{"id":"26"},"method":"POST","path":"/api/dcs/connection/test"}
API server response{"body":"{\"Fault\":{\"Code\":{\"Value\":\"Sender\",\"Subcode\":{\"Value\":\"DaasConnectionFail\"}},\"Reason\":{\"Text\":\"DAAS_ERROR: 486 : Target Connection failure.\"}}}","status":200}

There is a typical problem. Enabling logging on certain classes adds overhead and slows everything down. But on the other hand troubleshooting after the fact is often impossible. During development, I like to enable DAAS logging since it really makes figuring out what is breaking much easier. But it definitely slows down the process.

Another 486 error example:

Here is an example of generating the same basic error, with bad information (so the connection fails) and generating the 486 error, but this time, having edited the file:
/opt/netiq/idm/apps/tomcat/conf/daas-logging.xml

There are two classes named there:
com.netiq.daas
com.microfocus.daas

I find that we need the netiq instance trace level increased from the default of INFO to something higher. I like TRACE.

Thus the line in the daas-logging.xml file should then have this line in it.

<logger additivity="true" name="com.netiq.daas" level="TRACE"/>

Once enabled, more information, that we can see comes from the level FINE. We can see that this is using the MS SQL connector, it gets the DB name and info, the username, the password and so on.

[FINE] 2018-08-22 13:13:21 com.netiq.daas.daaservice.ServiceProviderMap clean - [DAAS] Collection cleaner running...
[FINE] 2018-08-22 13:13:21 com.netiq.daas.nativejdbcservice.ConnectorFactory createConnector - [DAAS] Creating Microsoft SQLServer Specific Connector
[FINE] 2018-08-22 13:13:21 com.netiq.daas.nativejdbcservice.connector.DBConnector setDriverClassName - [DAAS] Driver Class Name com.microsoft.sqlserver.jdbc.SQLServerDriver
[FINE] 2018-08-22 13:13:21 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] setting connectionProperties
[FINE] 2018-08-22 13:13:21 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] Key :databaseName value 'myDBname' added to connectionProperties
[FINE] 2018-08-22 13:13:21 com.netiq.daas.common.SrvInstance <init> - [DAAS] New service instance. TTL: 60
[FINE] 2018-08-22 13:13:21 com.netiq.daas.common.SrvInstance resetTimeout - [DAAS] Reset timeout for service instance to TTL: 60
[FINE] 2018-08-22 13:13:21 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] setting connectionProperties
[FINE] 2018-08-22 13:13:21 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] Key :password value '<suppressed>' added to connectionProperties
[FINE] 2018-08-22 13:13:21 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] Key :user value 'igops' added to connectionProperties
[FINEST] 2018-08-22 13:13:21 com.netiq.daas.nativejdbcservice.connector.DBConnector getConnectionProperties - [DAAS] accessor call to connectionProperties
[FINE] 2018-08-22 13:13:21 com.netiq.daas.nativejdbcservice.connector.DBConnector establishDBConnection - [DAAS] Caught SQLException: Cannot open database "" requested by the login.
The login failed. ClientConnectionId:c4914eed-92db-4291-9bc2-df22a17da70e
[FINE] 2018-08-22 13:13:21 com.netiq.iac.persistence.dcs.dce.daas.DaaSService testConnection - [IG-SERVER] DaaS Service Test response code: 486

Alas, there is not much here other than to say a 486 error and that the connection failed. But this time it gave me enough info to know that I had sent in the wrong DB name, as part of my troubleshooting, and once this showed it to me, I was able to easily fix it.

Actual Success of a test:

Once I figured out the proper parameters, I was able to get a successful connection, which I think is useful, since sometimes the error is the next line that should have happened, but did not yet happen.

[FINE] 2018-08-22 13:15:06 com.netiq.daas.daaservice.ServiceProviderMap clean - [DAAS] Collection cleaner running...
[FINE] 2018-08-22 13:15:06 com.netiq.daas.nativejdbcservice.ConnectorFactory createConnector - [DAAS] Creating Microsoft SQLServer Specific Connector
[FINE] 2018-08-22 13:15:06 com.netiq.daas.nativejdbcservice.connector.DBConnector setDriverClassName - [DAAS] Driver Class Name com.microsoft.sqlserver.jdbc.SQLServerDriver
[FINE] 2018-08-22 13:15:06 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] setting connectionProperties
[FINE] 2018-08-22 13:15:06 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] Key :databaseName value 'igops' added to connectionProperties
[FINE] 2018-08-22 13:15:06 com.netiq.daas.common.SrvInstance <init> - [DAAS] New service instance. TTL: 60
[FINE] 2018-08-22 13:15:06 com.netiq.daas.common.SrvInstance resetTimeout - [DAAS] Reset timeout for service instance to TTL: 60
[FINE] 2018-08-22 13:15:06 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] setting connectionProperties
[FINE] 2018-08-22 13:15:06 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] Key :password value '<suppressed>' added to connectionProperties
[FINE] 2018-08-22 13:15:06 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] Key :user value 'igops' added to connectionProperties
[FINEST] 2018-08-22 13:15:06 com.netiq.daas.nativejdbcservice.connector.DBConnector getConnectionProperties - [DAAS] accessor call to connectionProperties
[FINE] 2018-08-22 13:15:06 com.netiq.iac.persistence.dcs.dce.daas.DaaSService testConnection - [IG-SERVER] DaaS Service Test response code: 204

This time, it returned an HTTP 204, which means "No content". That is, success, but no where to go after the success. Usually 200 is success and here the 204 is a good success message.

In this case, I was testing a database connection to an MS SQL instance, where I had an Instance Name, but alas, the DBA's did not do as they normally would do on Microsoft SQL using an instance, and give me a custom port. Usually in MS SQL you connect on port 1433 to the main instance. If you are using instances, generally you define a different port for each instance. In my case, the DBAs decided to use the same port, but for an instance.

In that case, the connection URL needs to take an additional parameter, called instanceName=myInstance appended to the end of the connect URL. But critically, without a port number. An example URL might look like this:

jdbc:sqlserver://myDBServer.acme.edu;instanceName=sql2016NPR;databaseName=igops

If you had a custom port, say 1434, then it would be much simpler:
jdbc:sqlserver://myDBServer.acme.edu:1434;databaseName=igops

This was quite confusing and frustrating, but did all work in the end. We had to install with Liquibase making the SQL commands after install, edit the server.xml in Tomcat's directory to fix the connector configuration and put in the proper URL (also configutil.sh needs an update as well). But it does work.

You will notice this level of logging does not provide the JDBC URL to connect with, instead it shows just the username, password, and DB name. I think this is because you are connecting to a 'connection template' that defines the database connection information and this is just adding in the specifics of the user etc.

JTDS Issues:

To connect to a Microsoft SQL server there are actually two different JDBC Java classes you can use. There is the Microsoft provided class, and then there is an open source driver call JTDS. Sometimes I have seen it written as jTDS (Jave based, Tabular Data Stream) This is a nice driver since this one works with most databases and claims to be pretty fast and Open Source.

In my case, our first database was SQL Server with an Instance but not a custom port, but the second database we had to connect to was using Microsoft's Integrated Authentication. Alas, the Microsoft provided JDBC class did not support domain authentication, but jTDS the free, open source one did. Go figure.

First we tried to connect with domain\username as our login name and no success.

JTDS Failing:

[FINE] 2018-08-22 13:25:50 com.netiq.daas.daaservice.ServiceProviderMap clean - [DAAS] Collection cleaner running...
[FINE] 2018-08-22 13:25:50 com.netiq.daas.nativejdbcservice.ConnectorFactory createConnector - [DAAS] Creating GENERIC Connector, this can used to collect data from any data-base
[FINE] 2018-08-22 13:25:50 com.netiq.daas.nativejdbcservice.connector.DBConnector setDriverClassName - [DAAS] Driver Class Name net.sourceforge.jtds.jdbc
[FINE] 2018-08-22 13:25:50 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] setting connectionProperties
[FINE] 2018-08-22 13:25:50 com.netiq.daas.common.SrvInstance <init> - [DAAS] New service instance. TTL: 60
[FINE] 2018-08-22 13:25:50 com.netiq.daas.common.SrvInstance resetTimeout - [DAAS] Reset timeout for service instance to TTL: 60
[FINE] 2018-08-22 13:25:50 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] setting connectionProperties
[FINE] 2018-08-22 13:25:50 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] Key :password value '<suppressed>' added to connectionProperties
[FINE] 2018-08-22 13:25:50 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] Key :user value 'acme\myUserName' added to connectionProperties
[FINEST] 2018-08-22 13:25:50 com.netiq.daas.nativejdbcservice.connector.DBConnector getConnectionProperties - [DAAS] accessor call to connectionProperties
[FINE] 2018-08-22 13:25:50 com.netiq.daas.nativejdbcservice.connector.DBConnector establishDBConnection - [DAAS] Class resource to connect to the underlying database not found: net.sourceforge.jtds.jdbc
[FINE] 2018-08-22 13:25:50 com.netiq.iac.persistence.dcs.dce.daas.DaaSService testConnection - [IG-SERVER] DaaS Service Test response code: 486

Oh joy, another 486 error. Not so helpful this time.

JTDS Working:

Here we needed to specify the domain in the connection URL as:

jdbc:jtds:sqlserver://myDBServer.acme.edu:1433/Test;domain=acme

[FINE] 2018-08-22 13:49:09 com.netiq.daas.daaservice.ServiceProviderMap clean - [DAAS] Collection cleaner running...
[FINE] 2018-08-22 13:49:09 com.netiq.daas.nativejdbcservice.ConnectorFactory createConnector - [DAAS] Creating GENERIC Connector, this can used to collect data from any data-base
[FINE] 2018-08-22 13:49:09 com.netiq.daas.nativejdbcservice.connector.DBConnector setDriverClassName - [DAAS] Driver Class Name net.sourceforge.jtds.jdbc.Driver
[FINE] 2018-08-22 13:49:09 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] setting connectionProperties
[FINE] 2018-08-22 13:49:09 com.netiq.daas.common.SrvInstance <init> - [DAAS] New service instance. TTL: 60
[FINE] 2018-08-22 13:49:09 com.netiq.daas.common.SrvInstance resetTimeout - [DAAS] Reset timeout for service instance to TTL: 60
[FINE] 2018-08-22 13:49:09 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] setting connectionProperties
[FINE] 2018-08-22 13:49:09 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] Key :password value '<suppressed>' added to connectionProperties
[FINE] 2018-08-22 13:49:09 com.netiq.daas.nativejdbcservice.connector.DBConnector setConnectionProperties - [DAAS] Key :user value 'myUserName' added to connectionProperties
[FINEST] 2018-08-22 13:49:09 com.netiq.daas.nativejdbcservice.connector.DBConnector getConnectionProperties - [DAAS] accessor call to connectionProperties
[FINE] 2018-08-22 13:49:09 com.netiq.iac.persistence.dcs.dce.daas.DaaSService testConnection - [IG-SERVER] DaaS Service Test response code: 204

Here too we get success with a 204 success message, no content since it was just simply a quiet success.

That about wraps this episode of error codes in Identity Governance. I have another bunch of errors to continue writing up and I will try and get them done as soon as I can. If you happen to run across something interesting in your log, remember to grab and save it, especially if you can figure out how to fix it, since someone else is almost certain to run into the same error at some point and if you can write it up, they might find it and save a ton of time.