Dez 19, 2011 2:59:45 PM org.apache.catalina.core.AprLifecycleListener init
Information: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: C:\Program Files\Java\jre7\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\Program Files\Common Files\Microsoft Shared\Windows Live;C:\Program Files (x86)\Common Files\Microsoft Shared\Windows Live;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files\ThinkPad\Bluetooth Software\;C:\Program Files\ThinkPad\Bluetooth Software\syswow64;C:\Program Files\Broadcom\WHL\;C:\Program Files\Broadcom\WHL\syswow64;C:\Program Files\Broadcom\WHL\SysWow64\;C:\Program Files\Broadcom\WHL\SysWow64\syswow64;C:\Program Files\Intel\WiFi\bin\;C:\Program Files\Common Files\Intel\WirelessCommon\;C:\Program Files (x86)\Common Files\Lenovo;C:\Program Files (x86)\Common Files\Ulead Systems\MPEG;C:\Program Files (x86)\Windows Live\Shared;C:\SWTOOLS\ReadyApps;C:\Program Files (x86)\Lenovo\Access Connections\;C:\frameworks\ant\bin;.
Dez 19, 2011 2:59:45 PM org.apache.coyote.AbstractProtocol init
Information: Initializing ProtocolHandler ["http-bio-8080"]
Dez 19, 2011 2:59:45 PM org.apache.coyote.AbstractProtocol init
Information: Initializing ProtocolHandler ["ajp-bio-8009"]
Dez 19, 2011 2:59:45 PM org.apache.catalina.startup.Catalina load
Information: Initialization processed in 627 ms
Dez 19, 2011 2:59:45 PM org.apache.catalina.core.StandardService startInternal
Information: Starting service Catalina
Dez 19, 2011 2:59:45 PM org.apache.catalina.core.StandardEngine startInternal
Information: Starting Servlet Engine: Apache Tomcat/7.0.22
Dez 19, 2011 2:59:45 PM org.apache.catalina.startup.HostConfig deployDirectory
Information: Deploying web application directory camtool
Dez 19, 2011 2:59:46 PM org.apache.catalina.core.ApplicationContext log
Information: Initializing Spring root WebApplicationContext
AbandonedObjectPool is used (org.apache.commons.dbcp.AbandonedObjectPool@7c9b2f35)
   LogAbandoned: false
   RemoveAbandoned: true
   RemoveAbandonedTimeout: 60
