=== 2015-09-21 21:19:56,238 [80-2] INFO  RequestContext - URL: '/tools/visualBuilder/vbOperations.jsp', User-Agent: 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.152 Safari/537.36': Safari with Accept-Encoding header
=== 2015-09-21 21:19:56,269 [80-2] DEBUG XML - Parsed XML from (in memory stream): 1ms
=== 2015-09-21 21:19:56,272 [80-2] DEBUG XML - Parsed XML from /tank0/SmartClient10/SmartClient_SNAPSHOT_v101d_2015-06-02_Pro/smartclientSDK/isomorphic/system/schema/List.ds.xml: 1ms
=== 2015-09-21 21:19:56,275 [80-2] DEBUG RPCManager - Processing 1 requests.
=== 2015-09-21 21:19:56,294 [80-2] DEBUG XML - Parsed XML from /tank0/SmartClient10/SmartClient_SNAPSHOT_v101d_2015-06-02_Pro/smartclientSDK/tools/selenium/STDNT_GRAD_APPLICANTS.ds.xml: 4ms
=== 2015-09-21 21:19:56,398 [80-2] DEBUG SQLDataSource - DataSource 76 acquired SQLDriver instance 419018211 during initialization
=== 2015-09-21 21:19:56,400 [80-2] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
    },
    operationConfig:{
        dataSource:"STDNT_GRAD_APPLICANTS",
        repo:null,
        operationType:"fetch",
        textMatchStyle:"exact"
    },
    startRow:0,
    endRow:75,
    componentId:"ListGrid3",
    appID:"builtinApplication",
    operation:"STDNT_GRAD_APPLICANTS_fetch",
    oldValues:{
    }
}
=== 2015-09-21 21:19:56,405 [80-2] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2015-09-21 21:19:56,405 [80-2] DEBUG DeclarativeSecurity - DataSource STDNT_GRAD_APPLICANTS is not in the pre-checked list, processing...
=== 2015-09-21 21:19:56,418 [80-2] DEBUG AppBase - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] No userTypes defined, allowing anyone access to all operations for this application
=== 2015-09-21 21:19:56,418 [80-2] DEBUG AppBase - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] No public zero-argument method named '_STDNT_GRAD_APPLICANTS_fetch' found, performing generic datasource operation
=== 2015-09-21 21:19:56,419 [80-2] INFO  SQLDataSource - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Performing fetch operation with
	criteria: {}	values: {}
