Announcement

**Isomorphic** · 27 Mar 2017, 02:53

OK, thank you for the error report. Please try your test case with tomorrow's build, dated March 28th.

**claudiobosticco** · 29 Mar 2017, 23:15

Hello, I don't see new 11.1 Enterprise builds after that of 2017-03-25...

**claudiobosticco** · 5 Apr 2017, 23:56

SmartClient Version: SNAPSHOT_v11.1d_2017-04-04/Enterprise Development Only (built 2017-04-04)

Hello, I can confirm that now it's working, thank you very much

**claudiobosticco** · 12 May 2017, 00:04

SmartClient Version: SNAPSHOT_v11.1d_2017-05-10/Enterprise Development Only (built 2017-05-10)

Chrome on OSX

Hello, it seems that I just found another test case where a validator fails when it shouldn't.
The field LUOGO_NASCITA has a required validator, which must be active when the field ID_NAZIONE_NASCITA_FK is not equal to 118:

Code:

<DataSource xmlns:fmt="urn:jsptld:/WEB-INF/fmt.tld" xmlns="http://www.smartclient.com/schema"
            ID="JAS_ANAG_GIOCATORI_TEST"
            tableName="JAS_ANAG_GIOCATORI"
            schema="DBJAS"
            dbName="dbJas"
            serverType="sql"
        >
    <fields>
        <field name="ID_REC"  primaryKey="true"  type="sequence" hidden="true" sequenceName="SEQUENCE_ID_REC"/>
        <field name="NOME" length="30" type="text" required="true"/>
        <field name="COGNOME" length="50" type="text" required="true"/>
        <field name="LUOGO_NASCITA" length="60" type="text">
            <validators>
                <validator type="required">
                    <applyWhen fieldName="ID_NAZIONE_NASCITA_FK" operator="notEqual" value="118"/>
                </validator>
            </validators>
        </field>
        <field  name="ID_NAZIONE_NASCITA_FK" type="integer"/>
        <field name="ID_STATUS_GIOCATORE_FK" type="integer" />
    </fields>
    <operationBindings>
        <operationBinding operationType="update" serverMethod="updateTestValidator">
            <serverObject lookupStyle="new" className="com.juve.jas.utils.TestValidatorDMI"/>
        </operationBinding>
    </operationBindings>
</DataSource>

it fails when the update operation has a DMI method, which I've reduced to this:

Code:

public class TestValidatorDMI {

    public DSResponse updateTestValidator(DSRequest dsRequest, HttpServletRequest request, RPCManager rpcManager) throws Exception {
        DSRequest dsRequestTest = new DSRequest("JAS_ANAG_GIOCATORI_TEST", DataSource.OP_UPDATE, rpcManager);
        dsRequestTest.setCriteria("ID_REC", dsRequest.getCriteria());
        dsRequestTest.setFieldValue("ID_STATUS_GIOCATORE_FK", 5);
        dsRequestTest.execute();
        return new DSResponse().setFailure();
    }
}

In the tomcat logs, it seems that at first the required validator is correctly checked to be inactive, but then it's re-checked and results active (which is wrong, because the stored record has ID_NAZIONE_NASCITA_FK=118 and LUOGO_NASCITA has also a value in the stored record):

Code:

2017-05-12 09:45:02,469 DEBUG SQLDataSource DataSource 3080 acquired SQLDriver instance 1957008076 during initialization 
2017-05-12 09:45:02,469 DEBUG PoolableDataSourceFactory Created DataSource 3080 of type 'JAS_ANAG_GIOCATORI_TEST' and assigned it to thread http-bio-8443-exec-9 
2017-05-12 09:45:02,469 DEBUG DSRequest Caching instance 3080 of DS 'JAS_ANAG_GIOCATORI_TEST' from DSRequest.getDataSource() 
2017-05-12 09:45:02,469 DEBUG DSRequest Caching instance 3080 of DS JAS_ANAG_GIOCATORI_TEST 
2017-05-12 09:45:02,469 DEBUG RPCManager Request #1 (DSRequest) payload: {
    criteria:{
        ID_REC:499
    },
    values:{
        ID_REC:499
    },
    operationConfig:{
        dataSource:"JAS_ANAG_GIOCATORI_TEST",
        repo:null,
        operationType:"update",
        textMatchStyle:"exact"
    },
    appID:"builtinApplication",
    operation:"JAS_ANAG_GIOCATORI_TEST_update",
    oldValues:{
        ID_REC:499
    }
} 
2017-05-12 09:45:02,469 INFO  IDACall Performing 1 operation(s) 
2017-05-12 09:45:02,470 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-05-12 09:45:02,470 DEBUG DeclarativeSecurity DataSource JAS_ANAG_GIOCATORI_TEST is not in the pre-checked list, processing... 
2017-05-12 09:45:02,471 DEBUG DefaultValidators on field: 'LUOGO_NASCITA' for validator type 'required', 'applyWhen' is:
{
    fieldName:"ID_NAZIONE_NASCITA_FK",
    operator:"notEqual",
    value:"118"
}
record is:
{
    ID_REC:499,
    LUOGO_NASCITA:null
} 
2017-05-12 09:45:02,472 DEBUG SQLDataSource DataSource 3081 acquired SQLDriver instance 1493260013 during initialization 
2017-05-12 09:45:02,472 DEBUG PoolableDataSourceFactory Created DataSource 3081 of type 'JAS_ANAG_GIOCATORI_TEST' and assigned it to thread http-bio-8443-exec-9 
2017-05-12 09:45:02,472 DEBUG DSRequest Caching instance 3081 of DS 'JAS_ANAG_GIOCATORI_TEST' from DSRequest.getDataSource() 
2017-05-12 09:45:02,472 DEBUG DSRequest Caching instance 3081 of DS JAS_ANAG_GIOCATORI_TEST 
2017-05-12 09:45:02,472 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-05-12 09:45:02,472 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-05-12 09:45:02,473 DEBUG AppBase [builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application 
2017-05-12 09:45:02,473 DEBUG AppBase [builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation 
2017-05-12 09:45:02,473 INFO  SQLDataSource [builtinApplication.null] Performing fetch operation with
    criteria: {ID_REC:499}    values: {ID_REC:499} 
2017-05-12 09:45:02,473 INFO  SQLDataSource [builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause 
2017-05-12 09:45:02,474 INFO  SQLDataSource [builtinApplication.null] 3081: Executing SQL query on 'dbJas': SELECT JAS_ANAG_GIOCATORI.ID_REC, JAS_ANAG_GIOCATORI.NOME, JAS_ANAG_GIOCATORI.COGNOME, JAS_ANAG_GIOCATORI.LUOGO_NASCITA, JAS_ANAG_GIOCATORI.ID_NAZIONE_NASCITA_FK, JAS_ANAG_GIOCATORI.ID_STATUS_GIOCATORE_FK FROM DBJAS.JAS_ANAG_GIOCATORI WHERE (JAS_ANAG_GIOCATORI.ID_REC=499) 
2017-05-12 09:45:02,611 DEBUG PoolableSQLConnectionFactory [builtinApplication.null] makeObject() created an unpooled Connection '499624244' 
2017-05-12 09:45:02,611 DEBUG SQLConnectionManager [builtinApplication.null] Borrowed connection '499624244' 
2017-05-12 09:45:02,611 DEBUG SQLTransaction [builtinApplication.null] Started new dbJas transaction "499624244" 
2017-05-12 09:45:02,611 DEBUG SQLDataSource [builtinApplication.null] Setting DSRequest as being part of a transaction 
2017-05-12 09:45:02,611 INFO  SQLDriver [builtinApplication.null] Executing SQL query on 'dbJas' using connection '499624244': SELECT JAS_ANAG_GIOCATORI.ID_REC, JAS_ANAG_GIOCATORI.NOME, JAS_ANAG_GIOCATORI.COGNOME, JAS_ANAG_GIOCATORI.LUOGO_NASCITA, JAS_ANAG_GIOCATORI.ID_NAZIONE_NASCITA_FK, JAS_ANAG_GIOCATORI.ID_STATUS_GIOCATORE_FK FROM DBJAS.JAS_ANAG_GIOCATORI WHERE (JAS_ANAG_GIOCATORI.ID_REC=499) 
2017-05-12 09:45:02,616 INFO  DSResponse DSResponse: List with 1 items 
2017-05-12 09:45:02,616 DEBUG DSRequest freeOnExecute is false for request of type fetch on DataSource JAS_ANAG_GIOCATORI_TEST - not freeing resources! 
2017-05-12 09:45:02,621 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'sequence' but null was returned 
2017-05-12 09:45:02,621 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-05-12 09:45:02,621 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-05-12 09:45:02,621 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-05-12 09:45:02,622 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'integer' but null was returned 
2017-05-12 09:45:02,622 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'integer' but null was returned 
2017-05-12 09:45:02,622 DEBUG DefaultValidators NOTE: Record after applying stored values is:
{
    ID_REC:499,
    LUOGO_NASCITA:"CUNEO"
} 
2017-05-12 09:45:02,622 DEBUG DefaultValidators NOTE: Merged conditionRecord is:
{
    ID_NAZIONE_NASCITA_FK:118,
    ID_REC:499,
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:"CUNEO",
    NOME:"Simone",
    COGNOME:"MURATORE"
} 
2017-05-12 09:45:02,623 DEBUG DefaultOperators value (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-05-12 09:45:02,623 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-12 09:45:02,624 DEBUG DefaultOperators passedOp (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-05-12 09:45:02,624 DEBUG DefaultOperators isEqualToConfiguredValue returnstrue 
2017-05-12 09:45:02,624 INFO  DefaultValidators on field: 'LUOGO_NASCITA' conditional validator of type 'required' is: inactive 
2017-05-12 09:45:02,624 DEBUG DefaultOperators value (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-05-12 09:45:02,624 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-12 09:45:02,624 DEBUG DefaultOperators passedOp (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-05-12 09:45:02,624 DEBUG DefaultOperators isEqualToConfiguredValue returnstrue 
2017-05-12 09:45:05,078 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-05-12 09:45:05,078 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-05-12 09:45:05,078 INFO  RequestContext URL: '/Jas/isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.36': Safari with Accept-Encoding header 
2017-05-12 09:45:05,080 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; to: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png' 
2017-05-12 09:45:05,080 DEBUG FilterChainProxy Candidate is: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; pattern is /images/*; matched=false 
2017-05-12 09:45:05,080 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; to: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png' 
2017-05-12 09:45:05,081 DEBUG DefaultValidators on field: 'LUOGO_NASCITA' for validator type 'required', 'applyWhen' is:
{
    fieldName:"ID_NAZIONE_NASCITA_FK",
    operator:"notEqual",
    value:"118"
}
record is:
{
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:null
} 
2017-05-12 09:45:05,081 DEBUG FilterChainProxy Candidate is: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; pattern is /isomorphic/resthandler*; matched=false 
2017-05-12 09:45:05,081 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; to: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png' 
2017-05-12 09:45:05,081 DEBUG FilterChainProxy Candidate is: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; pattern is /**; matched=true 
2017-05-12 09:45:05,081 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png at position 1 of 10 in additional filter chain; firing Filter: 'ChannelProcessingFilter' 
2017-05-12 09:45:05,081 INFO  RequestContext URL: '/Jas/isomorphic/system/reference/skin/images/server_client_exchange.png', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_4) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.36': Safari with Accept-Encoding header 
2017-05-12 09:45:05,081 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; to: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png' 
2017-05-12 09:45:05,081 DEBUG DefaultValidators NOTE: Record after applying stored values is:
{
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:null
} 
2017-05-12 09:45:05,081 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; pattern is /*.jsp; matched=false 
2017-05-12 09:45:05,081 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png at position 2 of 10 in additional filter chain; firing Filter: 'ConcurrentSessionFilter' 
2017-05-12 09:45:05,081 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png at position 3 of 10 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter' 
2017-05-12 09:45:05,081 DEBUG DefaultValidators NOTE: Merged conditionRecord is:
{
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:null
} 
2017-05-12 09:45:05,081 DEBUG DefaultOperators value (null): isEqualToConfiguredValue 
2017-05-12 09:45:05,081 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-12 09:45:05,081 DEBUG DefaultOperators passedOp (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-12 09:45:05,081 DEBUG DefaultOperators isEqualToConfiguredValue returnsfalse 
2017-05-12 09:45:05,081 INFO  DefaultValidators on field: 'LUOGO_NASCITA' conditional validator of type 'required' is: active 
2017-05-12 09:45:05,081 DEBUG HttpSessionSecurityContextRepository Obtained a valid SecurityContext from SPRING_SECURITY_CONTEXT: 'org.springframework.security.core.context.SecurityContextImpl@3eb9819a: Authentication: org.springframework.security.cas.authentication.CasAuthenticationToken@3eb9819a: Principal: org.springframework.security.ldap.userdetails.InetOrgPerson@40ebd6d0: Dn: mail=alessandro.diliberto@zerob.it,o=JUVENTUSFC; Username: alessandro.diliberto@zerob.it; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; CredentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_ADMIN; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@0: RemoteIpAddress: 172.16.24.53; SessionId: B75D26010FC204E20B1567220F7E6A20; Granted Authorities: ROLE_ADMIN Assertion: org.jasig.cas.client.validation.AssertionImpl@87a0758 Credentials (Service/Proxy Ticket): ST-1-kjVitGOmkAjEe6Eey6wM-cas' 
2017-05-12 09:45:05,081 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-05-12 09:45:05,081 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png at position 4 of 10 in additional filter chain; firing Filter: 'LogoutFilter' 
2017-05-12 09:45:05,082 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png at position 5 of 10 in additional filter chain; firing Filter: 'CasAuthenticationFilter' 
2017-05-12 09:45:05,082 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png at position 6 of 10 in additional filter chain; firing Filter: 'RequestCacheAwareFilter' 
2017-05-12 09:45:05,082 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png at position 7 of 10 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter' 
2017-05-12 09:45:05,082 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png at position 8 of 10 in additional filter chain; firing Filter: 'SessionManagementFilter' 
2017-05-12 09:45:05,082 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png at position 9 of 10 in additional filter chain; firing Filter: 'ExceptionTranslationFilter' 
2017-05-12 09:45:05,082 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png at position 10 of 10 in additional filter chain; firing Filter: 'FilterSecurityInterceptor' 
2017-05-12 09:45:05,082 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /images/*; matched=false 
2017-05-12 09:45:05,083 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-05-12 09:45:05,082 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; to: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png' 
2017-05-12 09:45:05,083 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /isomorphic/resthandler*; matched=false 
2017-05-12 09:45:05,083 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; pattern is /*.jsp; matched=false 
2017-05-12 09:45:05,083 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; pattern is /isomorphic/idacall*; matched=false 
2017-05-12 09:45:05,083 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; pattern is /tools/*.jsp; matched=false 
2017-05-12 09:45:05,083 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-05-12 09:45:05,083 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/skins/graphite/images/dynamicform/unchecked_disabled.png'; pattern is /monitoring*; matched=false 
2017-05-12 09:45:05,083 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-05-12 09:45:05,083 DEBUG FilterChainProxy /isomorphic/skins/Graphite/images/DynamicForm/unchecked_Disabled.png reached end of additional filter chain; proceeding with original chain 
2017-05-12 09:45:05,083 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-05-12 09:45:05,083 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /**; matched=true 
2017-05-12 09:45:05,083 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 1 of 10 in additional filter chain; firing Filter: 'ChannelProcessingFilter' 
2017-05-12 09:45:05,084 DEBUG ValidationContext Adding validation errors at path '/JAS_ANAG_GIOCATORI_TEST/LUOGO_NASCITA/LUOGO_NASCITA': {errorMessage=Field is required} 
2017-05-12 09:45:05,084 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-05-12 09:45:05,084 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /*.jsp; matched=false 
2017-05-12 09:45:05,084 DEBUG DefaultOperators value (null): isEqualToConfiguredValue 
2017-05-12 09:45:05,084 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 2 of 10 in additional filter chain; firing Filter: 'ConcurrentSessionFilter' 
2017-05-12 09:45:05,084 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 3 of 10 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter' 
2017-05-12 09:45:05,084 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-12 09:45:05,084 DEBUG HttpSessionSecurityContextRepository Obtained a valid SecurityContext from SPRING_SECURITY_CONTEXT: 'org.springframework.security.core.context.SecurityContextImpl@3eb9819a: Authentication: org.springframework.security.cas.authentication.CasAuthenticationToken@3eb9819a: Principal: org.springframework.security.ldap.userdetails.InetOrgPerson@40ebd6d0: Dn: mail=alessandro.diliberto@zerob.it,o=JUVENTUSFC; Username: alessandro.diliberto@zerob.it; Password: [PROTECTED]; Enabled: true; AccountNonExpired: true; CredentialsNonExpired: true; AccountNonLocked: true; Granted Authorities: ROLE_ADMIN; Credentials: [PROTECTED]; Authenticated: true; Details: org.springframework.security.web.authentication.WebAuthenticationDetails@0: RemoteIpAddress: 172.16.24.53; SessionId: B75D26010FC204E20B1567220F7E6A20; Granted Authorities: ROLE_ADMIN Assertion: org.jasig.cas.client.validation.AssertionImpl@87a0758 Credentials (Service/Proxy Ticket): ST-1-kjVitGOmkAjEe6Eey6wM-cas' 
2017-05-12 09:45:05,084 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 4 of 10 in additional filter chain; firing Filter: 'LogoutFilter' 
2017-05-12 09:45:05,084 DEBUG DefaultOperators passedOp (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-12 09:45:05,084 DEBUG DefaultOperators isEqualToConfiguredValue returnsfalse 
2017-05-12 09:45:05,084 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 5 of 10 in additional filter chain; firing Filter: 'CasAuthenticationFilter' 
2017-05-12 09:45:05,084 DEBUG ValidationContext Adding validation errors at path '/JAS_ANAG_GIOCATORI_TEST/LUOGO_NASCITA': {errorMessage=Field is required} 
2017-05-12 09:45:05,084 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 6 of 10 in additional filter chain; firing Filter: 'RequestCacheAwareFilter' 
2017-05-12 09:45:05,084 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 7 of 10 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter' 
2017-05-12 09:45:05,084 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 8 of 10 in additional filter chain; firing Filter: 'SessionManagementFilter' 
2017-05-12 09:45:05,084 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 9 of 10 in additional filter chain; firing Filter: 'ExceptionTranslationFilter' 
2017-05-12 09:45:05,084 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 10 of 10 in additional filter chain; firing Filter: 'FilterSecurityInterceptor' 
2017-05-12 09:45:05,084 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-05-12 09:45:05,084 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /*.jsp; matched=false 
2017-05-12 09:45:05,084 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /isomorphic/idacall*; matched=false 
2017-05-12 09:45:05,084 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /tools/*.jsp; matched=false 
2017-05-12 09:45:05,084 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-05-12 09:45:05,084 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /monitoring*; matched=false 
2017-05-12 09:45:05,084 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-05-12 09:45:05,084 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png reached end of additional filter chain; proceeding with original chain 
2017-05-12 09:45:05,085 DEBUG ExceptionTranslationFilter Chain processed normally 
2017-05-12 09:45:05,085 DEBUG SecurityContextPersistenceFilter SecurityContextHolder now cleared, as request processing completed 
2017-05-12 09:45:05,085 INFO  Validation Validation error: [
    {
        LUOGO_NASCITA:[
            {
                errorMessage:"Field is required"
            },
            {
                errorMessage:"Field is required"
            }
        ]
    }
] 
2017-05-12 09:45:05,085 DEBUG DSRequest About to free up resources for request of type update on DataSource JAS_ANAG_GIOCATORI_TEST 
2017-05-12 09:45:05,085 DEBUG DSRequest Ignoring freeResources call because this is not a primary request! 
2017-05-12 09:45:05,085 DEBUG DSRequest About to free up resources for request of type update on DataSource JAS_ANAG_GIOCATORI_TEST 
2017-05-12 09:45:05,085 DEBUG DSRequest Ignoring freeResources call because this is not a primary request! 
2017-05-12 09:45:05,085 DEBUG RPCManager Content type for RPC transaction: text/plain; charset=UTF-8 
2017-05-12 09:45:05,085 DEBUG SQLTransaction Rolling back dbJas transaction "499624244"

**Isomorphic** · 16 May 2017, 15:22

Just to let you know, this is assigned. We will post back soon

**Isomorphic** · 25 May 2017, 01:30

What you are seeing here is the validation of two distinct update DSRequests - the one sent from the client (which is handled correctly) and then the one you create and execute from your DMI (which is not handled correctly). The second request is not validating as you expect because you have a bug in your DMI code, specifically in this line:

Code:

dsRequestTest.setCriteria("ID_REC", dsRequest.getCriteria());

In case you don't see the problem immediately, this is setting the "ID_REC" property of the new request's criteria to the entire criteria of the original request. A fix would be:

Code:

dsRequestTest.setCriteria("ID_REC", dsRequest.getCriteria()[b].get("ID_REC")[/b]);

Regards,
Isomorphic Software Support

**claudiobosticco** · 25 May 2017, 07:34

Sorry, you're right about the posted DMI test case, but I've got the same behaviour using the correct version:

Code:

public class TestValidatorDMI {

    public DSResponse updateTestValidator(DSRequest dsRequest, HttpServletRequest request, RPCManager rpcManager) throws Exception {
        DSRequest dsRequestTest = new DSRequest("JAS_ANAG_GIOCATORI_TEST", DataSource.OP_UPDATE, rpcManager);
        dsRequestTest.setCriteria("ID_REC", dsRequest.getCriteria().get("ID_REC"));
        dsRequestTest.setFieldValue("ID_STATUS_GIOCATORE_FK", 5);
        dsRequestTest.execute();
        return new DSResponse().setFailure();
    }
}

It gives this server log:

Code:

2017-05-25 15:20:53,876 DEBUG RPCManager Processing 1 requests. 
2017-05-25 15:20:53,884 DEBUG PoolableDataSourceFactory Created DataSource 1993 of type 'DataSource' and assigned it to thread http-bio-8443-exec-51 
2017-05-25 15:20:53,887 DEBUG PoolableDataSourceFactory Created DataSource 1994 of type 'DataSourceField' and assigned it to thread http-bio-8443-exec-51 
2017-05-25 15:20:53,887 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'field' but null was returned 
2017-05-25 15:20:53,890 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'validator' but null was returned 
2017-05-25 15:20:53,892 DEBUG PoolableDataSourceFactory Created DataSource 1995 of type 'Validator' and assigned it to thread http-bio-8443-exec-51 
2017-05-25 15:20:53,894 DEBUG PoolableDataSourceFactory Created DataSource 1997 of type 'Criterion' and assigned it to thread http-bio-8443-exec-51 
2017-05-25 15:20:53,894 DEBUG PoolableDataSourceFactory Created DataSource 1996 of type 'AdvancedCriteria' and assigned it to thread http-bio-8443-exec-51 
2017-05-25 15:20:53,895 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'applyWhen' but null was returned 
2017-05-25 15:20:53,900 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'operationBinding' but null was returned 
2017-05-25 15:20:53,904 DEBUG PoolableDataSourceFactory Created DataSource 1998 of type 'OperationBinding' and assigned it to thread http-bio-8443-exec-51 
2017-05-25 15:20:53,906 DEBUG PoolableDataSourceFactory Created DataSource 1999 of type 'ServerObject' and assigned it to thread http-bio-8443-exec-51 
2017-05-25 15:20:53,907 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'serverObject' but null was returned 
2017-05-25 15:20:53,908 DEBUG PoolableDataSourceFactory Created DataSource 2000 of type 'JAS_ANAG_GIOCATORI_TEST' and assigned it to thread http-bio-8443-exec-51 
2017-05-25 15:20:53,908 DEBUG DSRequest Caching instance 2000 of DS 'JAS_ANAG_GIOCATORI_TEST' from DSRequest.getDataSource() 
2017-05-25 15:20:53,908 DEBUG DSRequest Caching instance 2000 of DS JAS_ANAG_GIOCATORI_TEST 
2017-05-25 15:20:53,909 DEBUG RPCManager Request #1 (DSRequest) payload: {
    criteria:{
        ID_REC:499
    },
    values:{
        ID_REC:499
    },
    operationConfig:{
        dataSource:"JAS_ANAG_GIOCATORI_TEST",
        repo:null,
        operationType:"update",
        textMatchStyle:"exact"
    },
    appID:"builtinApplication",
    operation:"JAS_ANAG_GIOCATORI_TEST_update",
    oldValues:{
        ID_REC:499
    }
} 
2017-05-25 15:20:53,909 INFO  IDACall Performing 1 operation(s) 
2017-05-25 15:20:53,909 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-05-25 15:20:53,909 DEBUG DeclarativeSecurity DataSource JAS_ANAG_GIOCATORI_TEST is not in the pre-checked list, processing... 
2017-05-25 15:20:53,918 DEBUG DefaultValidators on field: 'LUOGO_NASCITA' for validator type 'required', 'applyWhen' is:
{
    fieldName:"ID_NAZIONE_NASCITA_FK",
    operator:"notEqual",
    value:"118"
}
record is:
{
    ID_REC:499,
    LUOGO_NASCITA:null
} 
2017-05-25 15:20:53,918 DEBUG PoolableDataSourceFactory Created DataSource 2001 of type 'JAS_ANAG_GIOCATORI_TEST' and assigned it to thread http-bio-8443-exec-51 
2017-05-25 15:20:53,918 DEBUG DSRequest Caching instance 2001 of DS 'JAS_ANAG_GIOCATORI_TEST' from DSRequest.getDataSource() 
2017-05-25 15:20:53,918 DEBUG DSRequest Caching instance 2001 of DS JAS_ANAG_GIOCATORI_TEST 
2017-05-25 15:20:53,918 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-05-25 15:20:53,918 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-05-25 15:20:53,918 DEBUG AppBase [builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application 
2017-05-25 15:20:53,919 DEBUG AppBase [builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation 
2017-05-25 15:20:53,919 INFO  SQLDataSource [builtinApplication.null] Performing fetch operation with
    criteria: {ID_REC:499}  values: {ID_REC:499} 
2017-05-25 15:20:53,920 DEBUG SQLDataSource [builtinApplication.null] DataSource 2001 acquired SQLDriver instance 1749392828 during initialization 
2017-05-25 15:20:53,920 INFO  SQLDataSource [builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause 
2017-05-25 15:20:53,921 INFO  SQLDataSource [builtinApplication.null] 2001: Executing SQL query on 'dbJas': SELECT JAS_ANAG_GIOCATORI.ID_REC, JAS_ANAG_GIOCATORI.NOME, JAS_ANAG_GIOCATORI.COGNOME, JAS_ANAG_GIOCATORI.LUOGO_NASCITA, JAS_ANAG_GIOCATORI.ID_NAZIONE_NASCITA_FK, JAS_ANAG_GIOCATORI.ID_STATUS_GIOCATORE_FK FROM DBJAS.JAS_ANAG_GIOCATORI WHERE (JAS_ANAG_GIOCATORI.ID_REC=499) 
2017-05-25 15:20:54,002 DEBUG PoolableSQLConnectionFactory [builtinApplication.null] makeObject() created an unpooled Connection '846649119' 
2017-05-25 15:20:54,002 DEBUG SQLConnectionManager [builtinApplication.null] Borrowed connection '846649119' 
2017-05-25 15:20:54,002 DEBUG SQLTransaction [builtinApplication.null] Started new dbJas transaction "846649119" 
2017-05-25 15:20:54,002 DEBUG SQLDataSource [builtinApplication.null] Setting DSRequest as being part of a transaction 
2017-05-25 15:20:54,002 INFO  SQLDriver [builtinApplication.null] Executing SQL query on 'dbJas' using connection '846649119': SELECT JAS_ANAG_GIOCATORI.ID_REC, JAS_ANAG_GIOCATORI.NOME, JAS_ANAG_GIOCATORI.COGNOME, JAS_ANAG_GIOCATORI.LUOGO_NASCITA, JAS_ANAG_GIOCATORI.ID_NAZIONE_NASCITA_FK, JAS_ANAG_GIOCATORI.ID_STATUS_GIOCATORE_FK FROM DBJAS.JAS_ANAG_GIOCATORI WHERE (JAS_ANAG_GIOCATORI.ID_REC=499) 
2017-05-25 15:20:54,009 INFO  DSResponse DSResponse: List with 1 items 
2017-05-25 15:20:54,009 DEBUG DSRequest freeOnExecute is false for request of type fetch on DataSource JAS_ANAG_GIOCATORI_TEST - not freeing resources! 
2017-05-25 15:20:54,009 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'sequence' but null was returned 
2017-05-25 15:20:54,010 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-05-25 15:20:54,010 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-05-25 15:20:54,010 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-05-25 15:20:54,010 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'integer' but null was returned 
2017-05-25 15:20:54,010 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'integer' but null was returned 
2017-05-25 15:20:54,011 DEBUG DefaultValidators NOTE: Record after applying stored values is:
{
    ID_REC:499,
    LUOGO_NASCITA:"CUNEO"
} 
2017-05-25 15:20:54,011 DEBUG DefaultValidators NOTE: Merged conditionRecord is:
{
    ID_NAZIONE_NASCITA_FK:118,
    ID_REC:499,
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:"CUNEO",
    NOME:"Simone",
    COGNOME:"MURATORE"
} 
2017-05-25 15:20:54,011 DEBUG DefaultOperators value (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-05-25 15:20:54,012 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-25 15:20:54,012 DEBUG DefaultOperators passedOp (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-05-25 15:20:54,012 DEBUG DefaultOperators isEqualToConfiguredValue returnstrue 
2017-05-25 15:20:54,012 INFO  DefaultValidators on field: 'LUOGO_NASCITA' conditional validator of type 'required' is: inactive 
2017-05-25 15:20:54,012 DEBUG DefaultOperators value (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-05-25 15:20:54,012 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-25 15:20:54,013 DEBUG DefaultOperators passedOp (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-05-25 15:20:54,013 DEBUG DefaultOperators isEqualToConfiguredValue returnstrue 
2017-05-25 15:20:56,982 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-05-25 15:20:56,982 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-05-25 15:20:56,983 INFO  RequestContext URL: '/Jas/isomorphic/system/reference/skin/images/opener_opened.png', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.36': Safari with Accept-Encoding header 
2017-05-25 15:20:56,983 INFO  RequestContext URL: '/Jas/isomorphic/system/reference/skin/images/server_client_exchange.png', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.36': Safari with Accept-Encoding header 
2017-05-25 15:20:56,990 INFO  RequestContext URL: '/Jas/isomorphic/system/reference/skin/images/server_network_closed.png', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.36': Safari with Accept-Encoding header 
2017-05-25 15:20:56,990 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/opener_opened.png'; to: '/isomorphic/system/reference/skin/images/opener_opened.png' 
2017-05-25 15:20:56,990 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /images/*; matched=false 
2017-05-25 15:20:56,990 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/opener_opened.png'; to: '/isomorphic/system/reference/skin/images/opener_opened.png' 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /isomorphic/resthandler*; matched=false 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/opener_opened.png'; to: '/isomorphic/system/reference/skin/images/opener_opened.png' 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_network_closed.png'; to: '/isomorphic/system/reference/skin/images/server_network_closed.png' 
2017-05-25 15:20:56,991 DEBUG DefaultValidators on field: 'LUOGO_NASCITA' for validator type 'required', 'applyWhen' is:
{
    fieldName:"ID_NAZIONE_NASCITA_FK",
    operator:"notEqual",
    value:"118"
}
record is:
{
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:null
} 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /images/*; matched=false 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /**; matched=true 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png at position 1 of 10 in additional filter chain; firing Filter: 'ChannelProcessingFilter' 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /images/*; matched=false 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-05-25 15:20:56,991 DEBUG DefaultValidators NOTE: Record after applying stored values is:
{
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:null
} 
2017-05-25 15:20:56,991 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/opener_opened.png'; to: '/isomorphic/system/reference/skin/images/opener_opened.png' 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_network_closed.png'; to: '/isomorphic/system/reference/skin/images/server_network_closed.png' 
2017-05-25 15:20:56,991 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /*.jsp; matched=false 
2017-05-25 15:20:56,991 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /isomorphic/resthandler*; matched=false 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png at position 2 of 10 in additional filter chain; firing Filter: 'ConcurrentSessionFilter' 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /isomorphic/resthandler*; matched=false 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png at position 3 of 10 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter' 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_network_closed.png'; to: '/isomorphic/system/reference/skin/images/server_network_closed.png' 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /**; matched=true 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /**; matched=true 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 1 of 10 in additional filter chain; firing Filter: 'ChannelProcessingFilter' 
2017-05-25 15:20:56,992 DEBUG DefaultValidators NOTE: Merged conditionRecord is:
{
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:null
} 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png at position 1 of 10 in additional filter chain; firing Filter: 'ChannelProcessingFilter' 
2017-05-25 15:20:56,992 DEBUG DefaultOperators value (null): isEqualToConfiguredValue 
2017-05-25 15:20:56,992 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-05-25 15:20:56,992 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_network_closed.png'; to: '/isomorphic/system/reference/skin/images/server_network_closed.png' 
2017-05-25 15:20:56,992 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /*.jsp; matched=false 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 2 of 10 in additional filter chain; firing Filter: 'ConcurrentSessionFilter' 
2017-05-25 15:20:56,992 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /*.jsp; matched=false 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 3 of 10 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter' 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png at position 4 of 10 in additional filter chain; firing Filter: 'LogoutFilter' 
2017-05-25 15:20:56,992 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png at position 2 of 10 in additional filter chain; firing Filter: 'ConcurrentSessionFilter' 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png at position 5 of 10 in additional filter chain; firing Filter: 'CasAuthenticationFilter' 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png at position 3 of 10 in additional filter chain; firing Filter: 'SecurityContextPersistenceFilter' 
2017-05-25 15:20:56,992 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png at position 6 of 10 in additional filter chain; firing Filter: 'RequestCacheAwareFilter' 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 4 of 10 in additional filter chain; firing Filter: 'LogoutFilter' 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png at position 7 of 10 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter' 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 5 of 10 in additional filter chain; firing Filter: 'CasAuthenticationFilter' 
2017-05-25 15:20:56,993 DEBUG DefaultOperators passedOp (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png at position 8 of 10 in additional filter chain; firing Filter: 'SessionManagementFilter' 
2017-05-25 15:20:56,993 DEBUG DefaultOperators isEqualToConfiguredValue returnsfalse 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 6 of 10 in additional filter chain; firing Filter: 'RequestCacheAwareFilter' 
2017-05-25 15:20:56,993 INFO  DefaultValidators on field: 'LUOGO_NASCITA' conditional validator of type 'required' is: active 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png at position 4 of 10 in additional filter chain; firing Filter: 'LogoutFilter' 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 7 of 10 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter' 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png at position 5 of 10 in additional filter chain; firing Filter: 'CasAuthenticationFilter' 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png at position 9 of 10 in additional filter chain; firing Filter: 'ExceptionTranslationFilter' 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 8 of 10 in additional filter chain; firing Filter: 'SessionManagementFilter' 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png at position 10 of 10 in additional filter chain; firing Filter: 'FilterSecurityInterceptor' 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png at position 6 of 10 in additional filter chain; firing Filter: 'RequestCacheAwareFilter' 
2017-05-25 15:20:56,993 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/opener_opened.png'; to: '/isomorphic/system/reference/skin/images/opener_opened.png' 
2017-05-25 15:20:56,993 DEBUG ValidationContext Adding validation errors at path '/JAS_ANAG_GIOCATORI_TEST/LUOGO_NASCITA/LUOGO_NASCITA': {errorMessage=Field is required} 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 9 of 10 in additional filter chain; firing Filter: 'ExceptionTranslationFilter' 
2017-05-25 15:20:56,993 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /*.jsp; matched=false 
2017-05-25 15:20:56,993 DEBUG DefaultOperators value (null): isEqualToConfiguredValue 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png at position 7 of 10 in additional filter chain; firing Filter: 'SecurityContextHolderAwareRequestFilter' 
2017-05-25 15:20:56,993 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /isomorphic/idacall*; matched=false 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png at position 10 of 10 in additional filter chain; firing Filter: 'FilterSecurityInterceptor' 
2017-05-25 15:20:56,993 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /tools/*.jsp; matched=false 
2017-05-25 15:20:56,993 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png at position 8 of 10 in additional filter chain; firing Filter: 'SessionManagementFilter' 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /monitoring*; matched=false 
2017-05-25 15:20:56,994 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-05-25 15:20:56,994 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-25 15:20:56,994 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png at position 9 of 10 in additional filter chain; firing Filter: 'ExceptionTranslationFilter' 
2017-05-25 15:20:56,994 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/opener_opened.png reached end of additional filter chain; proceeding with original chain 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /*.jsp; matched=false 
2017-05-25 15:20:56,994 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png at position 10 of 10 in additional filter chain; firing Filter: 'FilterSecurityInterceptor' 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /isomorphic/idacall*; matched=false 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_network_closed.png'; to: '/isomorphic/system/reference/skin/images/server_network_closed.png' 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /tools/*.jsp; matched=false 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /*.jsp; matched=false 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-05-25 15:20:56,994 DEBUG DefaultOperators passedOp (class java.lang.String): "118": isEqualToConfiguredValue 
2017-05-25 15:20:56,994 DEBUG DefaultOperators isEqualToConfiguredValue returnsfalse 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /isomorphic/idacall*; matched=false 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /monitoring*; matched=false 
2017-05-25 15:20:56,994 DEBUG ValidationContext Adding validation errors at path '/JAS_ANAG_GIOCATORI_TEST/LUOGO_NASCITA': {errorMessage=Field is required} 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /tools/*.jsp; matched=false 
2017-05-25 15:20:56,994 DEBUG ExceptionTranslationFilter Chain processed normally 
2017-05-25 15:20:56,994 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-05-25 15:20:56,994 DEBUG SecurityContextPersistenceFilter SecurityContextHolder now cleared, as request processing completed 
2017-05-25 15:20:56,994 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_client_exchange.png reached end of additional filter chain; proceeding with original chain 
2017-05-25 15:20:56,994 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-05-25 15:20:56,995 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /monitoring*; matched=false 
2017-05-25 15:20:56,995 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-05-25 15:20:56,995 DEBUG FilterChainProxy /isomorphic/system/reference/skin/images/server_network_closed.png reached end of additional filter chain; proceeding with original chain 
2017-05-25 15:20:56,995 DEBUG ExceptionTranslationFilter Chain processed normally 
2017-05-25 15:20:56,995 DEBUG SecurityContextPersistenceFilter SecurityContextHolder now cleared, as request processing completed 
2017-05-25 15:20:56,995 DEBUG ExceptionTranslationFilter Chain processed normally 
2017-05-25 15:20:56,995 DEBUG SecurityContextPersistenceFilter SecurityContextHolder now cleared, as request processing completed 
2017-05-25 15:20:56,995 INFO  Validation Validation error: [
    {
        LUOGO_NASCITA:[
            {
                errorMessage:"Field is required"
            },
            {
                errorMessage:"Field is required"
            }
        ]
    }
] 
2017-05-25 15:20:56,996 DEBUG DSRequest About to free up resources for request of type update on DataSource JAS_ANAG_GIOCATORI_TEST 
2017-05-25 15:20:56,996 DEBUG DSRequest Ignoring freeResources call because this is not a primary request! 
2017-05-25 15:20:56,996 DEBUG DSRequest About to free up resources for request of type update on DataSource JAS_ANAG_GIOCATORI_TEST 
2017-05-25 15:20:56,996 DEBUG DSRequest Ignoring freeResources call because this is not a primary request! 
2017-05-25 15:20:56,996 DEBUG RPCManager Content type for RPC transaction: text/plain; charset=UTF-8 
2017-05-25 15:20:56,996 DEBUG SQLDataSource DataSource 2000 acquired SQLDriver instance 1197150680 during initialization 
2017-05-25 15:20:56,997 DEBUG SQLTransaction Rolling back dbJas transaction "846649119"

**Isomorphic** · 30 May 2017, 04:50

Now this is happening because the key value "ID_REC" is only present in the criteria. If you look at the request sent from the client in the SmartClient Developer Console, you will see that the complete record - sent up as "values" - includes the criteria field(s); your server-created DSRequest should do the same thing. For example, add this line:

Code:

dsRequestTest.setFieldValue("ID_REC", dsRequest.getCriteria().get("ID_REC"));

**claudiobosticco** · 30 May 2017, 23:04

Whoa, I didn't know that. Usually, when I create a DSRequest (server side) for an update, I don't set the criteria also in the values. Is it always mandatory, or only when there's an applyWhen validator?

**claudiobosticco** · 7 Jun 2017, 07:41

Hello, apart from my comment above, I tried your suggestion, so the new DMI code is:

Code:

public class TestValidatorDMI {

    public DSResponse updateTestValidator(DSRequest dsRequest, HttpServletRequest request, RPCManager rpcManager) throws Exception {
        DSRequest dsRequestTest = new DSRequest("JAS_ANAG_GIOCATORI_TEST", DataSource.OP_UPDATE, rpcManager);
        dsRequestTest.setCriteria("ID_REC", dsRequest.getCriteria().get("ID_REC"));
        dsRequestTest.setFieldValue("ID_REC", dsRequest.getCriteria().get("ID_REC"));
        dsRequestTest.setFieldValue("ID_STATUS_GIOCATORE_FK", 5);
        return dsRequestTest.execute();
    }

}

the dataSource is unchanged:

Code:

<DataSource xmlns:fmt="urn:jsptld:/WEB-INF/fmt.tld" xmlns="http://www.smartclient.com/schema"
            ID="JAS_ANAG_GIOCATORI_TEST"
            tableName="JAS_ANAG_GIOCATORI"
            schema="DBJAS"
            dbName="dbJas"
            serverType="sql"
        >
    <fields>
        <field name="ID_REC"  primaryKey="true"  type="sequence" hidden="true" sequenceName="SEQUENCE_ID_REC"/>
        <field name="NOME" length="30" type="text" required="true"/>
        <field name="COGNOME" length="50" type="text" required="true"/>
        <field name="LUOGO_NASCITA" length="60" type="text">
            <validators>
                <validator type="required">
                    <applyWhen fieldName="ID_NAZIONE_NASCITA_FK" operator="notEqual" value="118"/>
                </validator>
            </validators>
        </field>
        <field  name="ID_NAZIONE_NASCITA_FK" type="integer"/>
        <field name="ID_STATUS_GIOCATORE_FK" type="integer" />
    </fields>
    <operationBindings>
        <operationBinding operationType="update" serverMethod="updateTestValidator">
            <serverObject lookupStyle="new" className="com.juve.jas.utils.TestValidatorDMI"/>
        </operationBinding>
    </operationBindings>
</DataSource>

Now, there's a very strange behaviour: it keeps on doing the same fetch (the log is cut after 3 fetches...):

Code:

2017-06-07 09:54:40,765 DEBUG IDACall Header Name:Value pair: host:axelpro.local:8443 
2017-06-07 09:54:40,765 DEBUG IDACall Header Name:Value pair: connection:keep-alive 
2017-06-07 09:54:40,765 DEBUG IDACall Header Name:Value pair: content-length:1149 
2017-06-07 09:54:40,765 DEBUG IDACall Header Name:Value pair: origin:https://axelpro.local:8443 
2017-06-07 09:54:40,765 DEBUG IDACall Header Name:Value pair: user-agent:Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.36 
2017-06-07 09:54:40,765 DEBUG IDACall Header Name:Value pair: content-type:application/x-www-form-urlencoded; charset=UTF-8 
2017-06-07 09:54:40,766 DEBUG IDACall Header Name:Value pair: accept:*/* 
2017-06-07 09:54:40,766 DEBUG IDACall Header Name:Value pair: dnt:1 
2017-06-07 09:54:40,766 DEBUG IDACall Header Name:Value pair: referer:https://axelpro.local:8443/Jas/ 
2017-06-07 09:54:40,766 DEBUG IDACall Header Name:Value pair: accept-encoding:gzip, deflate, br 
2017-06-07 09:54:40,766 DEBUG IDACall Header Name:Value pair: accept-language:it-IT,it;q=0.8,en-US;q=0.6,en;q=0.4 
2017-06-07 09:54:40,766 DEBUG IDACall Header Name:Value pair: cookie:JSESSIONID=39E340BC9BEF2136394262E0B8EB7774; isc_cState=ready; GLog=%7B%0A%20%20%20%20trackRPC%3Atrue%2C%20%0A%20%20%20%20isc_pageURL%3A%22https%3A//axelpro.local%3A8443/Jas/%23ath%22%2C%20%0A%20%20%20%20isc_pageGUID%3A%222DDA87CD-2702-4597-B094-9B6E3683B5D6%22%2C%20%0A%20%20%20%20priorityDefaults%3A%7B%0A%20%20%20%20%20%20%20%20sgwtInternal%3A1%2C%20%0A%20%20%20%20%20%20%20%20Log%3A4%0A%20%20%20%20%7D%2C%20%0A%20%20%20%20defaultPriority%3A3%2C%20%0A%20%20%20%20left%3A215%2C%20%0A%20%20%20%20top%3A22%2C%20%0A%20%20%20%20width%3A1280%2C%20%0A%20%20%20%20height%3A951%0A%7D 
2017-06-07 09:54:40,766 DEBUG IDACall session exists: 39E340BC9BEF2136394262E0B8EB7774 
2017-06-07 09:54:40,769 DEBUG XML Parsed XML from (in memory stream): 2ms 
2017-06-07 09:54:40,770 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'transaction' but null was returned 
2017-06-07 09:54:40,770 DEBUG PoolableDataSourceFactory Created DataSource 1975 of type 'Object' and assigned it to thread http-bio-8443-exec-8 
2017-06-07 09:54:40,771 DEBUG PoolableDataSourceFactory Created DataSource 1976 of type 'List' and assigned it to thread http-bio-8443-exec-8 
2017-06-07 09:54:40,771 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'elem' but null was returned 
2017-06-07 09:54:40,772 DEBUG RPCManager Processing 1 requests. 
2017-06-07 09:54:40,772 DEBUG PoolableDataSourceFactory Created DataSource 1977 of type 'JAS_ANAG_GIOCATORI_TEST' and assigned it to thread http-bio-8443-exec-8 
2017-06-07 09:54:40,772 DEBUG DSRequest Caching instance 1977 of DS 'JAS_ANAG_GIOCATORI_TEST' from DSRequest.getDataSource() 
2017-06-07 09:54:40,772 DEBUG DSRequest Caching instance 1977 of DS JAS_ANAG_GIOCATORI_TEST 
2017-06-07 09:54:40,773 DEBUG RPCManager Request #1 (DSRequest) payload: {
    criteria:{
        ID_REC:499
    },
    values:{
        ID_REC:499
    },
    operationConfig:{
        dataSource:"JAS_ANAG_GIOCATORI_TEST",
        repo:null,
        operationType:"update",
        textMatchStyle:"exact"
    },
    appID:"builtinApplication",
    operation:"JAS_ANAG_GIOCATORI_TEST_update",
    oldValues:{
        ID_REC:499
    }
} 
2017-06-07 09:54:40,773 INFO  IDACall Performing 1 operation(s) 
2017-06-07 09:54:40,773 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:54:40,773 DEBUG DeclarativeSecurity DataSource JAS_ANAG_GIOCATORI_TEST is not in the pre-checked list, processing... 
2017-06-07 09:54:40,776 DEBUG DefaultValidators on field: 'LUOGO_NASCITA' for validator type 'required', 'applyWhen' is:
{
    fieldName:"ID_NAZIONE_NASCITA_FK",
    operator:"notEqual",
    value:"118"
}
record is:
{
    ID_REC:499,
    LUOGO_NASCITA:null
} 
2017-06-07 09:54:40,776 DEBUG PoolableDataSourceFactory Created DataSource 1978 of type 'JAS_ANAG_GIOCATORI_TEST' and assigned it to thread http-bio-8443-exec-8 
2017-06-07 09:54:40,776 DEBUG DSRequest Caching instance 1978 of DS 'JAS_ANAG_GIOCATORI_TEST' from DSRequest.getDataSource() 
2017-06-07 09:54:40,776 DEBUG DSRequest Caching instance 1978 of DS JAS_ANAG_GIOCATORI_TEST 
2017-06-07 09:54:40,776 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:54:40,776 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-06-07 09:54:44,147 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:54:44,147 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-06-07 09:54:44,147 DEBUG AppBase [builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application 
2017-06-07 09:54:44,147 DEBUG AppBase [builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation 
2017-06-07 09:54:44,148 INFO  SQLDataSource [builtinApplication.null] Performing fetch operation with
    criteria: {ID_REC:499}    values: {ID_REC:499} 
2017-06-07 09:54:44,148 INFO  RequestContext URL: '/Jas/isomorphic/system/reference/skin/images/server_network_closed.png', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.36': Safari with Accept-Encoding header 
2017-06-07 09:54:44,148 INFO  RequestContext URL: '/Jas/isomorphic/system/reference/skin/images/opener_opened.png', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.36': Safari with Accept-Encoding header 
2017-06-07 09:54:44,148 INFO  RequestContext URL: '/Jas/isomorphic/system/reference/skin/images/server_client_exchange.png', User-Agent: 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.3029.110 Safari/537.36': Safari with Accept-Encoding header 
2017-06-07 09:54:44,149 DEBUG SQLDataSource [builtinApplication.null] DataSource 1978 acquired SQLDriver instance 1008244188 during initialization 
2017-06-07 09:54:44,149 INFO  SQLDataSource [builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause 
2017-06-07 09:54:44,150 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/messaging'; to: '/isomorphic/messaging' 
2017-06-07 09:54:44,150 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /*.jsp; matched=false 
2017-06-07 09:54:44,150 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-06-07 09:54:44,150 INFO  SQLDataSource [builtinApplication.null] 1978: Executing SQL query on 'dbJas': SELECT JAS_ANAG_GIOCATORI.ID_REC, JAS_ANAG_GIOCATORI.NOME, JAS_ANAG_GIOCATORI.COGNOME, JAS_ANAG_GIOCATORI.LUOGO_NASCITA, JAS_ANAG_GIOCATORI.ID_NAZIONE_NASCITA_FK, JAS_ANAG_GIOCATORI.ID_STATUS_GIOCATORE_FK FROM DBJAS.JAS_ANAG_GIOCATORI WHERE (JAS_ANAG_GIOCATORI.ID_REC=499) 
2017-06-07 09:54:44,150 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /*.jsp; matched=false 
2017-06-07 09:54:44,150 DEBUG PoolableSQLConnectionFactory [builtinApplication.null] makeObject() created an unpooled Connection '688459482' 
2017-06-07 09:54:44,150 DEBUG SQLConnectionManager [builtinApplication.null] Borrowed connection '688459482' 
2017-06-07 09:54:44,150 DEBUG SQLTransaction [builtinApplication.null] Started new dbJas transaction "688459482" 
2017-06-07 09:54:44,150 DEBUG SQLDataSource [builtinApplication.null] Setting DSRequest as being part of a transaction 
2017-06-07 09:54:44,150 INFO  SQLDriver [builtinApplication.null] Executing SQL query on 'dbJas' using connection '688459482': SELECT JAS_ANAG_GIOCATORI.ID_REC, JAS_ANAG_GIOCATORI.NOME, JAS_ANAG_GIOCATORI.COGNOME, JAS_ANAG_GIOCATORI.LUOGO_NASCITA, JAS_ANAG_GIOCATORI.ID_NAZIONE_NASCITA_FK, JAS_ANAG_GIOCATORI.ID_STATUS_GIOCATORE_FK FROM DBJAS.JAS_ANAG_GIOCATORI WHERE (JAS_ANAG_GIOCATORI.ID_REC=499) 
2017-06-07 09:54:44,150 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_network_closed.png'; to: '/isomorphic/system/reference/skin/images/server_network_closed.png' 
2017-06-07 09:54:44,151 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /*.jsp; matched=false 
2017-06-07 09:54:44,152 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/opener_opened.png'; to: '/isomorphic/system/reference/skin/images/opener_opened.png' 
2017-06-07 09:54:44,152 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /*.jsp; matched=false 
2017-06-07 09:54:44,152 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; to: '/isomorphic/system/reference/skin/images/server_client_exchange.png' 
2017-06-07 09:54:44,152 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/messaging'; to: '/isomorphic/messaging' 
2017-06-07 09:54:44,152 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /*.jsp; matched=false 
2017-06-07 09:54:44,152 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /*.jsp; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /isomorphic/idacall*; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /tools/*.jsp; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /isomorphic/idacall*; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /tools/*.jsp; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_client_exchange.png'; pattern is /monitoring*; matched=false 
2017-06-07 09:54:44,153 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /monitoring*; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/server_network_closed.png'; to: '/isomorphic/system/reference/skin/images/server_network_closed.png' 
2017-06-07 09:54:44,153 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /*.jsp; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /isomorphic/idacall*; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /tools/*.jsp; matched=false 
2017-06-07 09:54:44,153 DEBUG ExceptionTranslationFilter Chain processed normally 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-06-07 09:54:44,153 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/system/reference/skin/images/opener_opened.png'; to: '/isomorphic/system/reference/skin/images/opener_opened.png' 
2017-06-07 09:54:44,154 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/server_network_closed.png'; pattern is /monitoring*; matched=false 
2017-06-07 09:54:44,154 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-06-07 09:54:44,153 DEBUG SecurityContextPersistenceFilter SecurityContextHolder now cleared, as request processing completed 
2017-06-07 09:54:44,154 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /*.jsp; matched=false 
2017-06-07 09:54:44,154 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /isomorphic/idacall*; matched=false 
2017-06-07 09:54:44,154 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /tools/*.jsp; matched=false 
2017-06-07 09:54:44,154 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-06-07 09:54:44,154 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/system/reference/skin/images/opener_opened.png'; pattern is /monitoring*; matched=false 
2017-06-07 09:54:44,154 DEBUG ExceptionTranslationFilter Chain processed normally 
2017-06-07 09:54:44,154 DEBUG SecurityContextPersistenceFilter SecurityContextHolder now cleared, as request processing completed 
2017-06-07 09:54:44,154 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-06-07 09:54:44,154 DEBUG ExceptionTranslationFilter Chain processed normally 
2017-06-07 09:54:44,154 DEBUG SecurityContextPersistenceFilter SecurityContextHolder now cleared, as request processing completed 
2017-06-07 09:54:44,161 INFO  DSResponse DSResponse: List with 1 items 
2017-06-07 09:54:44,161 DEBUG DSRequest freeOnExecute is false for request of type fetch on DataSource JAS_ANAG_GIOCATORI_TEST - not freeing resources! 
2017-06-07 09:54:44,161 INFO  DSResponse DSResponse: List with 1 items 
2017-06-07 09:54:44,161 DEBUG DSRequest freeOnExecute is false for request of type fetch on DataSource JAS_ANAG_GIOCATORI_TEST - not freeing resources! 
2017-06-07 09:54:44,161 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'sequence' but null was returned 
2017-06-07 09:54:44,161 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-06-07 09:54:44,161 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-06-07 09:54:44,161 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-06-07 09:54:44,162 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'integer' but null was returned 
2017-06-07 09:54:44,162 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'integer' but null was returned 
2017-06-07 09:54:44,162 DEBUG DefaultValidators NOTE: Record after applying stored values is:
{
    ID_REC:499,
    LUOGO_NASCITA:"CUNEO"
} 
2017-06-07 09:54:44,162 DEBUG DefaultValidators NOTE: Merged conditionRecord is:
{
    ID_NAZIONE_NASCITA_FK:118,
    ID_REC:499,
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:"CUNEO",
    NOME:"Simone",
    COGNOME:"MURATORE"
} 
2017-06-07 09:54:44,163 DEBUG DefaultOperators value (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:54:44,163 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-06-07 09:54:44,163 DEBUG DefaultOperators passedOp (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:54:44,163 DEBUG DefaultOperators isEqualToConfiguredValue returnstrue 
2017-06-07 09:54:44,163 INFO  DefaultValidators on field: 'LUOGO_NASCITA' conditional validator of type 'required' is: inactive 
2017-06-07 09:54:44,164 DEBUG DefaultOperators value (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:54:44,164 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-06-07 09:54:44,164 DEBUG DefaultOperators passedOp (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:54:44,164 DEBUG DefaultOperators isEqualToConfiguredValue returnstrue 
2017-06-07 09:54:44,165 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:54:44,165 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-06-07 09:54:44,165 DEBUG DefaultValidators on field: 'LUOGO_NASCITA' for validator type 'required', 'applyWhen' is:
{
    fieldName:"ID_NAZIONE_NASCITA_FK",
    operator:"notEqual",
    value:"118"
}
record is:
{
    ID_REC:499,
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:null
} 
2017-06-07 09:54:44,166 DEBUG PoolableDataSourceFactory Created DataSource 1979 of type 'JAS_ANAG_GIOCATORI_TEST' and assigned it to thread http-bio-8443-exec-8 
2017-06-07 09:54:44,166 DEBUG DSRequest Caching instance 1979 of DS 'JAS_ANAG_GIOCATORI_TEST' from DSRequest.getDataSource() 
2017-06-07 09:54:44,166 DEBUG DSRequest Caching instance 1979 of DS JAS_ANAG_GIOCATORI_TEST 
2017-06-07 09:54:44,166 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:54:44,166 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-06-07 09:57:01,647 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:57:01,647 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-06-07 09:57:01,648 DEBUG AppBase [builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application 
2017-06-07 09:57:01,648 DEBUG AppBase [builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation 
2017-06-07 09:57:01,649 INFO  SQLDataSource [builtinApplication.null] Performing fetch operation with
    criteria: {ID_REC:499}    values: {ID_REC:499} 
2017-06-07 09:57:01,649 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/messaging'; to: '/isomorphic/messaging' 
2017-06-07 09:57:01,650 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/messaging'; to: '/isomorphic/messaging' 
2017-06-07 09:57:01,649 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /*.jsp; matched=false 
2017-06-07 09:57:01,650 DEBUG SQLDataSource [builtinApplication.null] DataSource 1979 acquired SQLDriver instance 1179510431 during initialization 
2017-06-07 09:57:01,650 DEBUG DefaultFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/messaging'; to: '/isomorphic/messaging' 
2017-06-07 09:57:01,651 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /*.jsp; matched=false 
2017-06-07 09:57:01,650 DEBUG DefaultFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /*.jsp; matched=false 
2017-06-07 09:57:01,651 INFO  SQLDataSource [builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause 
2017-06-07 09:57:01,651 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/messaging'; to: '/isomorphic/messaging' 
2017-06-07 09:57:01,652 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /*.jsp; matched=false 
2017-06-07 09:57:01,652 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /isomorphic/idacall*; matched=false 
2017-06-07 09:57:01,654 INFO  SQLDataSource [builtinApplication.null] 1979: Executing SQL query on 'dbJas': SELECT JAS_ANAG_GIOCATORI.ID_REC, JAS_ANAG_GIOCATORI.NOME, JAS_ANAG_GIOCATORI.COGNOME, JAS_ANAG_GIOCATORI.LUOGO_NASCITA, JAS_ANAG_GIOCATORI.ID_NAZIONE_NASCITA_FK, JAS_ANAG_GIOCATORI.ID_STATUS_GIOCATORE_FK FROM DBJAS.JAS_ANAG_GIOCATORI WHERE (JAS_ANAG_GIOCATORI.ID_REC=499) 
2017-06-07 09:57:01,654 DEBUG SQLDataSource [builtinApplication.null] Setting DSRequest as being part of a transaction 
2017-06-07 09:57:01,654 INFO  SQLDriver [builtinApplication.null] Executing SQL query on 'dbJas' using connection '688459482': SELECT JAS_ANAG_GIOCATORI.ID_REC, JAS_ANAG_GIOCATORI.NOME, JAS_ANAG_GIOCATORI.COGNOME, JAS_ANAG_GIOCATORI.LUOGO_NASCITA, JAS_ANAG_GIOCATORI.ID_NAZIONE_NASCITA_FK, JAS_ANAG_GIOCATORI.ID_STATUS_GIOCATORE_FK FROM DBJAS.JAS_ANAG_GIOCATORI WHERE (JAS_ANAG_GIOCATORI.ID_REC=499) 
2017-06-07 09:57:01,654 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/messaging'; to: '/isomorphic/messaging' 
2017-06-07 09:57:01,654 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /*.jsp; matched=false 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /tools/*.jsp; matched=false 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /isomorphic/idacall*; matched=false 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /monitoring*; matched=false 
2017-06-07 09:57:01,655 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Converted URL to lowercase, from: '/isomorphic/messaging'; to: '/isomorphic/messaging' 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /*.jsp; matched=false 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /isomorphic/idacall*; matched=false 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /tools/*.jsp; matched=false 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /monitoring*; matched=false 
2017-06-07 09:57:01,655 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-06-07 09:57:01,655 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /tools/*.jsp; matched=false 
2017-06-07 09:57:01,656 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /tools/visualbuilder/*.jsp; matched=false 
2017-06-07 09:57:01,656 DEBUG ExpressionBasedFilterInvocationSecurityMetadataSource Candidate is: '/isomorphic/messaging'; pattern is /monitoring*; matched=false 
2017-06-07 09:57:01,656 DEBUG FilterSecurityInterceptor Public object - authentication not attempted 
2017-06-07 09:57:01,668 INFO  DSResponse DSResponse: List with 1 items 
2017-06-07 09:57:01,668 DEBUG DSRequest freeOnExecute is false for request of type fetch on DataSource JAS_ANAG_GIOCATORI_TEST - not freeing resources! 
2017-06-07 09:57:01,668 INFO  DSResponse DSResponse: List with 1 items 
2017-06-07 09:57:01,668 DEBUG DSRequest freeOnExecute is false for request of type fetch on DataSource JAS_ANAG_GIOCATORI_TEST - not freeing resources! 
2017-06-07 09:57:01,669 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'sequence' but null was returned 
2017-06-07 09:57:01,669 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-06-07 09:57:01,669 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-06-07 09:57:01,669 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-06-07 09:57:01,669 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'integer' but null was returned 
2017-06-07 09:57:01,669 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'integer' but null was returned 
2017-06-07 09:57:01,670 DEBUG DefaultValidators NOTE: Record after applying stored values is:
{
    ID_REC:499,
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:"CUNEO"
} 
2017-06-07 09:57:01,670 DEBUG DefaultValidators NOTE: Merged conditionRecord is:
{
    ID_NAZIONE_NASCITA_FK:118,
    ID_REC:499,
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:"CUNEO",
    NOME:"Simone",
    COGNOME:"MURATORE"
} 
2017-06-07 09:57:01,670 DEBUG DefaultOperators value (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:57:01,670 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-06-07 09:57:01,671 DEBUG DefaultOperators passedOp (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:57:01,671 DEBUG DefaultOperators isEqualToConfiguredValue returnstrue 
2017-06-07 09:57:01,671 INFO  DefaultValidators on field: 'LUOGO_NASCITA' conditional validator of type 'required' is: inactive 
2017-06-07 09:57:01,672 DEBUG DefaultOperators value (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:57:01,672 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-06-07 09:57:01,672 DEBUG DefaultOperators passedOp (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:57:01,672 DEBUG DefaultOperators isEqualToConfiguredValue returnstrue 
2017-06-07 09:57:01,673 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:57:01,673 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-06-07 09:57:01,674 DEBUG DefaultValidators on field: 'LUOGO_NASCITA' for validator type 'required', 'applyWhen' is:
{
    fieldName:"ID_NAZIONE_NASCITA_FK",
    operator:"notEqual",
    value:"118"
}
record is:
{
    ID_REC:499,
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:null
} 
2017-06-07 09:57:01,674 DEBUG PoolableDataSourceFactory Created DataSource 1980 of type 'JAS_ANAG_GIOCATORI_TEST' and assigned it to thread http-bio-8443-exec-8 
2017-06-07 09:57:01,674 DEBUG DSRequest Caching instance 1980 of DS 'JAS_ANAG_GIOCATORI_TEST' from DSRequest.getDataSource() 
2017-06-07 09:57:01,674 DEBUG DSRequest Caching instance 1980 of DS JAS_ANAG_GIOCATORI_TEST 
2017-06-07 09:57:01,675 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:57:01,675 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-06-07 09:57:02,557 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:57:02,557 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-06-07 09:57:02,558 DEBUG AppBase [builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application 
2017-06-07 09:57:02,558 DEBUG AppBase [builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation 
2017-06-07 09:57:02,559 INFO  SQLDataSource [builtinApplication.null] Performing fetch operation with
    criteria: {ID_REC:499}    values: {ID_REC:499} 
2017-06-07 09:57:02,559 DEBUG SQLDataSource [builtinApplication.null] DataSource 1980 acquired SQLDriver instance 1517656029 during initialization 
2017-06-07 09:57:02,560 INFO  SQLDataSource [builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause 
2017-06-07 09:57:02,561 INFO  SQLDataSource [builtinApplication.null] 1980: Executing SQL query on 'dbJas': SELECT JAS_ANAG_GIOCATORI.ID_REC, JAS_ANAG_GIOCATORI.NOME, JAS_ANAG_GIOCATORI.COGNOME, JAS_ANAG_GIOCATORI.LUOGO_NASCITA, JAS_ANAG_GIOCATORI.ID_NAZIONE_NASCITA_FK, JAS_ANAG_GIOCATORI.ID_STATUS_GIOCATORE_FK FROM DBJAS.JAS_ANAG_GIOCATORI WHERE (JAS_ANAG_GIOCATORI.ID_REC=499) 
2017-06-07 09:57:02,561 DEBUG SQLDataSource [builtinApplication.null] Setting DSRequest as being part of a transaction 
2017-06-07 09:57:02,561 INFO  SQLDriver [builtinApplication.null] Executing SQL query on 'dbJas' using connection '688459482': SELECT JAS_ANAG_GIOCATORI.ID_REC, JAS_ANAG_GIOCATORI.NOME, JAS_ANAG_GIOCATORI.COGNOME, JAS_ANAG_GIOCATORI.LUOGO_NASCITA, JAS_ANAG_GIOCATORI.ID_NAZIONE_NASCITA_FK, JAS_ANAG_GIOCATORI.ID_STATUS_GIOCATORE_FK FROM DBJAS.JAS_ANAG_GIOCATORI WHERE (JAS_ANAG_GIOCATORI.ID_REC=499) 
2017-06-07 09:57:02,572 INFO  DSResponse DSResponse: List with 1 items 
2017-06-07 09:57:02,572 DEBUG DSRequest freeOnExecute is false for request of type fetch on DataSource JAS_ANAG_GIOCATORI_TEST - not freeing resources! 
2017-06-07 09:57:02,572 INFO  DSResponse DSResponse: List with 1 items 
2017-06-07 09:57:02,572 DEBUG DSRequest freeOnExecute is false for request of type fetch on DataSource JAS_ANAG_GIOCATORI_TEST - not freeing resources! 
2017-06-07 09:57:02,573 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'sequence' but null was returned 
2017-06-07 09:57:02,573 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-06-07 09:57:02,573 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-06-07 09:57:02,573 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'text' but null was returned 
2017-06-07 09:57:02,576 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'integer' but null was returned 
2017-06-07 09:57:02,576 DEBUG PoolableDataSourceFactory Tried to create DataSource  of type 'integer' but null was returned 
2017-06-07 09:57:02,576 DEBUG DefaultValidators NOTE: Record after applying stored values is:
{
    ID_REC:499,
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:"CUNEO"
} 
2017-06-07 09:57:02,577 DEBUG DefaultValidators NOTE: Merged conditionRecord is:
{
    ID_NAZIONE_NASCITA_FK:118,
    ID_REC:499,
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:"CUNEO",
    NOME:"Simone",
    COGNOME:"MURATORE"
} 
2017-06-07 09:57:02,577 DEBUG DefaultOperators value (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:57:02,577 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-06-07 09:57:02,577 DEBUG DefaultOperators passedOp (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:57:02,577 DEBUG DefaultOperators isEqualToConfiguredValue returnstrue 
2017-06-07 09:57:02,577 INFO  DefaultValidators on field: 'LUOGO_NASCITA' conditional validator of type 'required' is: inactive 
2017-06-07 09:57:02,578 DEBUG DefaultOperators value (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:57:02,578 DEBUG DefaultOperators operand (class java.lang.String): "118": isEqualToConfiguredValue 
2017-06-07 09:57:02,578 DEBUG DefaultOperators passedOp (class java.math.BigDecimal): 118: isEqualToConfiguredValue 
2017-06-07 09:57:02,578 DEBUG DefaultOperators isEqualToConfiguredValue returnstrue 
2017-06-07 09:57:02,579 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:57:02,579 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
2017-06-07 09:57:02,580 DEBUG DefaultValidators on field: 'LUOGO_NASCITA' for validator type 'required', 'applyWhen' is:
{
    fieldName:"ID_NAZIONE_NASCITA_FK",
    operator:"notEqual",
    value:"118"
}
record is:
{
    ID_REC:499,
    ID_STATUS_GIOCATORE_FK:5,
    LUOGO_NASCITA:null
} 
2017-06-07 09:57:02,580 DEBUG PoolableDataSourceFactory Created DataSource 1981 of type 'JAS_ANAG_GIOCATORI_TEST' and assigned it to thread http-bio-8443-exec-8 
2017-06-07 09:57:02,580 DEBUG DSRequest Caching instance 1981 of DS 'JAS_ANAG_GIOCATORI_TEST' from DSRequest.getDataSource() 
2017-06-07 09:57:02,580 DEBUG DSRequest Caching instance 1981 of DS JAS_ANAG_GIOCATORI_TEST 
2017-06-07 09:57:02,580 DEBUG DeclarativeSecurity Processing security checks for DataSource null, field null 
2017-06-07 09:57:02,580 DEBUG DeclarativeSecurity Request is not a client request, ignoring security checks. 
[cut]

...until a stack overflow error:

Code:

2017-06-07 10:12:04,262 INFO  SQLDataSource [builtinApplication.null] Performing fetch operation with
    criteria: {ID_REC:499}    values: {ID_REC:499} 
2017-06-07 10:12:04,262 DEBUG SQLDataSource [builtinApplication.null] DataSource 4689 acquired SQLDriver instance 1534284657 during initialization 
2017-06-07 10:12:04,263 INFO  SQLDataSource [builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause 
2017-06-07 10:12:04,340 WARN  RequestContext dsRequest.execute() failed:  
java.lang.StackOverflowError
    at org.apache.commons.lang.text.StrBuilder.ensureCapacity(StrBuilder.java:232)
    at org.apache.commons.lang.text.StrBuilder.append(StrBuilder.java:626)
    at org.apache.velocity.runtime.parser.ParserTokenManager.SkipLexicalActions(ParserTokenManager.java:5437)
    at org.apache.velocity.runtime.parser.ParserTokenManager.getNextToken(ParserTokenManager.java:5389)
    at org.apache.velocity.runtime.parser.Parser.jj_scan_token(Parser.java:3567)
    at org.apache.velocity.runtime.parser.Parser.jj_3R_73(Parser.java:2905)
    at org.apache.velocity.runtime.parser.Parser.jj_3R_63(Parser.java:3413)
    at org.apache.velocity.runtime.parser.Parser.jj_3R_38(Parser.java:2809)
    at org.apache.velocity.runtime.parser.Parser.jj_3R_24(Parser.java:2841)
    at org.apache.velocity.runtime.parser.Parser.jj_3_1(Parser.java:3219)
    at org.apache.velocity.runtime.parser.Parser.jj_2_1(Parser.java:2661)
    at org.apache.velocity.runtime.parser.Parser.Statement(Parser.java:356)
    at org.apache.velocity.runtime.parser.Parser.process(Parser.java:317)
    at org.apache.velocity.runtime.parser.Parser.parse(Parser.java:117)
    at org.apache.velocity.runtime.RuntimeInstance.parse(RuntimeInstance.java:1226)
    at org.apache.velocity.runtime.RuntimeInstance.parse(RuntimeInstance.java:1181)
    at org.apache.velocity.runtime.RuntimeInstance.evaluate(RuntimeInstance.java:1297)
    at org.apache.velocity.runtime.RuntimeInstance.evaluate(RuntimeInstance.java:1265)
    at org.apache.velocity.app.VelocityEngine.evaluate(VelocityEngine.java:199)
    at com.isomorphic.velocity.Velocity.evaluate(Velocity.java:371)
    at com.isomorphic.velocity.Velocity.evaluateAsString(Velocity.java:296)
    at com.isomorphic.velocity.Velocity.evaluateWithSnippets(Velocity.java:496)
    at com.isomorphic.sql.SQLDataSource.generateSQLStatement(SQLDataSource.java:1486)
    at com.isomorphic.sql.SQLDataSource.SQLExecute(SQLDataSource.java:1723)
    at com.isomorphic.sql.SQLDataSource.processRequest(SQLDataSource.java:434)
    at com.isomorphic.sql.SQLDataSource.executeFetch(SQLDataSource.java:379)
    at com.isomorphic.datasource.DataSource.execute(DataSource.java:2224)
    at com.isomorphic.application.AppBase.executeDefaultDSOperation(AppBase.java:629)
    at com.isomorphic.application.AppBase.executeAppOperation(AppBase.java:546)
    at com.isomorphic.application.AppBase.execute(AppBase.java:489)
    at com.isomorphic.datasource.DSRequest.execute(DSRequest.java:2807)
    at com.juve.jas.utils.TestValidatorDMI.fetchTestValidator(TestValidatorDMI.java:22)
[cut]

am I missing something?

**Isomorphic** · 8 Jun 2017, 08:04

Your DataSource only has one update operation configured:

Code:

<operationBinding operationType="update" serverMethod="updateTestValidator">
    <serverObject lookupStyle="new" className="com.juve.jas.utils.TestValidatorDMI"/>
</operationBinding>

However, testValidatorDMI::updateTestValidator() blindly creates and executes a new "update" DSRequests on the same DataSource. This DSRequest is going to end up back in that same method - of course it is, that is the only "update" operation defined for that DataSource. You need to do something to prevent the second request from just going down the same path as the first: use a different operationId and test for it in the code, for example, or look to see if the DSRequest came from the client or the server (dsRequest.isClientRequest()).

**claudiobosticco** · 14 Jun 2017, 13:12

Originally posted by Isomorphic View Post

This DSRequest is going to end up back in that same method

oh well, this is a bit embarassing, in this aspect my test case is completely flawed.
After fixing this, the test case works.

And what about my other comment?

Originally posted by claudiobosticco View Post

Usually, when I create a DSRequest (server side) for an update, I don't set the criteria also in the values. Is it always mandatory, or only when there's an applyWhen validator?

**claudiobosticco** · 6 Jul 2017, 05:42

Originally posted by claudiobosticco View Post

Usually, when I create a DSRequest (server side) for an update, I don't set the criteria also in the values. Is it always mandatory, or only when there's an applyWhen validator?

Hello Isomorphic, could you please comment about this question?

**Isomorphic** · 7 Jul 2017, 00:18

We are discussing this internally. We'll post back on here soon

**Blama** · 7 Jul 2017, 03:00

Hi claudiobosticco, Hi Isomorphic,

this is a bit off an hijacked thread, but claudiobosticco was able to see the same error I saw. Then Isomorphic fixed some source of this error here:

Originally posted by Isomorphic View Post

Yes, the validation should not be happening for an included field - we're looking into it right now. claudiobosticco we see why you are getting the problem causing the validation to fire inappropriately, but right now the underlying cause is not clear - again, we are looking into it

But for me it still occurs (only after some time):

Originally posted by Blama View Post

Hi Isomorphic,

really bad news. This issue appeared again, this time using v10.1p_2017-03-02.
Did your fix from #32 also make it in 5.1p?

Best regards
Blama

Now my question is: Can you still reproduce it with your code from #22 - #27?
If so, perhaps you could send some stack trace, log, or similar to Isomorphic, so that they can investigate further.

Thank you & Best regards
Blama

Announcement

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment

Comment