Dez 19, 2011 2:59:48 PM org.activiti.engine.impl.ProcessEngineImpl <init>
Information: ProcessEngine default created
Dez 19, 2011 2:59:48 PM org.activiti.engine.impl.jobexecutor.JobAcquisitionThread run
Information: JobAcquisitionThread starting to acquire jobs
ISC: Configuring log4j from: file:/C:/apache-tomcat-7.0.22/webapps/camtool/WEB-INF/classes/log4j.isc.config.xml
=== 2011-12-19 14:59:48,856 [ad-1] INFO  ISCInit - Isomorphic SmartClient Framework - Initializing
=== 2011-12-19 14:59:48,861 [ad-1] INFO  ConfigLoader - Attempting to load framework.properties from CLASSPATH
=== 2011-12-19 14:59:48,985 [ad-1] INFO  ConfigLoader - Successfully loaded framework.properties from CLASSPATH at location: jar:file:/C:/apache-tomcat-7.0.22/webapps/camtool/WEB-INF/lib/isomorphic_core_rpc.jar!/framework.properties
=== 2011-12-19 14:59:48,985 [ad-1] INFO  ConfigLoader - Attempting to load project.properties from CLASSPATH
=== 2011-12-19 14:59:48,986 [ad-1] INFO  ConfigLoader - Unable to locate project.properties in CLASSPATH
=== 2011-12-19 14:59:48,989 [ad-1] INFO  ConfigLoader - Successfully loaded isc_interfaces.properties from CLASSPATH at location: jar:file:/C:/apache-tomcat-7.0.22/webapps/camtool/WEB-INF/lib/isomorphic_core_rpc.jar!/isc_interfaces.properties
=== 2011-12-19 14:59:48,989 [ad-1] INFO  ConfigLoader - Attempting to load server.properties from CLASSPATH
=== 2011-12-19 14:59:48,991 [ad-1] INFO  ConfigLoader - Successfully loaded server.properties from CLASSPATH at location: file:/C:/apache-tomcat-7.0.22/webapps/camtool/WEB-INF/classes/server.properties
=== 2011-12-19 14:59:48,997 [ad-1] INFO  Logger - Logging system started.
=== 2011-12-19 14:59:48,997 [ad-1] INFO  ISCInit - Isomorphic SmartClient Framework (SC_SNAPSHOT-2011-12-15/EVAL Deployment 2011-12-15) - Initialization Complete
=== 2011-12-19 14:59:48,999 [ad-1] INFO  ISCInit - Auto-detected webRoot - using: C:\apache-tomcat-7.0.22\webapps\camtool
Dez 19, 2011 2:59:49 PM org.apache.catalina.core.ApplicationContext log
Information: Initializing Spring FrameworkServlet 'spring'
Dez 19, 2011 2:59:49 PM org.apache.catalina.startup.HostConfig deployDirectory
Information: Deploying web application directory docs
Dez 19, 2011 2:59:49 PM org.apache.catalina.startup.HostConfig deployDirectory
Information: Deploying web application directory examples
Dez 19, 2011 2:59:49 PM org.apache.catalina.core.ApplicationContext log
Information: ContextListener: contextInitialized()
Dez 19, 2011 2:59:49 PM org.apache.catalina.core.ApplicationContext log
Information: SessionListener: contextInitialized()
Dez 19, 2011 2:59:49 PM org.apache.catalina.core.ApplicationContext log
Information: ContextListener: attributeAdded('org.apache.jasper.compiler.TldLocationsCache', 'org.apache.jasper.compiler.TldLocationsCache@566ab457')
Dez 19, 2011 2:59:49 PM org.apache.catalina.startup.HostConfig deployDirectory
Information: Deploying web application directory host-manager
Dez 19, 2011 2:59:49 PM org.apache.catalina.startup.HostConfig deployDirectory
Information: Deploying web application directory manager
Dez 19, 2011 2:59:49 PM org.apache.catalina.startup.HostConfig deployDirectory
Information: Deploying web application directory ROOT
Dez 19, 2011 2:59:49 PM org.apache.coyote.AbstractProtocol start
Information: Starting ProtocolHandler ["http-bio-8080"]
Dez 19, 2011 2:59:49 PM org.apache.coyote.AbstractProtocol start
Information: Starting ProtocolHandler ["ajp-bio-8009"]
Dez 19, 2011 2:59:49 PM org.apache.catalina.startup.Catalina start
Information: Server startup in 3901 ms
=== 2011-12-19 14:59:59,848 [ec-5] INFO  RequestContext - URL: '/camtool/camtool/sc/DataSourceLoader', User-Agent: 'Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; Win64; x64; Trident/5.0; .NET CLR 2.0.50727; SLCC2; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; InfoPath.3)': MSIE with Accept-Encoding header, ready for compressed JS
=== 2011-12-19 14:59:59,857 [ec-5] INFO  DBConnectionManager - Registered JDBC driver net.sourceforge.jtds.jdbc.Driver
=== 2011-12-19 14:59:59,858 [ec-5] INFO  DBConnectionManager - Initialized db pool 
=== 2011-12-19 14:59:59,859 [c-10] INFO  Download - Returning 304: Not modified on conditional get of: C:\apache-tomcat-7.0.22\webapps\camtool\camtool\sc\skins\Enterprise\load_skin.js
=== 2011-12-19 14:59:59,867 [ec-5] DEBUG DBConnectionManager - Created a new connection
=== 2011-12-19 14:59:59,918 [ec-5] DEBUG XML - Parsed XML from C:\apache-tomcat-7.0.22\webapps\camtool\camtool\sc\system\schema\builtinTypes.xml: 5ms
=== 2011-12-19 14:59:59,936 [ec-5] INFO  PoolManager - SmartClient pooling disabled for 'simpleTypes' objects
=== 2011-12-19 14:59:59,985 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 2ms
=== 2011-12-19 14:59:59,989 [ec-5] DEBUG XML - Parsed XML from C:\apache-tomcat-7.0.22\webapps\camtool\camtool\sc\system\schema\DataSource.ds.xml: 3ms
=== 2011-12-19 15:00:00,055 [ec-5] DEBUG XML - Parsed XML from C:\apache-tomcat-7.0.22\webapps\camtool\camtool\sc\system\schema\DataSourceField.ds.xml: 3ms
=== 2011-12-19 15:00:00,083 [ec-5] DEBUG XML - Parsed XML from C:\apache-tomcat-7.0.22\webapps\camtool\camtool\sc\system\schema\OperationBinding.ds.xml: 2ms
=== 2011-12-19 15:00:00,104 [ec-7] INFO  Download - Returning 304: Not modified on conditional get of: C:\apache-tomcat-7.0.22\webapps\camtool\camtool\sc\skins\Enterprise\skin_styles.css
=== 2011-12-19 15:00:00,145 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 1ms
=== 2011-12-19 15:00:00,160 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 1ms
=== 2011-12-19 15:00:00,168 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 0ms
=== 2011-12-19 15:00:00,180 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 1ms
=== 2011-12-19 15:00:00,188 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 1ms
=== 2011-12-19 15:00:00,197 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 1ms
=== 2011-12-19 15:00:00,206 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 1ms
=== 2011-12-19 15:00:00,216 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 1ms
=== 2011-12-19 15:00:00,226 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 2ms
=== 2011-12-19 15:00:00,235 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 1ms
=== 2011-12-19 15:00:00,243 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 1ms
=== 2011-12-19 15:00:00,247 [ec-5] DEBUG XML - Parsed XML from C:\apache-tomcat-7.0.22\webapps\camtool\camtool\sc\system\schema\ServerObject.ds.xml: 1ms
=== 2011-12-19 15:00:05,450 [ec-6] INFO  RequestContext - URL: '/camtool/LoginServlet', User-Agent: 'Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; Win64; x64; Trident/5.0; .NET CLR 2.0.50727; SLCC2; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; InfoPath.3)': MSIE with Accept-Encoding header, ready for compressed JS
=== 2011-12-19 15:00:05,675 [ec-8] INFO  RequestContext - URL: '/camtool/camtool/security.rpc', User-Agent: 'Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; Win64; x64; Trident/5.0; .NET CLR 2.0.50727; SLCC2; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; InfoPath.3)': MSIE with Accept-Encoding header, ready for compressed JS
AbandonedObjectPool is used (org.apache.commons.dbcp.AbandonedObjectPool@fe523c0)
   LogAbandoned: false
   RemoveAbandoned: true
   RemoveAbandonedTimeout: 60