=== 2015-09-21 21:19:56,429 [80-2] INFO  SQLWhereClause - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] empty condition
=== 2015-09-21 21:19:56,430 [80-2] INFO  SQLDataSource - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
=== 2015-09-21 21:19:56,431 [80-2] INFO  Velocity - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Velocity Tools not available - using standard Velocity Contexts.
=== 2015-09-21 21:19:56,437 [80-2] DEBUG Velocity - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Velocity config: {
}
=== 2015-09-21 21:19:56,465 [80-2] DEBUG Velocity - Log4JLogChute using logger 'org.apache.Velocity'
=== 2015-09-21 21:19:56,465 [80-2] DEBUG Velocity - Initializing Velocity, Calling init()...
=== 2015-09-21 21:19:56,466 [80-2] DEBUG Velocity - Starting Apache Velocity v1.7 (compiled: 2010-11-19 12:14:37)
=== 2015-09-21 21:19:56,466 [80-2] DEBUG Velocity - Default Properties File: org/apache/velocity/runtime/defaults/velocity.properties
=== 2015-09-21 21:19:56,466 [80-2] DEBUG Velocity - Trying to use logger class org.apache.velocity.runtime.log.Log4JLogChute
=== 2015-09-21 21:19:56,466 [80-2] DEBUG Velocity - Using logger class org.apache.velocity.runtime.log.Log4JLogChute
=== 2015-09-21 21:19:56,471 [80-2] DEBUG Velocity - ResourceLoader instantiated: org.apache.velocity.runtime.resource.loader.FileResourceLoader
=== 2015-09-21 21:19:56,472 [80-2] DEBUG Velocity - Do unicode file recognition:  false
=== 2015-09-21 21:19:56,472 [80-2] DEBUG Velocity - FileResourceLoader : adding path ''
=== 2015-09-21 21:19:56,472 [80-2] DEBUG Velocity - ResourceCache: initialized (class org.apache.velocity.runtime.resource.ResourceCacheImpl) with class java.util.Collections$SynchronizedMap cache map.
=== 2015-09-21 21:19:56,474 [80-2] DEBUG Velocity - Loaded System Directive: org.apache.velocity.runtime.directive.Stop
=== 2015-09-21 21:19:56,475 [80-2] DEBUG Velocity - Loaded System Directive: org.apache.velocity.runtime.directive.Define
=== 2015-09-21 21:19:56,476 [80-2] DEBUG Velocity - Loaded System Directive: org.apache.velocity.runtime.directive.Break
=== 2015-09-21 21:19:56,476 [80-2] DEBUG Velocity - Loaded System Directive: org.apache.velocity.runtime.directive.Evaluate
=== 2015-09-21 21:19:56,477 [80-2] DEBUG Velocity - Loaded System Directive: org.apache.velocity.runtime.directive.Literal
=== 2015-09-21 21:19:56,478 [80-2] DEBUG Velocity - Loaded System Directive: org.apache.velocity.runtime.directive.Macro
=== 2015-09-21 21:19:56,480 [80-2] DEBUG Velocity - Loaded System Directive: org.apache.velocity.runtime.directive.Parse
=== 2015-09-21 21:19:56,481 [80-2] DEBUG Velocity - Loaded System Directive: org.apache.velocity.runtime.directive.Include
=== 2015-09-21 21:19:56,482 [80-2] DEBUG Velocity - Loaded System Directive: org.apache.velocity.runtime.directive.Foreach
=== 2015-09-21 21:19:56,512 [80-2] DEBUG Velocity - Created '20' parsers.
=== 2015-09-21 21:19:56,519 [80-2] DEBUG Velocity - Velocimacro : "velocimacro.library" is not set.  Trying default library: VM_global_library.vm
=== 2015-09-21 21:19:56,519 [80-2] DEBUG Velocity - Velocimacro : Default library not found.
=== 2015-09-21 21:19:56,519 [80-2] DEBUG Velocity - Velocimacro : allowInline = true : VMs can be defined inline in templates
=== 2015-09-21 21:19:56,519 [80-2] DEBUG Velocity - Velocimacro : allowInlineToOverride = false : VMs defined inline may NOT replace previous VM definitions
=== 2015-09-21 21:19:56,519 [80-2] DEBUG Velocity - Velocimacro : allowInlineLocal = false : VMs defined inline will be global in scope if allowed.
=== 2015-09-21 21:19:56,519 [80-2] DEBUG Velocity - Velocimacro : autoload off : VM system will not automatically reload global library macros
=== 2015-09-21 21:19:56,528 [80-2] DEBUG SQLDataSource - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Executing row count query: SELECT COUNT(*) FROM $defaultTableClause WHERE $defaultWhereClause
=== 2015-09-21 21:19:56,529 [80-2] DEBUG SQLDataSource - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Eval'd row count query: SELECT COUNT(*) FROM STDNT_GRAD_APPLICANTS WHERE ('1'='1')
=== 2015-09-21 21:19:56,565 [80-2] INFO  PoolManager - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] SmartClient pooling started for 'INFO_ACCESS' objects
=== 2015-09-21 21:19:56,565 [80-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Initializing SQL config for 'INFO_ACCESS' from system config - using DataSource:  oracle.jdbc.pool.OracleDataSource
=== 2015-09-21 21:19:56,595 [80-2] INFO  DataTools - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] setProperties: couldn't set:
{
    context:"No such property"
}
=== 2015-09-21 21:19:56,996 [80-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] makeObject() created a pooled Connection '466877379'
=== 2015-09-21 21:19:57,037 [80-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Executing pingTest 'select 1 from dual' on connection 466877379
=== 2015-09-21 21:19:57,050 [80-2] DEBUG SQLConnectionManager - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Borrowed connection '466877379'
=== 2015-09-21 21:19:57,050 [80-2] INFO  SQLDriver - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Executing SQL query on 'INFO_ACCESS' using connection '466877379': SELECT COUNT(*) FROM STDNT_GRAD_APPLICANTS WHERE ('1'='1')
=== 2015-09-21 21:19:57,055 [80-2] INFO  SQLDriver - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Execute of select: SELECT COUNT(*) FROM STDNT_GRAD_APPLICANTS WHERE ('1'='1') on db: INFO_ACCESS threw exception: java.sql.SQLSyntaxErrorException: ORA-00942: table or view does not exist
 - assuming stale connection and retrying query.
=== 2015-09-21 21:19:57,055 [80-2] DEBUG SQLConnectionManager - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] About to close connection with hashcode "466877379"
=== 2015-09-21 21:19:57,055 [80-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Executing pingTest 'select 1 from dual' on connection 466877379
=== 2015-09-21 21:19:57,059 [80-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Passivating connection '466877379
=== 2015-09-21 21:19:57,060 [80-2] DEBUG SQLConnectionManager - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] Really closing and invalidating PoolableConnection with hashcode "466877379"
=== 2015-09-21 21:19:57,286 [80-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.STDNT_GRAD_APPLICANTS_fetch] makeObject() created a pooled Connection '586220251'
=== 2015-09-21 21:19:57,290 [80-2] WARN  RequestContext - Content type has already been set to: text/html - setting to: text/plain; charset=UTF-8
=== 2015-09-21 21:19:57,290 [80-2] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2015-09-21 21:19:57,290 [80-2] DEBUG RPCManager - non-DMI response, dropExtraFields: false
=== 2015-09-21 21:19:57,292 [80-2] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 76
=== 2015-09-21 21:19:57,292 [80-2] DEBUG SQLDriver - Freeing SQLDriver dbConnection 586220251 for SQLDriver instance 419018211
=== 2015-09-21 21:19:57,292 [80-2] DEBUG SQLConnectionManager - About to close connection with hashcode "586220251"
=== 2015-09-21 21:19:57,293 [80-2] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 586220251
=== 2015-09-21 21:19:57,294 [80-2] DEBUG PoolableSQLConnectionFactory - Passivating connection '586220251
=== 2015-09-21 21:19:57,294 [80-2] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 76
=== 2015-09-21 21:19:57,294 [80-2] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 76