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 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