=== 2011-12-19 15:00:28,729 [ec-2] INFO  RequestContext - URL: '/camtool/camtool/sc/IDACall', User-Agent: 'Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; Win64; x64; Trident/5.0; .NET CLR 2.0.50727; SLCC2; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; InfoPath.3)': MSIE with Accept-Encoding header, ready for compressed JS
=== 2011-12-19 15:00:28,835 [ec-1] INFO  RequestContext - URL: '/camtool/camtool/sc/IDACall', User-Agent: 'Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; Win64; x64; Trident/5.0; .NET CLR 2.0.50727; SLCC2; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; InfoPath.3)': MSIE with Accept-Encoding header, ready for compressed JS
=== 2011-12-19 15:00:28,938 [ec-2] DEBUG XML - Parsed XML from (in memory stream): 2ms
=== 2011-12-19 15:00:28,938 [ec-1] DEBUG XML - Parsed XML from (in memory stream): 2ms
=== 2011-12-19 15:00:28,941 [ec-2] DEBUG XML - Parsed XML from C:\apache-tomcat-7.0.22\webapps\camtool\camtool\sc\system\schema\List.ds.xml: 1ms
=== 2011-12-19 15:00:28,941 [ec-1] DEBUG XML - Parsed XML from C:\apache-tomcat-7.0.22\webapps\camtool\camtool\sc\system\schema\List.ds.xml: 1ms
=== 2011-12-19 15:00:28,947 [ec-1] DEBUG RPCManager - Processing 1 requests.
=== 2011-12-19 15:00:28,948 [ec-2] DEBUG RPCManager - Processing 1 requests.
=== 2011-12-19 15:00:28,959 [ec-1] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
    },
    operationConfig:{
        dataSource:"tbSecApplication",
        operationType:"fetch",
        textMatchStyle:"substring"
    },
    startRow:0,
    endRow:75,
    componentId:"isc_ListGrid_2",
    appID:"builtinApplication",
    operation:"tbSecApplication_fetch",
    oldValues:{
    }
}
=== 2011-12-19 15:00:28,959 [ec-2] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
    },
    operationConfig:{
        dataSource:"tbSecRole",
        operationType:"fetch",
        textMatchStyle:"substring"
    },
    startRow:0,
    endRow:75,
    componentId:"isc_ListGrid_0",
    appID:"builtinApplication",
    operation:"tbSecRole_fetch",
    oldValues:{
    }
}
=== 2011-12-19 15:00:28,965 [ec-1] WARN  Velocity - DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:00:28,965 [ec-2] WARN  Velocity - DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:00:28,965 [ec-1] WARN  Velocity - DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:00:28,965 [ec-2] WARN  Velocity - DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:00:28,965 [ec-2] WARN  Velocity - DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:00:28,970 [ec-2] DEBUG AppBase - [builtinApplication.tbSecRole_fetch] No userTypes defined, allowing anyone access to all operations for this application
=== 2011-12-19 15:00:28,970 [ec-1] DEBUG AppBase - [builtinApplication.tbSecApplication_fetch] No userTypes defined, allowing anyone access to all operations for this application
=== 2011-12-19 15:00:28,970 [ec-2] DEBUG AppBase - [builtinApplication.tbSecRole_fetch] No public zero-argument method named '_tbSecRole_fetch' found, performing generic datasource operation
=== 2011-12-19 15:00:28,970 [ec-1] DEBUG AppBase - [builtinApplication.tbSecApplication_fetch] No public zero-argument method named '_tbSecApplication_fetch' found, performing generic datasource operation
=== 2011-12-19 15:00:28,971 [ec-2] INFO  SQLDataSource - [builtinApplication.tbSecRole_fetch] Performing fetch operation with
	criteria: {}	values: {}
