=== 2016-01-15 14:34:51,333 [6-39] INFO RequestContext - URL: '/builtinds/sc/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; CTL_11; rv:11.0) like Gecko': Unsupported with Accept-Encoding header === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: Cookie:GLog=%7B%0A%20%20%20%20trackRPC%3Atrue%2C%20%0A%20%20%20%20isc_pageURL%3A%22http%3A//127.0.0.1%3A8888/BuiltInDS.html%3Fgwt.codesvr%3D127.0.0.1%3A9997%22%2C%20%0A%20%20%20%20isc_pageGUID%3A%22F1E219C6-7D76-49E9-BAE0-5703862499D4%22%2C%20%0A%20%20%20%20priorityDefaults%3A%7B%0A%20%20%20%20%20%20%20%20sgwtInternal%3A1%0A%20%20%20%20%7D%2C%20%0A%20%20%20%20defaultPriority%3A3%2C%20%0A%20%20%20%20left%3A-32000%2C%20%0A%20%20%20%20top%3A-31971%2C%20%0A%20%20%20%20width%3A1032%2C%20%0A%20%20%20%20height%3A661%0A%7D; isc_cState=ready; JSESSIONID=19o96jgnl5u5f17l0braei1zuf === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: Host:127.0.0.1:8888 === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: Accept:*/* === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: Content-Length:6678 === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8 === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: Accept-Language:en-US === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: Connection:keep-alive === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: User-Agent:Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; CTL_11; rv:11.0) like Gecko === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: Referer:http://127.0.0.1:8888/BuiltInDS.html?gwt.codesvr=127.0.0.1:9997 === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - session exists: 19o96jgnl5u5f17l0braei1zuf === 2016-01-15 14:34:51,333 [6-39] DEBUG IDACall - remote user: null === 2016-01-15 14:34:51,385 [6-39] DEBUG XML - Parsed XML from (in memory stream): 0ms === 2016-01-15 14:34:51,385 [6-39] DEBUG ISCKeyedObjectPool - Borrowing object for 'transaction' === 2016-01-15 14:34:51,385 [6-39] DEBUG PoolableDataSourceFactory - Tried to create DataSource of type 'transaction' but null was returned === 2016-01-15 14:34:51,385 [6-39] DEBUG PoolableDataSourceFactory - Created DataSource null of type 'transaction' in the pooling flow === 2016-01-15 14:34:51,385 [6-39] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object' === 2016-01-15 14:34:51,385 [6-39] DEBUG PoolableDataSourceFactory - Created DataSource 112 of type 'Object' and assigned it to thread qtp336217686-39 === 2016-01-15 14:34:51,385 [6-39] DEBUG PoolableDataSourceFactory - Created DataSource 112 of type 'Object' in the pooling flow === 2016-01-15 14:34:51,385 [6-39] DEBUG PoolableDataSourceFactory - Activated DataSource 112 of type 'Object' === 2016-01-15 14:34:51,385 [6-39] DEBUG ISCKeyedObjectPool - Borrowing object for 'List' === 2016-01-15 14:34:51,401 [6-39] DEBUG PoolableDataSourceFactory - Created DataSource 113 of type 'List' and assigned it to thread qtp336217686-39 === 2016-01-15 14:34:51,401 [6-39] DEBUG PoolableDataSourceFactory - Created DataSource 113 of type 'List' in the pooling flow === 2016-01-15 14:34:51,401 [6-39] DEBUG PoolableDataSourceFactory - Activated DataSource 113 of type 'List' === 2016-01-15 14:34:51,401 [6-39] DEBUG ISCKeyedObjectPool - Borrowing object for 'elem' === 2016-01-15 14:34:51,401 [6-39] DEBUG PoolableDataSourceFactory - Tried to create DataSource of type 'elem' but null was returned === 2016-01-15 14:34:51,401 [6-39] DEBUG PoolableDataSourceFactory - Created DataSource null of type 'elem' in the pooling flow === 2016-01-15 14:34:51,401 [6-39] DEBUG RPCManager - Processing 1 requests. === 2016-01-15 14:34:51,401 [6-39] DEBUG ISCKeyedObjectPool - Borrowing object for 'fourDimensionRates' === 2016-01-15 14:34:51,401 [6-39] DEBUG PoolableDataSourceFactory - Activated DataSource 44 of type 'fourDimensionRates' === 2016-01-15 14:34:51,401 [6-39] DEBUG DSRequest - Caching instance 44 of DS 'fourDimensionRates' from DSRequest.getDataSource() === 2016-01-15 14:34:51,401 [6-39] DEBUG DSRequest - Caching instance 44 of DS fourDimensionRates === 2016-01-15 14:34:51,401 [6-39] DEBUG RPCManager - Request #1 (DSRequest) payload: { criteria:{ operator:"and", _constructor:"AdvancedCriteria", criteria:[ { fieldName:"RATE_SET_CD", operator:"equals", value:"TIER DS1 IP" }, { fieldName:"EFFECTIVE_DT", operator:"equals", value:new Date(1452834000000) }, { fieldName:"RC3_OCCUR_NO", operator:"iEquals", value:"1" }, { fieldName:"RC4_OCCUR_NO", operator:"iEquals", value:"1" }, { _constructor:"AdvancedCriteria", operator:"or", criteria:[ { fieldName:"RC2_OCCUR_NO", operator:"equals", value:4 }, { fieldName:"RC2_OCCUR_NO", operator:"equals", value:3 }, { fieldName:"RC2_OCCUR_NO", operator:"equals", value:2 }, { fieldName:"RC2_OCCUR_NO", operator:"equals", value:1 } ] }, { _constructor:"AdvancedCriteria", operator:"or", criteria:[ { fieldName:"RC1_OCCUR_NO", operator:"equals", value:2 }, { fieldName:"RC1_OCCUR_NO", operator:"equals", value:1 } ] }, { _constructor:"AdvancedCriteria", operator:"or", criteria:[ { fieldName:"RATE_SET_CD", operator:"iEquals", value:"TIER DS1 IP" } ] } ] }, operationConfig:{ dataSource:"fourDimensionRates", repo:null, operationType:"fetch", textMatchStyle:"exact" }, useStrictJSON:true, appID:"builtinApplication", operation:"fourDimensionRates_fetch", oldValues:{ operator:"and", _constructor:"AdvancedCriteria", criteria:[ { fieldName:"RATE_SET_CD", operator:"equals", value:"TIER DS1 IP" }, { fieldName:"EFFECTIVE_DT", operator:"equals", value:new Date(1452834000000) }, { fieldName:"RC3_OCCUR_NO", operator:"iEquals", value:"1" }, { fieldName:"RC4_OCCUR_NO", operator:"iEquals", value:"1" }, { _constructor:"AdvancedCriteria", operator:"or", criteria:[ { fieldName:"RC2_OCCUR_NO", operator:"equals", value:4 }, { fieldName:"RC2_OCCUR_NO", operator:"equals", value:3 }, { fieldName:"RC2_OCCUR_NO", operator:"equals", value:2 }, { fieldName:"RC2_OCCUR_NO", operator:"equals", value:1 } ] }, { _constructor:"AdvancedCriteria", operator:"or", criteria:[ { fieldName:"RC1_OCCUR_NO", operator:"equals", value:2 }, { fieldName:"RC1_OCCUR_NO", operator:"equals", value:1 } ] }, { _constructor:"AdvancedCriteria", operator:"or", criteria:[ { fieldName:"RATE_SET_CD", operator:"iEquals", value:"TIER DS1 IP" } ] } ] } } === 2016-01-15 14:34:51,401 [6-39] INFO IDACall - Performing 1 operation(s) === 2016-01-15 14:34:51,401 [6-39] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null === 2016-01-15 14:34:51,401 [6-39] DEBUG DeclarativeSecurity - DataSource fourDimensionRates is not in the pre-checked list, processing... === 2016-01-15 14:34:51,401 [6-39] DEBUG AppBase - [builtinApplication.fourDimensionRates_fetch] No userTypes defined, allowing anyone access to all operations for this application === 2016-01-15 14:34:51,401 [6-39] DEBUG AppBase - [builtinApplication.fourDimensionRates_fetch] No public zero-argument method named '_fourDimensionRates_fetch' found, performing generic datasource operation === 2016-01-15 14:34:51,401 [6-39] INFO SQLDataSource - [builtinApplication.fourDimensionRates_fetch] Performing fetch operation with criteria: {criteria:[{fieldName:"RATE_SET_CD",operator:"equals",value:"TIER DS1 IP"},{fieldName:"EFFECTIVE_DT",operator:"equals",value:new Date(1452834000000)},{fieldName:"RC3_OCCUR_NO",operator:"iEquals",value:"1"},{fieldName:"RC4_OCCUR_NO",operator:"iEquals",value:"1"},{criteria:[{fieldName:"RC2_OCCUR_NO",operator:"equals",value:4},{fieldName:"RC2_OCCUR_NO",operator:"equals",value:3},{fieldName:"RC2_OCCUR_NO",operator:"equals",value:2},{fieldName:"RC2_OCCUR_NO",operator:"equals",value:1}],operator:"or"},{criteria:[{fieldName:"RC1_OCCUR_NO",operator:"equals",value:2},{fieldName:"RC1_OCCUR_NO",operator:"equals",value:1}],operator:"or"},{criteria:[{fieldName:"RATE_SET_CD",operator:"iEquals",value:"TIER DS1 IP"}],operator:"or"}],operator:"and",_constructor:"AdvancedCriteria"} values: {criteria:[{fieldName:"RATE_SET_CD",operator:"equals",value:"TIER DS1 IP"},{fieldName:"EFFECTIVE_DT",operator:"equals",value:new Date(1452834000000)},{fieldName:"RC3_OCCUR_NO",operator:"iEquals",value:"1"},{fieldName:"RC4_OCCUR_NO",operator:"iEquals",value:"1"},{criteria:[{fieldName:"RC2_OCCUR_NO",operator:"equals",value:4},{fieldName:"RC2_OCCUR_NO",operator:"equals",value:3},{fieldName:"RC2_OCCUR_NO",operator:"equals",value:2},{fieldName:"RC2_OCCUR_NO",operator:"equals",value:1}],operator:"or"},{criteria:[{fieldName:"RC1_OCCUR_NO",operator:"equals",value:2},{fieldName:"RC1_OCCUR_NO",operator:"equals",value:1}],operator:"or"},{criteria:[{fieldName:"RATE_SET_CD",operator:"iEquals",value:"TIER DS1 IP"}],operator:"or"}],operator:"and",_constructor:"AdvancedCriteria"} === 2016-01-15 14:34:51,432 [6-39] DEBUG DSRequest - About to free up resources for request of type fetch on DataSource fourDimensionRates === 2016-01-15 14:34:51,432 [6-39] WARN RequestContext - dsRequest.execute() failed: java.lang.NullPointerException at com.isomorphic.sql.OracleDriver.sqlInTransform(OracleDriver.java:276) at com.isomorphic.sql.SQLDataSource.valueForWhereClause(SQLDataSource.java:964) at com.isomorphic.sql.SQLDataSource.escapeValueForWhereClause(SQLDataSource.java:887) at com.isomorphic.velocity.ISCReferenceInsertionEventHandler.referenceInsert(ISCReferenceInsertionEventHandler.java:125) at org.apache.velocity.app.event.ReferenceInsertionEventHandler$referenceInsertExecutor.execute(ReferenceInsertionEventHandler.java:87) at org.apache.velocity.app.event.EventHandlerUtil.iterateOverEventHandlers(EventHandlerUtil.java:444) at org.apache.velocity.app.event.EventHandlerUtil.referenceInsert(EventHandlerUtil.java:97) at org.apache.velocity.runtime.parser.node.ASTReference.render(ASTReference.java:404) at org.apache.velocity.runtime.parser.node.SimpleNode.render(SimpleNode.java:342) at org.apache.velocity.runtime.RuntimeInstance.render(RuntimeInstance.java:1378) at org.apache.velocity.runtime.RuntimeInstance.evaluate(RuntimeInstance.java:1314) at org.apache.velocity.runtime.RuntimeInstance.evaluate(RuntimeInstance.java:1265) at org.apache.velocity.app.VelocityEngine.evaluate(VelocityEngine.java:199) at com.isomorphic.velocity.Velocity.evaluate(Velocity.java:293) at com.isomorphic.velocity.Velocity.evaluateAsString(Velocity.java:260) at com.isomorphic.sql.SQLDataSource.generateSQLStatement(SQLDataSource.java:1344) at com.isomorphic.sql.SQLDataSource.SQLExecute(SQLDataSource.java:1979) at com.isomorphic.sql.SQLDataSource.processRequest(SQLDataSource.java:447) at com.isomorphic.sql.SQLDataSource.executeFetch(SQLDataSource.java:392) at com.isomorphic.datasource.DataSource.execute(DataSource.java:2227) at com.isomorphic.application.AppBase.executeDefaultDSOperation(AppBase.java:735) at com.isomorphic.application.AppBase.executeAppOperation(AppBase.java:652) at com.isomorphic.application.AppBase.execute(AppBase.java:493) at com.isomorphic.datasource.DSRequest.execute(DSRequest.java:2666) at com.isomorphic.servlet.IDACall.handleDSRequest(IDACall.java:228) at com.isomorphic.servlet.IDACall.processRPCTransaction(IDACall.java:187) at com.isomorphic.servlet.IDACall.processRequest(IDACall.java:152) at com.isomorphic.servlet.IDACall._processRequest(IDACall.java:119) at com.isomorphic.servlet.IDACall.doPost(IDACall.java:79) at javax.servlet.http.HttpServlet.service(HttpServlet.java:755) at com.isomorphic.servlet.BaseServlet.service(BaseServlet.java:162) at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:686) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1494) at com.isomorphic.servlet.CompressionFilter._doFilter(CompressionFilter.java:260) at com.isomorphic.servlet.BaseFilter.doFilter(BaseFilter.java:88) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1474) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:499) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:557) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1086) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:428) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1020) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116) at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:68) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116) at org.eclipse.jetty.server.Server.handle(Server.java:370) at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:489) at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:960) at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:1021) at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:865) at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82) at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:668) at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) at java.lang.Thread.run(Unknown Source) === 2016-01-15 14:34:51,432 [6-39] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8 === 2016-01-15 14:34:51,432 [6-39] DEBUG RPCManager - non-DMI response, dropExtraFields: false === 2016-01-15 14:34:51,432 [6-39] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 44 === 2016-01-15 14:34:51,432 [6-39] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 44 === 2016-01-15 14:34:51,432 [6-39] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 44 === 2016-01-15 14:34:51,432 [6-39] DEBUG PoolableDataSourceFactory - Cleared and passivated DataSource 44 of type 'fourDimensionRates' === 2016-01-15 14:34:51,432 [6-39] INFO Compression - /builtinds/sc/IDACall: 150 -> 134 bytes === 2016-01-15 14:34:51,912 [6-28] INFO RequestContext - URL: '/builtinds/sc/skins/Enterprise/images/Dialog/warn.png', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; CTL_11; rv:11.0) like Gecko': Unsupported with Accept-Encoding header === 2016-01-15 14:34:51,918 [6-28] INFO Download - done streaming: C:/Users/aa82923/DEV/eclipse/SandBox/builtinds/war/builtinds/sc/skins/Enterprise/images/Dialog/warn.png === 2016-01-15 14:34:52,188 [6-29] INFO RequestContext - URL: '/builtinds/sc/skins/Enterprise/images/headerIcons/close.png', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; CTL_11; rv:11.0) like Gecko': Unsupported with Accept-Encoding header === 2016-01-15 14:34:52,193 [6-29] INFO Download - done streaming: C:/Users/aa82923/DEV/eclipse/SandBox/builtinds/war/builtinds/sc/skins/Enterprise/images/headerIcons/close.png === 2016-01-15 14:35:02,325 [6-24] INFO RequestContext - URL: '/builtinds/sc/system/development/ISC_ServerLogViewer.js', User-Agent: 'Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; CTL_11; rv:11.0) like Gecko': Unsupported with Accept-Encoding header === 2016-01-15 14:35:02,385 [6-24] INFO Download - done streaming: C:/Users/aa82923/DEV/eclipse/SandBox/builtinds/war/builtinds/sc/system/development/ISC_ServerLogViewer.js === 2016-01-15 14:35:02,385 [6-24] INFO Compression - /builtinds/sc/system/development/ISC_ServerLogViewer.js: 7713 -> 3122 bytes