Announcement

Collapse
No announcement yet.
X
  • Filter
  • Time
Clear All
new posts

    SGWT.mobile - Exception on com.isomorphic.servlet.ServletTools.parseQueryStri ng

    Any idea of what is causing the exception at the end of the log ? It does not block the application but there might be something not working that I don't see.

    Using SGWT.mobile 2012-12-28 and SGWT Power 2012-12-24

    Thanks, Ben.

    Code:
    2012-12-28 23:56:50.816 java[10993:407] [Java CocoaComponent compatibility mode]: Enabled
    2012-12-28 23:56:50.817 java[10993:407] [Java CocoaComponent compatibility mode]: Setting timeout for SWT to 0.100000
    ISC: Configuring log4j from: file:/Users/bda/Documents/eclipse.indigo_workspace/MOON/war/WEB-INF/classes/log4j.isc.config.xml
    === 2012-12-28 23:56:52,932 [ad-0] INFO  ISCInit - Isomorphic SmartClient/SmartGWT Framework - Initializing
    === 2012-12-28 23:56:52,938 [ad-0] INFO  ConfigLoader - Attempting to load framework.properties from CLASSPATH
    === 2012-12-28 23:56:53,051 [ad-0] INFO  ConfigLoader - Successfully loaded framework.properties from CLASSPATH at location: jar:file:/Users/bda/Documents/eclipse.indigo_workspace/MOON/war/WEB-INF/lib/isomorphic_core_rpc.jar!/framework.properties
    === 2012-12-28 23:56:53,052 [ad-0] INFO  ConfigLoader - Attempting to load project.properties from CLASSPATH
    === 2012-12-28 23:56:53,052 [ad-0] INFO  ConfigLoader - Unable to locate project.properties in CLASSPATH
    === 2012-12-28 23:56:53,057 [ad-0] INFO  ConfigLoader - Successfully loaded isc_interfaces.properties from CLASSPATH at location: jar:file:/Users/bda/Documents/eclipse.indigo_workspace/MOON/war/WEB-INF/lib/isomorphic_core_rpc.jar!/isc_interfaces.properties
    === 2012-12-28 23:56:53,057 [ad-0] INFO  ConfigLoader - Attempting to load server.properties from CLASSPATH
    === 2012-12-28 23:56:53,062 [ad-0] INFO  ConfigLoader - Successfully loaded server.properties from CLASSPATH at location: file:/Users/bda/Documents/eclipse.indigo_workspace/MOON/war/WEB-INF/classes/server.properties
    === 2012-12-28 23:56:53,067 [ad-0] INFO  Logger - Logging system started.
    === 2012-12-28 23:56:53,068 [ad-0] INFO  ISCInit - Isomorphic SmartClient/SmartGWT Framework (v8.3p_2012-12-24/PowerEdition Deployment 2012-12-24) - Initialization Complete
    === 2012-12-28 23:56:53,070 [ad-0] INFO  ISCInit - Auto-detected webRoot - using: /Users/bda/Documents/eclipse.indigo_workspace/MOON/war
    === 2012-12-28 23:56:53,075 [ad-0] INFO  ISCInit - Isomorphic SmartClient/SmartGWT Framework initialization called from com.isomorphic.base.Base
    === 2012-12-28 23:56:53,075 [ad-0] INFO  ISCInit - Isomorphic SmartClient/SmartGWT Framework is already initialized
    log4j:WARN No appenders could be found for logger (org.apache.jasper.compiler.JspRuntimeContext).
    log4j:WARN Please initialize the log4j system properly.
    === 2012-12-28 23:56:53,156 [ad-0] INFO  ISCInit - Isomorphic SmartClient/SmartGWT Framework initialization called from com.isomorphic.base.Init
    === 2012-12-28 23:56:53,156 [ad-0] INFO  ISCInit - Isomorphic SmartClient/SmartGWT Framework is already initialized
    === 2012-12-28 23:58:37,601 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:37,627 [l0-0] INFO  PoolManager - SmartClient pooling disabled for 'properties' objects
    === 2012-12-28 23:58:37,679 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/moon_desktop/sc/system/schema/builtinTypes.xml: 28ms
    === 2012-12-28 23:58:37,716 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/properties.ds.xml: 2ms
    === 2012-12-28 23:58:37,722 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/moon_desktop/sc/system/schema/DataSource.ds.xml: 5ms
    === 2012-12-28 23:58:37,767 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/moon_desktop/sc/system/schema/DataSourceField.ds.xml: 5ms
    === 2012-12-28 23:58:37,926 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:37,928 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/ui_list_operations.ds.xml: 1ms
    === 2012-12-28 23:58:38,050 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,053 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/ui_list_objects.ds.xml: 2ms
    === 2012-12-28 23:58:38,168 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,172 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/ui_security_rights.ds.xml: 3ms
    === 2012-12-28 23:58:38,354 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,356 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/ui_logger.ds.xml: 1ms
    === 2012-12-28 23:58:38,361 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/moon_desktop/sc/system/schema/OperationBinding.ds.xml: 3ms
    === 2012-12-28 23:58:38,372 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/moon_desktop/sc/system/schema/ServerObject.ds.xml: 1ms
    === 2012-12-28 23:58:38,430 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,432 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_types_prospect.ds.xml: 1ms
    === 2012-12-28 23:58:38,502 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,504 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_sources_prospect.ds.xml: 2ms
    === 2012-12-28 23:58:38,576 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,579 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_countries.ds.xml: 2ms
    === 2012-12-28 23:58:38,662 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,664 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_companies.ds.xml: 2ms
    === 2012-12-28 23:58:38,745 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,748 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_sectors.ds.xml: 2ms
    === 2012-12-28 23:58:38,819 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,821 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_products.ds.xml: 1ms
    === 2012-12-28 23:58:38,892 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,894 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_offices.ds.xml: 2ms
    === 2012-12-28 23:58:38,962 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:38,964 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_accounting_codes.ds.xml: 1ms
    === 2012-12-28 23:58:39,046 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:39,048 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_persons.ds.xml: 1ms
    === 2012-12-28 23:58:39,140 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:39,147 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_prospects.ds.xml: 1ms
    === 2012-12-28 23:58:39,247 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:39,249 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_statuses_prospect.ds.xml: 1ms
    === 2012-12-28 23:58:39,318 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:39,320 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_list_currencies.ds.xml: 2ms
    === 2012-12-28 23:58:39,390 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:39,393 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_grid_prospects.ds.xml: 2ms
    === 2012-12-28 23:58:39,611 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:39,614 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_form_prospects_.ds.xml: 2ms
    === 2012-12-28 23:58:39,720 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:39,723 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_form_prospects.ds.xml: 3ms
    === 2012-12-28 23:58:39,997 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:39,999 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_form_prospects_status_.ds.xml: 2ms
    === 2012-12-28 23:58:40,113 [l0-0] INFO  RequestContext - URL: '/isomorphic/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:40,118 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/ds/mb_form_prospects_status.ds.xml: 4ms
    === 2012-12-28 23:58:40,125 [l0-0] DEBUG XML - Parsed XML from /Users/bda/Documents/eclipse.indigo_workspace/MOON/war/moon_desktop/sc/system/schema/Validator.ds.xml: 3ms
    === 2012-12-28 23:58:40,870 [l0-5] INFO  RequestContext - URL: '/isomorphic/RESTHandler', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:40,871 [l0-5] DEBUG RESTHandler - Wrapping json responses:false
    === 2012-12-28 23:58:40,871 [l0-5] DEBUG RESTHandler - json prefix:null
    === 2012-12-28 23:58:40,871 [l0-5] DEBUG RESTHandler - json suffix:null
    === 2012-12-28 23:58:40,871 [l0-5] DEBUG RESTHandler - Default response data format:json
    === 2012-12-28 23:58:40,873 [l0-5] INFO  DataTools - setProperties: couldn't set:
    {
        defaultDataFormat:"No such property",
        wrapJSONResponses:"No such property"
    }
    === 2012-12-28 23:58:40,885 [l0-5] DEBUG RestRequestParser - Parameter:'_operationType'. Value:'fetch'.
    === 2012-12-28 23:58:40,885 [l0-5] DEBUG RestRequestParser - Parameter:'_useStrictJSON'. Value:'true'.
    === 2012-12-28 23:58:40,885 [l0-5] DEBUG RestRequestParser - Parameter:'_dataSource'. Value:'properties'.
    === 2012-12-28 23:58:40,885 [l0-5] DEBUG RestRequestParser - Parameter:'isc_metaDataPrefix'. Value:'_'.
    === 2012-12-28 23:58:40,899 [l0-5] INFO  RESTHandler - Performing 1 operation(s)
    === 2012-12-28 23:58:40,900 [l0-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
    === 2012-12-28 23:58:40,900 [l0-5] DEBUG DeclarativeSecurity - DataSource properties is not in the pre-checked list, processing...
    === 2012-12-28 23:58:40,905 [l0-5] DEBUG AppBase - [builtinApplication.properties_fetch] No userTypes defined, allowing anyone access to all operations for this application
    === 2012-12-28 23:58:40,905 [l0-5] DEBUG AppBase - [builtinApplication.properties_fetch] No public zero-argument method named '_properties_fetch' found, performing generic datasource operation
    === 2012-12-28 23:58:40,906 [l0-5] INFO  SQLDataSource - [builtinApplication.properties_fetch] Performing fetch operation with
    	criteria: {}	values: {}
    === 2012-12-28 23:58:40,913 [l0-5] INFO  SQLWhereClause - [builtinApplication.properties_fetch] empty condition
    === 2012-12-28 23:58:40,914 [l0-5] INFO  SQLDataSource - [builtinApplication.properties_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    === 2012-12-28 23:58:40,995 [l0-5] INFO  SQLDataSource - [builtinApplication.properties_fetch] Executing SQL query on 'Mysql': SELECT properties.name, properties.value FROM properties WHERE ('1'='1')
    === 2012-12-28 23:58:41,046 [l0-5] INFO  PoolManager - [builtinApplication.properties_fetch] SmartClient pooling started for 'Mysql' objects
    === 2012-12-28 23:58:41,046 [l0-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.properties_fetch] Initializing SQL config for 'Mysql' from system config - using DataSource:  com.mysql.jdbc.jdbc2.optional.MysqlDataSource
    === 2012-12-28 23:58:41,077 [l0-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.properties_fetch] makeObject() created a pooled Connection '1647988829'
    === 2012-12-28 23:58:41,081 [l0-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.properties_fetch] Executing pingTest 'select 1 from dual' on connection 1647988829
    === 2012-12-28 23:58:41,083 [l0-5] DEBUG SQLConnectionManager - [builtinApplication.properties_fetch] Returning borrowed connection '1647988829'
    === 2012-12-28 23:58:41,083 [l0-5] DEBUG SQLDriver - [builtinApplication.properties_fetch] About to execute SQL query in 'Mysql' using connection '1647988829'
    === 2012-12-28 23:58:41,083 [l0-5] INFO  SQLDriver - [builtinApplication.properties_fetch] Executing SQL query on 'Mysql': SELECT properties.name, properties.value FROM properties WHERE ('1'='1')
    === 2012-12-28 23:58:41,092 [l0-5] INFO  DSResponse - [builtinApplication.properties_fetch] DSResponse: List with 25 items
    === 2012-12-28 23:58:41,092 [l0-5] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1647988829"
    === 2012-12-28 23:58:41,092 [l0-5] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 1647988829
    === 2012-12-28 23:58:41,093 [l0-5] DEBUG RPCManager - Content type for RPC transaction: text/html; charset=UTF-8
    === 2012-12-28 23:58:41,094 [l0-5] DEBUG RPCManager - non-DMI response, dropExtraFields: false
    === 2012-12-28 23:58:41,404 [l0-5] INFO  RequestContext - URL: '/isomorphic/RESTHandler', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:41,410 [l0-5] DEBUG RestRequestParser - Parameter:'_operationType'. Value:'fetch'.
    === 2012-12-28 23:58:41,410 [l0-5] DEBUG RestRequestParser - Parameter:'_useStrictJSON'. Value:'true'.
    === 2012-12-28 23:58:41,410 [l0-5] DEBUG RestRequestParser - Parameter:'_dataSource'. Value:'ui_list_objects'.
    === 2012-12-28 23:58:41,411 [l0-5] DEBUG RestRequestParser - Parameter:'isc_metaDataPrefix'. Value:'_'.
    === 2012-12-28 23:58:41,416 [l0-5] INFO  RESTHandler - Performing 1 operation(s)
    === 2012-12-28 23:58:41,416 [l0-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
    === 2012-12-28 23:58:41,416 [l0-5] DEBUG DeclarativeSecurity - DataSource ui_list_objects is not in the pre-checked list, processing...
    === 2012-12-28 23:58:41,416 [l0-5] DEBUG AppBase - [builtinApplication.ui_list_objects_fetch] No userTypes defined, allowing anyone access to all operations for this application
    === 2012-12-28 23:58:41,416 [l0-5] DEBUG AppBase - [builtinApplication.ui_list_objects_fetch] No public zero-argument method named '_ui_list_objects_fetch' found, performing generic datasource operation
    === 2012-12-28 23:58:41,416 [l0-5] INFO  SQLDataSource - [builtinApplication.ui_list_objects_fetch] Performing fetch operation with
    	criteria: {}	values: {}
    === 2012-12-28 23:58:41,417 [l0-5] INFO  SQLWhereClause - [builtinApplication.ui_list_objects_fetch] empty condition
    === 2012-12-28 23:58:41,417 [l0-5] INFO  SQLDataSource - [builtinApplication.ui_list_objects_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    === 2012-12-28 23:58:41,417 [l0-5] INFO  SQLDataSource - [builtinApplication.ui_list_objects_fetch] Executing SQL query on 'Mysql': SELECT ui_list_objects.code, ui_list_objects.display, ui_list_objects.id, ui_list_objects.name, ui_list_objects.sortkey FROM ui_list_objects WHERE ('1'='1')
    === 2012-12-28 23:58:41,418 [l0-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.ui_list_objects_fetch] Executing pingTest 'select 1 from dual' on connection 1647988829
    === 2012-12-28 23:58:41,419 [l0-5] DEBUG SQLConnectionManager - [builtinApplication.ui_list_objects_fetch] Returning borrowed connection '1647988829'
    === 2012-12-28 23:58:41,419 [l0-5] DEBUG SQLDriver - [builtinApplication.ui_list_objects_fetch] About to execute SQL query in 'Mysql' using connection '1647988829'
    === 2012-12-28 23:58:41,419 [l0-5] INFO  SQLDriver - [builtinApplication.ui_list_objects_fetch] Executing SQL query on 'Mysql': SELECT ui_list_objects.code, ui_list_objects.display, ui_list_objects.id, ui_list_objects.name, ui_list_objects.sortkey FROM ui_list_objects WHERE ('1'='1')
    === 2012-12-28 23:58:41,424 [l0-5] INFO  DSResponse - [builtinApplication.ui_list_objects_fetch] DSResponse: List with 15 items
    === 2012-12-28 23:58:41,424 [l0-5] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1647988829"
    === 2012-12-28 23:58:41,424 [l0-5] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 1647988829
    === 2012-12-28 23:58:41,425 [l0-5] DEBUG RPCManager - Content type for RPC transaction: text/html; charset=UTF-8
    === 2012-12-28 23:58:41,426 [l0-5] DEBUG RPCManager - non-DMI response, dropExtraFields: false
    === 2012-12-28 23:58:41,719 [l0-5] INFO  RequestContext - URL: '/isomorphic/RESTHandler', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:41,720 [l0-5] DEBUG RestRequestParser - Parameter:'_operationType'. Value:'fetch'.
    === 2012-12-28 23:58:41,720 [l0-5] DEBUG RestRequestParser - Parameter:'_useStrictJSON'. Value:'true'.
    === 2012-12-28 23:58:41,720 [l0-5] DEBUG RestRequestParser - Parameter:'_dataSource'. Value:'ui_list_operations'.
    === 2012-12-28 23:58:41,721 [l0-5] DEBUG RestRequestParser - Parameter:'isc_metaDataPrefix'. Value:'_'.
    === 2012-12-28 23:58:41,722 [l0-5] INFO  RESTHandler - Performing 1 operation(s)
    === 2012-12-28 23:58:41,722 [l0-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
    === 2012-12-28 23:58:41,722 [l0-5] DEBUG DeclarativeSecurity - DataSource ui_list_operations is not in the pre-checked list, processing...
    === 2012-12-28 23:58:41,722 [l0-5] DEBUG AppBase - [builtinApplication.ui_list_operations_fetch] No userTypes defined, allowing anyone access to all operations for this application
    === 2012-12-28 23:58:41,722 [l0-5] DEBUG AppBase - [builtinApplication.ui_list_operations_fetch] No public zero-argument method named '_ui_list_operations_fetch' found, performing generic datasource operation
    === 2012-12-28 23:58:41,723 [l0-5] INFO  SQLDataSource - [builtinApplication.ui_list_operations_fetch] Performing fetch operation with
    	criteria: {}	values: {}
    === 2012-12-28 23:58:41,723 [l0-5] INFO  SQLWhereClause - [builtinApplication.ui_list_operations_fetch] empty condition
    === 2012-12-28 23:58:41,723 [l0-5] INFO  SQLDataSource - [builtinApplication.ui_list_operations_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    === 2012-12-28 23:58:41,723 [l0-5] INFO  SQLDataSource - [builtinApplication.ui_list_operations_fetch] Executing SQL query on 'Mysql': SELECT ui_list_operations.code, ui_list_operations.display, ui_list_operations.id, ui_list_operations.level, ui_list_operations.name, ui_list_operations.sortkey FROM ui_list_operations WHERE ('1'='1')
    === 2012-12-28 23:58:41,723 [l0-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.ui_list_operations_fetch] Executing pingTest 'select 1 from dual' on connection 1647988829
    === 2012-12-28 23:58:41,724 [l0-5] DEBUG SQLConnectionManager - [builtinApplication.ui_list_operations_fetch] Returning borrowed connection '1647988829'
    === 2012-12-28 23:58:41,724 [l0-5] DEBUG SQLDriver - [builtinApplication.ui_list_operations_fetch] About to execute SQL query in 'Mysql' using connection '1647988829'
    === 2012-12-28 23:58:41,724 [l0-5] INFO  SQLDriver - [builtinApplication.ui_list_operations_fetch] Executing SQL query on 'Mysql': SELECT ui_list_operations.code, ui_list_operations.display, ui_list_operations.id, ui_list_operations.level, ui_list_operations.name, ui_list_operations.sortkey FROM ui_list_operations WHERE ('1'='1')
    === 2012-12-28 23:58:41,727 [l0-5] INFO  DSResponse - [builtinApplication.ui_list_operations_fetch] DSResponse: List with 23 items
    === 2012-12-28 23:58:41,727 [l0-5] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1647988829"
    === 2012-12-28 23:58:41,727 [l0-5] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 1647988829
    === 2012-12-28 23:58:41,728 [l0-5] DEBUG RPCManager - Content type for RPC transaction: text/html; charset=UTF-8
    === 2012-12-28 23:58:41,728 [l0-5] DEBUG RPCManager - non-DMI response, dropExtraFields: false
    === 2012-12-28 23:58:42,209 [l0-5] INFO  RequestContext - URL: '/isomorphic/RESTHandler', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:42,211 [l0-5] DEBUG RestRequestParser - Parsing json object: '{"transactionNum":4,"dataSource":"ui_security_rights","sortBy":null,"operationType":"fetch","requestId":"4","showPrompt":null,"data":{"id_person":3}}'
    === 2012-12-28 23:58:42,227 [l0-5] DEBUG RestRequestParser - Parameter:'isc_dataFormat'. Value:'json'.
    === 2012-12-28 23:58:42,229 [l0-5] INFO  RESTHandler - Performing 1 operation(s)
    === 2012-12-28 23:58:42,230 [l0-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
    === 2012-12-28 23:58:42,230 [l0-5] DEBUG DeclarativeSecurity - DataSource ui_security_rights is not in the pre-checked list, processing...
    === 2012-12-28 23:58:42,230 [l0-5] DEBUG AppBase - [builtinApplication.ui_security_rights_fetch] No userTypes defined, allowing anyone access to all operations for this application
    === 2012-12-28 23:58:42,230 [l0-5] DEBUG AppBase - [builtinApplication.ui_security_rights_fetch] No public zero-argument method named '_ui_security_rights_fetch' found, performing generic datasource operation
    === 2012-12-28 23:58:42,231 [l0-5] INFO  SQLDataSource - [builtinApplication.ui_security_rights_fetch] Performing fetch operation with
    	criteria: {id_person:"3"}	values: {id_person:"3"}
    === 2012-12-28 23:58:42,231 [l0-5] INFO  SQLDataSource - [builtinApplication.ui_security_rights_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    === 2012-12-28 23:58:42,232 [l0-5] INFO  SQLDataSource - [builtinApplication.ui_security_rights_fetch] Executing SQL query on 'Mysql': SELECT ui_security_rights.id_person, ui_security_rights.is_contributor_add, ui_security_rights.is_contributor_delete, ui_security_rights.is_contributor_update, ui_security_rights.is_contributor_view, ui_security_rights.is_owner_add, ui_security_rights.is_owner_delete, ui_security_rights.is_owner_update, ui_security_rights.is_owner_view, ui_security_rights.is_user_add, ui_security_rights.is_user_delete, ui_security_rights.is_user_update, ui_security_rights.is_user_view, ui_security_rights.name FROM ui_security_rights WHERE (ui_security_rights.id_person=3)
    === 2012-12-28 23:58:42,232 [l0-5] DEBUG PoolableSQLConnectionFactory - [builtinApplication.ui_security_rights_fetch] Executing pingTest 'select 1 from dual' on connection 1647988829
    === 2012-12-28 23:58:42,233 [l0-5] DEBUG SQLConnectionManager - [builtinApplication.ui_security_rights_fetch] Returning borrowed connection '1647988829'
    === 2012-12-28 23:58:42,233 [l0-5] DEBUG SQLDriver - [builtinApplication.ui_security_rights_fetch] About to execute SQL query in 'Mysql' using connection '1647988829'
    === 2012-12-28 23:58:42,233 [l0-5] INFO  SQLDriver - [builtinApplication.ui_security_rights_fetch] Executing SQL query on 'Mysql': SELECT ui_security_rights.id_person, ui_security_rights.is_contributor_add, ui_security_rights.is_contributor_delete, ui_security_rights.is_contributor_update, ui_security_rights.is_contributor_view, ui_security_rights.is_owner_add, ui_security_rights.is_owner_delete, ui_security_rights.is_owner_update, ui_security_rights.is_owner_view, ui_security_rights.is_user_add, ui_security_rights.is_user_delete, ui_security_rights.is_user_update, ui_security_rights.is_user_view, ui_security_rights.name FROM ui_security_rights WHERE (ui_security_rights.id_person=3)
    === 2012-12-28 23:58:42,284 [l0-5] INFO  DSResponse - [builtinApplication.ui_security_rights_fetch] DSResponse: List with 122 items
    === 2012-12-28 23:58:42,284 [l0-5] DEBUG SQLConnectionManager - About to close PoolableConnection with hashcode "1647988829"
    === 2012-12-28 23:58:42,285 [l0-5] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 1647988829
    === 2012-12-28 23:58:42,285 [l0-5] DEBUG RPCManager - Content type for RPC transaction: text/html; charset=UTF-8
    === 2012-12-28 23:58:42,286 [l0-5] DEBUG RPCManager - non-DMI response, dropExtraFields: false
    === 2012-12-28 23:58:46,231 [l0-5] INFO  RequestContext - URL: '/isomorphic/RESTHandler', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_5) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.101 Safari/537.11': Safari with Accept-Encoding header
    === 2012-12-28 23:58:46,233 [l0-5] WARN  RPCManager - Error initializing log settings
    java.lang.IndexOutOfBoundsException: Index: 1, Size: 1
    	at java.util.ArrayList.RangeCheck(ArrayList.java:547)
    	at java.util.ArrayList.get(ArrayList.java:322)
    	at com.isomorphic.servlet.ServletTools.parseQueryString(ServletTools.java:89)
    	at com.isomorphic.rpc.RPCManager.initLog(RPCManager.java:328)
    	at com.isomorphic.rpc.RPCManager.<init>(RPCManager.java:282)
    	at com.isomorphic.servlet.RESTHandler.processRequest(RESTHandler.java:307)
    	at com.isomorphic.servlet.RESTHandler.doPost(RESTHandler.java:259)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
    	at com.isomorphic.servlet.BaseServlet.service(BaseServlet.java:152)
    	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    	at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:487)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1097)
    	at com.isomorphic.servlet.CompressionFilter.doFilter(CompressionFilter.java:259)
    	at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1088)
    	at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:360)
    	at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
    	at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
    	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:729)
    	at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:405)
    	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    	at org.mortbay.jetty.handler.RequestLogHandler.handle(RequestLogHandler.java:49)
    	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
    	at org.mortbay.jetty.Server.handle(Server.java:324)
    	at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:505)
    	at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:843)
    	at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:647)
    	at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:211)
    	at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:380)
    	at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:395)
    	at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:488)
    === 2012-12-28 23:58:46,234 [l0-5] DEBUG RestRequestParser - Parsing json object: '{"transactionNum":5,"dataSource":"ui_logger","sortBy":null,"operationType":"custom","requestId":"5","showPrompt":null,"data":{},"params":{"id_object":null,"id_person":3,"id_record":null,"id_operation":3,"addClientInfo":"1.3.0","custom":""},"operationId":"log"}'
    === 2012-12-28 23:58:46,241 [l0-5] DEBUG RestRequestParser - Parameter:'isc_dataFormat'. Value:'json'.
    === 2012-12-28 23:58:46,241 [l0-5] DEBUG RestRequestParser - Parameter:'id_person'. Value:'3'.
    === 2012-12-28 23:58:46,241 [l0-5] DEBUG RestRequestParser - Parameter:'id_operation'. Value:'3'.
    === 2012-12-28 23:58:46,241 [l0-5] DEBUG RestRequestParser - Parameter:'addClientInfo'. Value:'1.3.0'.
    === 2012-12-28 23:58:46,241 [l0-5] DEBUG RestRequestParser - Parameter:'custom'. Value:''.
    === 2012-12-28 23:58:46,242 [l0-5] INFO  RESTHandler - Performing 1 operation(s)
    === 2012-12-28 23:58:46,242 [l0-5] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
    === 2012-12-28 23:58:46,242 [l0-5] DEBUG DeclarativeSecurity - DataSource ui_logger is not in the pre-checked list, processing...
    === 2012-12-28 23:58:46,266 [l0-5] DEBUG RPCManager - Content type for RPC transaction: text/html; charset=UTF-8
    === 2012-12-28 23:58:46,267 [l0-5] DEBUG RPCManager - DMI response, dropExtraFields: false

    #2
    We can't really see what would cause this except perhaps "&&" in the query string. Can you capture the query string so we can see it?

    Comment


      #3
      I don't know how to do what you ask, but after some analysis I found that the exception is launched AFTER a ds.performCustomOperation (client side) and BEFORE the corresponding DMI (server side) is executed. The SQL is actually generated in the DMI, so there is no SQL involved yet when the Exception occurs.

      Here is the client side code that calls the DMI:

      Code:
      			DSRequest request = new DSRequest();
      			HashMap<String, Object> params = new HashMap<String, Object>();
      			params.put("id_person",user==null?null:user.getId());
      			params.put("id_operation",MoonMobile.getOperationId(operation));
      			params.put("id_object",MoonMobile.getObjectId(object));
      			params.put("id_record",id);
      			params.put("custom",custom);
      			if(operation.equals(OPERATION_LOGIN_FAILURE_USERNAME)||
      			   operation.equals(OPERATION_LOGIN_FAILURE_PASSWORD)||
      			   operation.equals(OPERATION_LOGIN_SUCCESS)){
      				params.put("addClientInfo",MoonMobile.getUIVersion());
      			}
      			request.setParams(params);
      
      ds.performCustomOperation("log",new Record(),new DSCallback() {
      				public void execute(DSResponse response, Object rawData, DSRequest request) {
      				}
      			},request);
      At execution time a params.toString() gives:

      Code:
      {id_object=null, id_person=3, id_record=null, id_operation=3, addClientInfo=1.3.0, custom=}
      The ds
      Code:
      <DataSource
          ID="mb_logger"
      	serverType="sql"
      	tableName="ui_logger"
      >
          <fields>
          </fields>
         	<operationBindings>
              <binding operationType="custom" operationId="log" serverMethod="log">
                  <serverObject lookupStyle="new" className="com.nside.moon.server.dmi.LoggerDMI"/>
              </binding>
          </operationBindings>         
      </DataSource>
      The DMI (which is not in cause since if I break on the first line of log method, the Exception has already occured):

      Code:
      package com.nside.moon.server.dmi;
      
      import java.sql.Connection;
      import java.sql.Statement;
      import java.text.SimpleDateFormat;
      import java.util.Date;
      
      import javax.servlet.http.HttpServletRequest;
      
      import com.isomorphic.datasource.DSRequest;
      import com.isomorphic.datasource.DSResponse;
      import com.mysql.jdbc.jdbc2.optional.MysqlDataSource;
      import com.nside.moon.server.listener.MYSQLServletContextListener;
      
      
      public class LoggerDMI {
      	
      	private static SimpleDateFormat dateFormat = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
      	private static String sqlTemplate = "INSERT INTO log_ui (date,id_person,id_operation,id_object,id_record,custom) VALUES('%s',%s,%s,%s,%s,%s);";
      	
          public DSResponse log(DSRequest dsRequest) throws Exception {  
              
      		HttpServletRequest r = dsRequest.getHttpServletRequest();
      		
      		
      		String date = dateFormat.format(new Date());
      		String id_person = r.getParameter("id_person");
      		String id_operation = r.getParameter("id_operation");
      		String id_object = r.getParameter("id_object");
      		String id_record = r.getParameter("id_record");
      		String custom = r.getParameter("custom");
      		String clientInfo = r.getParameter("addClientInfo");
      		if (clientInfo!=null){
      			String ip = r.getRemoteAddr();
      			String browser = r.getHeader("User-Agent");
      			String uiversion = clientInfo;
      			custom += " client info:" + ip + " " + browser + " uiversion=" + uiversion; 
      		}
      		if (!custom.equals("null")) custom = "'"+custom+"'";
          	
      		String sql =String.format(sqlTemplate, date,id_person,id_operation,id_object,id_record,custom);
      
      		Connection con = null;
              try {
      
              	MysqlDataSource ds = new MysqlDataSource();  
              	ds.setURL(MYSQLServletContextListener.URL);
              	ds.setUser(MYSQLServletContextListener.USER);  
              	ds.setPassword(MYSQLServletContextListener.PASSWORD);
      
              	con = ds.getConnection();
                  Statement stmt = con.createStatement();
                  stmt.executeUpdate(sql);
                  stmt.close();
      
              	con.close();
      
              } catch (Exception e) {
              	throw e;
              }
              
              
              DSResponse resp = new DSResponse();  
              resp.setStatus(DSResponse.STATUS_SUCCESS);  
              return resp;  
          	
      
          }  
      	
      }
      Last edited by bda@n-side.com; 29 Dec 2012, 12:35.

      Comment


        #4
        Additional info:

        If I comment the line request.setParams(params), the exception is not thrown. This shows that the problem comes from the passing of request params to the DMI.

        Looking at the param values, I noticed the zero-length string assigned to "custom" param, which is apparently the cause of the problem. If I pass a null value instead it works. If I pass a non-empty string it works as well.

        Conclusion, passing "" (zero-length string) to a string parameter in the request causes the Exception.

        I am waiting on you hand and foot ;-).

        Comment


          #5
          This if fixed for tomorrow's SGWT (desktop / server) build.

          Comment


            #6
            Works, thanks!

            Comment

            Working...
            X