=== 2011-12-19 15:00:28,971 [ec-1] INFO  SQLDataSource - [builtinApplication.tbSecApplication_fetch] Performing fetch operation with
	criteria: {}	values: {}
=== 2011-12-19 15:00:28,978 [ec-2] INFO  SQLWhereClause - [builtinApplication.tbSecRole_fetch] empty condition
=== 2011-12-19 15:00:28,978 [ec-1] INFO  SQLWhereClause - [builtinApplication.tbSecApplication_fetch] empty condition
=== 2011-12-19 15:00:28,979 [ec-1] WARN  Velocity - [builtinApplication.tbSecApplication_fetch] DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:00:28,979 [ec-2] WARN  Velocity - [builtinApplication.tbSecRole_fetch] DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:00:28,979 [ec-2] INFO  SQLDataSource - [builtinApplication.tbSecRole_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause AND $defaultJoinWhereClause
=== 2011-12-19 15:00:28,979 [ec-1] INFO  SQLDataSource - [builtinApplication.tbSecApplication_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
=== 2011-12-19 15:00:29,086 [ec-2] DEBUG SQLDataSource - [builtinApplication.tbSecRole_fetch] Executing row count query: SELECT COUNT(*) FROM $defaultTableClause WHERE $defaultWhereClause
=== 2011-12-19 15:00:29,086 [ec-1] DEBUG SQLDataSource - [builtinApplication.tbSecApplication_fetch] Executing row count query: SELECT COUNT(*) FROM $defaultTableClause WHERE $defaultWhereClause
=== 2011-12-19 15:00:29,086 [ec-2] DEBUG SQLDataSource - [builtinApplication.tbSecRole_fetch] Eval'd row count query: SELECT COUNT(*) FROM dbo.tbSecRole, dbo.tbSecUser WHERE ('1'='1')
=== 2011-12-19 15:00:29,086 [ec-1] DEBUG SQLDataSource - [builtinApplication.tbSecApplication_fetch] Eval'd row count query: SELECT COUNT(*) FROM dbo.tbSecApplication WHERE ('1'='1')
=== 2011-12-19 15:00:29,111 [ec-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_fetch] Initializing SQL config for 'CamSecurity' from system config - using DriverManager:  net.sourceforge.jtds.jdbc.Driver
=== 2011-12-19 15:00:29,111 [ec-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_fetch] net.sourceforge.jtds.jdbc.Driver lookup successful
=== 2011-12-19 15:00:29,111 [ec-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_fetch] DriverManager fetching connection for CamSecurity via jdbc url
=== 2011-12-19 15:00:29,111 [ec-1] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecApplication_fetch] DriverManager fetching connection for CamSecurity via jdbc url 
=== 2011-12-19 15:00:29,111 [ec-1] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecApplication_fetch] Passing JDBC URL only to getConnection
=== 2011-12-19 15:00:29,111 [ec-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_fetch] Passing JDBC URL only to getConnection
=== 2011-12-19 15:00:29,124 [ec-1] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecApplication_fetch] Returning pooled Connection
=== 2011-12-19 15:00:29,124 [ec-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_fetch] Returning pooled Connection
=== 2011-12-19 15:00:29,124 [ec-1] INFO  SQLDriver - [builtinApplication.tbSecApplication_fetch] Executing SQL query on 'CamSecurity': SELECT COUNT(*) FROM dbo.tbSecApplication WHERE ('1'='1')
=== 2011-12-19 15:00:29,125 [ec-2] INFO  SQLDriver - [builtinApplication.tbSecRole_fetch] Executing SQL query on 'CamSecurity': SELECT COUNT(*) FROM dbo.tbSecRole, dbo.tbSecUser WHERE ('1'='1')
=== 2011-12-19 15:00:29,131 [ec-2] DEBUG SQLServerDriver - [builtinApplication.tbSecRole_fetch] SQL Server version is '10.50.2500'
=== 2011-12-19 15:00:29,131 [ec-1] DEBUG SQLServerDriver - [builtinApplication.tbSecApplication_fetch] SQL Server version is '10.50.2500'
=== 2011-12-19 15:00:29,131 [ec-2] DEBUG SQLDataSource - [builtinApplication.tbSecRole_fetch] Using SQL Limit query
=== 2011-12-19 15:00:29,131 [ec-1] DEBUG SQLDataSource - [builtinApplication.tbSecApplication_fetch] Using SQL Limit query
=== 2011-12-19 15:00:29,132 [ec-1] DEBUG SQLDataSource - [builtinApplication.tbSecApplication_fetch] Using PK as default sorter: ApplicationID
=== 2011-12-19 15:00:29,132 [ec-2] DEBUG SQLDataSource - [builtinApplication.tbSecRole_fetch] Using PK as default sorter: RoleID
=== 2011-12-19 15:00:29,132 [ec-1] DEBUG SQLDataSource - [builtinApplication.tbSecApplication_fetch] SQL windowed select rows 0->75, result size 75. Query: SELECT * FROM (SELECT *, ROW_NUMBER() OVER (ORDER BY x.ApplicationID) AS rowID FROM (SELECT TOP 100 PERCENT  tbSecApplication.Application, tbSecApplication.ApplicationID, tbSecApplication.ClassName, tbSecApplication.Description, tbSecApplication.Flag, tbSecApplication.ParentID FROM dbo.tbSecApplication WHERE ('1'='1')) x) y WHERE y.rowID BETWEEN 1 AND 75
=== 2011-12-19 15:00:29,132 [ec-2] DEBUG SQLDataSource - [builtinApplication.tbSecRole_fetch] SQL windowed select rows 0->75, result size 75. Query: SELECT * FROM (SELECT *, ROW_NUMBER() OVER (ORDER BY x.RoleID) AS rowID FROM (SELECT TOP 100 PERCENT  tbSecRole.CreatedBy, tbSecRole.CreationDate, tbSecRole.Description, tbSecRole.Flag, tbSecRole.LastModifiedTime, tbSecRole.ModifiedBy, tbSecRole.Role, tbSecRole.RoleID, tbSecUser.UserName FROM dbo.tbSecRole, dbo.tbSecUser WHERE ('1'='1') AND tbSecUser.UserID = tbSecRole.CreatedBy) x) y WHERE y.rowID BETWEEN 1 AND 75
=== 2011-12-19 15:00:29,132 [ec-1] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecApplication_fetch] DriverManager fetching connection for CamSecurity via jdbc url 
=== 2011-12-19 15:00:29,132 [ec-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_fetch] DriverManager fetching connection for CamSecurity via jdbc url 
=== 2011-12-19 15:00:29,132 [ec-1] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecApplication_fetch] Passing JDBC URL only to getConnection
=== 2011-12-19 15:00:29,132 [ec-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_fetch] Passing JDBC URL only to getConnection
=== 2011-12-19 15:00:29,145 [ec-2] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_fetch] Returning pooled Connection
=== 2011-12-19 15:00:29,145 [ec-1] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecApplication_fetch] Returning pooled Connection
=== 2011-12-19 15:00:29,150 [ec-1] INFO  DSResponse - [builtinApplication.tbSecApplication_fetch] DSResponse: List with 4 items
=== 2011-12-19 15:00:29,151 [ec-2] INFO  DSResponse - [builtinApplication.tbSecRole_fetch] DSResponse: List with 3 items
=== 2011-12-19 15:00:29,151 [ec-2] WARN  DSRequest - SmartClient/SmartGWT Server does not currently support sort or filter on fields from non-SQL DataSources when performing paged fetches. If you need to sort or filter on these fields, use a basic fetch (ie, do not specify endRow), but be aware that this may drastically affect performance.  The following fields have been dropped from the specified criteria: null
=== 2011-12-19 15:00:29,151 [ec-1] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2011-12-19 15:00:29,151 [ec-2] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2011-12-19 15:00:29,152 [ec-2] DEBUG RPCManager - non-DMI response, dropExtraFields: false
=== 2011-12-19 15:00:29,152 [ec-1] DEBUG RPCManager - non-DMI response, dropExtraFields: false
=== 2011-12-19 15:00:29,156 [ec-2] INFO  Compression - /camtool/camtool/sc/IDACall: 942 -> 500 bytes
=== 2011-12-19 15:00:29,156 [ec-1] INFO  Compression - /camtool/camtool/sc/IDACall: 622 -> 286 bytes
=== 2011-12-19 15:01:02,290 [ec-5] INFO  RequestContext - URL: '/camtool/camtool/sc/IDACall', User-Agent: 'Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; Win64; x64; Trident/5.0; .NET CLR 2.0.50727; SLCC2; .NET CLR 3.5.30729; .NET CLR 3.0.30729; Media Center PC 6.0; .NET4.0C; InfoPath.3)': MSIE with Accept-Encoding header, ready for compressed JS
=== 2011-12-19 15:01:02,411 [ec-5] DEBUG XML - Parsed XML from (in memory stream): 5ms
=== 2011-12-19 15:01:02,415 [ec-5] DEBUG RPCManager - Processing 1 requests.
=== 2011-12-19 15:01:02,416 [ec-5] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    values:{
        UserName:"ldap_camtool",
        Role:"test",
        Description:"test"
    },
    operationConfig:{
        dataSource:"tbSecRole",
        operationType:"add"
    },
    componentId:"isc_ListGrid_0",
    appID:"builtinApplication",
    operation:"tbSecRole_add",
    oldValues:{
        UserName:"ldap_camtool",
        Role:"test",
        Description:"test"
    },
    criteria:{
    }
}
=== 2011-12-19 15:01:02,416 [ec-5] WARN  Velocity - DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:01:02,416 [ec-5] WARN  Velocity - DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:01:02,416 [ec-5] WARN  Velocity - DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:01:02,417 [ec-5] DEBUG AppBase - [builtinApplication.tbSecRole_add] No userTypes defined, allowing anyone access to all operations for this application
=== 2011-12-19 15:01:02,418 [ec-5] DEBUG AppBase - [builtinApplication.tbSecRole_add] No public zero-argument method named '_tbSecRole_add' found, performing generic datasource operation
=== 2011-12-19 15:01:02,418 [ec-5] INFO  SQLDataSource - [builtinApplication.tbSecRole_add] Performing add operation with
	criteria: {UserName:"ldap_camtool",Role:"test",Description:"test",CreatedBy:"3"}	values: {UserName:"ldap_camtool",Role:"test",Description:"test",CreatedBy:3}
=== 2011-12-19 15:01:02,421 [ec-5] DEBUG SQLValuesClause - [builtinApplication.tbSecRole_add] Sequences: {}
=== 2011-12-19 15:01:02,425 [ec-5] WARN  Velocity - [builtinApplication.tbSecRole_add] DSRequest-specified a template context variable: userId collides with derived key of the same name - using the DSRequest-specified value.
=== 2011-12-19 15:01:02,426 [ec-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_add] DriverManager fetching connection for CamSecurity via jdbc url 
=== 2011-12-19 15:01:02,426 [ec-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_add] Passing JDBC URL only to getConnection
=== 2011-12-19 15:01:02,441 [ec-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_add] Returning pooled Connection
=== 2011-12-19 15:01:02,441 [ec-5] INFO  SQLDriver - [builtinApplication.tbSecRole_add] Executing SQL update on 'CamSecurity': INSERT INTO dbo.tbSecRole (CreatedBy, Description, Role, UserName) VALUES (3, 'test', 'test', 'ldap_camtool')
=== 2011-12-19 15:01:02,449 [ec-5] INFO  SQLDriver - [builtinApplication.tbSecRole_add] Execute of update: INSERT INTO dbo.tbSecRole (CreatedBy, Description, Role, UserName) VALUES (3, 'test', 'test', 'ldap_camtool') on db: CamSecurity threw exception: java.sql.SQLException: Invalid column name 'UserName'. - assuming stale connection and retrying update.
=== 2011-12-19 15:01:02,449 [ec-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_add] DriverManager fetching connection for CamSecurity via jdbc url 
=== 2011-12-19 15:01:02,449 [ec-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_add] Passing JDBC URL only to getConnection
=== 2011-12-19 15:01:02,459 [ec-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.tbSecRole_add] Returning pooled Connection
=== 2011-12-19 15:01:02,467 [ec-5] WARN  RequestContext - dsRequest.execute() failed: 
java.sql.SQLException: Invalid column name 'UserName'.
	at net.sourceforge.jtds.jdbc.SQLDiagnostic.addDiagnostic(SQLDiagnostic.java:368)
	at net.sourceforge.jtds.jdbc.TdsCore.tdsErrorToken(TdsCore.java:2820)
	at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2258)
	at net.sourceforge.jtds.jdbc.TdsCore.getMoreResults(TdsCore.java:632)
	at net.sourceforge.jtds.jdbc.JtdsStatement.processResults(JtdsStatement.java:584)
	at net.sourceforge.jtds.jdbc.JtdsStatement.executeSQL(JtdsStatement.java:546)
	at net.sourceforge.jtds.jdbc.JtdsPreparedStatement.executeUpdate(JtdsPreparedStatement.java:504)
	at org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:102)
	at com.isomorphic.sql.SQLDriver.doUpdate(SQLDriver.java:528)
	at com.isomorphic.sql.SQLDriver.update(SQLDriver.java:493)
	at com.isomorphic.sql.SQLDriver.executeUpdate(SQLDriver.java:602)
	at com.isomorphic.sql.SQLDataSource.executeNativeUpdate(SQLDataSource.java:403)
	at com.isomorphic.sql.SQLDataSource.SQLExecute(SQLDataSource.java:1368)
	at com.isomorphic.sql.SQLDataSource.processRequest(SQLDataSource.java:293)
	at com.isomorphic.sql.SQLDataSource.executeAdd(SQLDataSource.java:245)
	at com.isomorphic.datasource.DataSource.execute(DataSource.java:1293)
	at com.isomorphic.application.AppBase.executeDefaultDSOperation(AppBase.java:721)
	at com.isomorphic.application.AppBase.executeAppOperation(AppBase.java:658)
	at com.isomorphic.application.AppBase.execute(AppBase.java:491)
	at com.isomorphic.datasource.DSRequest.execute(DSRequest.java:1948)
	at com.ascom.camtool.gwt.server.security.SecureIDACall.handleDSRequest(SecureIDACall.java:131)
	at com.isomorphic.servlet.IDACall.processRPCTransaction(IDACall.java:156)
	at com.isomorphic.servlet.IDACall.processRequest(IDACall.java:121)
	at com.ascom.camtool.gwt.server.security.SecureIDACall.processRequest(SecureIDACall.java:101)
	at com.isomorphic.servlet.IDACall.doPost(IDACall.java:73)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:641)
	at com.isomorphic.servlet.BaseServlet.service(BaseServlet.java:152)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:304)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
	at com.isomorphic.servlet.CompressionFilter.doFilter(CompressionFilter.java:259)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:224)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:169)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:581)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:405)
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:964)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:515)
	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:302)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
=== 2011-12-19 15:01:02,468 [ec-5] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2011-12-19 15:01:02,471 [ec-5] DEBUG RPCManager - non-DMI response, dropExtraFields: false
=== 2011-12-19 15:01:02,472 [ec-5] INFO  Compression - /camtool/camtool/sc/IDACall: 152 -> 139 bytes