Announcement

Collapse
No announcement yet.
X
Collapse
  • Page of 1
  • Filter
  • Time
Clear All
new posts
Previous template Next
    #1

    Question/Bug: Expected behaviour for related updates when a Queue fails

    Hi Isomorphic,

    I'm seeing a behaviour in 12.0p, where I think it might be a bug:
    I have a operationType:custom-DSRequest, that can be sent for one or many items of a list from clientside. In case many entries are selected, the requests are sent as a queue.

    Now this request fails for some entries, which is fine in general. The problem is the handling of relatedUpdates in the non-failing requests in the queue.
    In this case the relatedUpdates of request 1 is applied in the GUI/ResultSet, while the whole transaction is rolled back serverside.

    An example where DSRequest 2 and 3 of 3 fail, while DSRequest 1 on it's own succeeds:
    • Queue-response
      • operationType:custom-DSResponse
        • status:0
        • queueStatus:-1
        • relatedUpdates: some proper relatedUpdate-record
      • operationType:custom-DSResponse
        • status:-1
        • queueStatus:-1,
        • data: my error message text
      • operationType:custom-DSResponse
        • status:-1
        • queueStatus:-1,
        • data: my error message text
    I don't think it is correct that the relatedUpdate of DSRequest 1 is applied in the GUI. If you agree, can you have a look?

    Thank you & Best regards
    Blama
    Tags: None
    #2
    We agree, no relatedUpdates are expected to be applied if queue had failed requests. In order to address this we need more details, ideally a standalone use case, since we could not reproduce it. Thank you.

    Comment

      #3
      Hi Isomorphic,

      here is a BuiltInDS based test case.
      • Click "Reset all data to 0"" to set all salaries to 0 and show this change in data through relatedUpdates (just to show that this works in general)
      • Select some (not the first two entries) and click "Change selected to 1000" to change some salaries to 1000 and show this change in data through relatedUpdates
      • Select some - including 1st and/or 2nd - and click "Change selected to 1000" to change some salaries to 1000, which should not work
      In the 3rd case there are two problems:
      1. The one mentioned in #1 - even if the Queue fails, the GUI is updated for the not-failed requests (see Developer Console RPC Tab)
      2. Only in the testcase (at least not happening in my project using PostgreSQL): No rollback serverside before data is returned to the client, even though one request failed. The log mentions "Committing HSQLDB transaction". I'd expect an rollback.
      Best regards
      Blama

      employees.ds.xml addition:
      Code:
          <serverObject lookupStyle="new" className="com.smartgwt.sample.server.listener.Employees" />
    <operationBindings>
        <operationBinding operationType="custom" operationId="resetCustom" serverMethod="resetCustom" />
        <operationBinding operationType="custom" operationId="updateCustom" serverMethod="updateCustom" />
    </operationBindings>
      BuiltInDS.java:
      Code:
      package com.smartgwt.sample.client;

import com.google.gwt.core.client.EntryPoint;
import com.smartgwt.client.Version;
import com.smartgwt.client.core.KeyIdentifier;
import com.smartgwt.client.data.AdvancedCriteria;
import com.smartgwt.client.data.DataSource;
import com.smartgwt.client.data.SortSpecifier;
import com.smartgwt.client.rpc.RPCManager;
import com.smartgwt.client.types.OperatorId;
import com.smartgwt.client.types.SortDirection;
import com.smartgwt.client.util.Page;
import com.smartgwt.client.util.PageKeyHandler;
import com.smartgwt.client.util.SC;
import com.smartgwt.client.widgets.IButton;
import com.smartgwt.client.widgets.Window;
import com.smartgwt.client.widgets.events.ClickEvent;
import com.smartgwt.client.widgets.events.ClickHandler;
import com.smartgwt.client.widgets.grid.ListGrid;
import com.smartgwt.client.widgets.grid.ListGridField;
import com.smartgwt.client.widgets.grid.ListGridRecord;
import com.smartgwt.client.widgets.layout.HLayout;
import com.smartgwt.client.widgets.layout.VLayout;

public class BuiltInDS implements EntryPoint {
    private VLayout mainLayout;
    private IButton recreateBtn;

    public void onModuleLoad() {
        KeyIdentifier debugKey = new KeyIdentifier();
        debugKey.setCtrlKey(true);
        debugKey.setKeyName("D");

        Page.registerKey(debugKey, new PageKeyHandler() {
            public void execute(String keyName) {
                SC.showConsole();
            }
        });

        mainLayout = new VLayout(20);
        mainLayout.setWidth100();
        mainLayout.setHeight100();

        recreateBtn = new IButton("Recreate");
        recreateBtn.addClickHandler(new ClickHandler() {
            @Override
            public void onClick(ClickEvent event) {
                recreate();
            }
        });
        mainLayout.addMember(recreateBtn);
        recreate();
        mainLayout.draw();
    }

    private void recreate() {
        Window w = new Window();
        w.setWidth("95%");
        w.setHeight("95%");
        w.setMembersMargin(0);
        w.setModalMaskOpacity(70);
        w.setTitle(" (" + Version.getVersion() + "/" + Version.getSCVersionNumber() + ")");
        w.setTitle("Problem with failed queues and relatedUpdate" + w.getTitle());
        w.setShowMinimizeButton(false);
        w.setIsModal(true);
        w.setShowModalMask(true);
        w.centerInPage();
        final DataSource employeesDS = DataSource.get("employees");
        final ListGrid lg = new ListGrid(employeesDS);
        lg.setAutoFetchData(true);
        lg.setWidth(650);
        lg.setHeight100();
        lg.setSort(new SortSpecifier("EmployeeId", SortDirection.ASCENDING));
        lg.setInitialCriteria(new AdvancedCriteria("EmployeeId", OperatorId.LESS_OR_EQUAL, 190));
        ListGridField employeeId = new ListGridField("EmployeeId");
        ListGridField name = new ListGridField("Name");
        ListGridField salary = new ListGridField("Salary");
        lg.setFields(employeeId, name, salary);

        final IButton reloadBtn = new IButton("Reload data");
        reloadBtn.setWidth(200);
        reloadBtn.addClickHandler(new ClickHandler() {
            @Override
            public void onClick(ClickEvent event) {
                lg.invalidateCache();
            }
        });
        final IButton resetBtn = new IButton("Reset all data to 0");
        resetBtn.setWidth(200);
        resetBtn.addClickHandler(new ClickHandler() {
            @Override
            public void onClick(ClickEvent event) {
                employeesDS.performCustomOperation("resetCustom");
            }
        });
        final IButton changeBtn = new IButton("Change selected to 1000");
        changeBtn.setWidth(200);
        changeBtn.addClickHandler(new ClickHandler() {
            @Override
            public void onClick(ClickEvent event) {
                RPCManager.startQueue();
                for (ListGridRecord lgr : lg.getSelectedRecords()) {
                    employeesDS.performCustomOperation("updateCustom", lgr);
                }

                if (!RPCManager.hasCurrentTransactionQueued()) {
                    RPCManager.cancelQueue();
                    RPCManager.startQueue(false);
                } else {
                    RPCManager.sendQueue();
                }
            }
        });
        HLayout buttonsLayout = new HLayout(10) {
            {
                addMembers(reloadBtn, resetBtn, changeBtn);
            }
        };
        VLayout vLayout = new VLayout(10) {
            {
                addMembers(lg, buttonsLayout);
            }
        };
        w.addItem(vLayout);
        w.show();
    }
}
      Employees.java:
      Code:
      package com.smartgwt.sample.server.listener;

import javax.servlet.http.HttpServletRequest;

import com.isomorphic.criteria.AdvancedCriteria;
import com.isomorphic.criteria.DefaultOperators;
import com.isomorphic.criteria.criterion.SimpleCriterion;
import com.isomorphic.datasource.DSRequest;
import com.isomorphic.datasource.DSResponse;
import com.isomorphic.datasource.DataSource;

public class Employees {
    public DSResponse resetCustom(DSRequest request, HttpServletRequest servletRequest) throws Exception {
        DSRequest resetSalaryReq = new DSRequest(request.getDataSourceName(), DataSource.OP_UPDATE, request.getRPCManager());
        resetSalaryReq.setAllowMultiUpdate(true);
        resetSalaryReq.setFieldValue("Salary", 0);
        resetSalaryReq.setAdvancedCriteria(new AdvancedCriteria(new SimpleCriterion("EmployeeId", DefaultOperators.LessOrEqual, 190)));
        resetSalaryReq.execute();

        DSRequest fetchEmployeesReq = new DSRequest(request.getDataSourceName(), DataSource.OP_FETCH, request.getRPCManager());
        fetchEmployeesReq.setAdvancedCriteria(new AdvancedCriteria(new SimpleCriterion("EmployeeId", DefaultOperators.LessOrEqual, 190)));
        DSResponse fetchEmployeesResp = fetchEmployeesReq.execute();

        fetchEmployeesResp.setAffectedRows(fetchEmployeesResp.getTotalRows());
        fetchEmployeesResp.setOperationType(DataSource.OP_UPDATE);

        DSResponse myResponse = new DSResponse().setSuccess();
        myResponse.addRelatedUpdate(fetchEmployeesResp);
        return myResponse;
    }

    public DSResponse updateCustom(DSRequest request, HttpServletRequest servletRequest) throws Exception {
        Long employeeId = (Long) request.getValues().get("EmployeeId");

        if (employeeId.equals(4L) || employeeId.equals(182L))
            return new DSResponse().setFailure("Editing of Charles Madigen and Tamara Kane forbidden");

        DSRequest updateSalaryReq = new DSRequest(request.getDataSourceName(), DataSource.OP_UPDATE, request.getRPCManager());
        updateSalaryReq.setFieldValue("Salary", 1000);
        updateSalaryReq.setAdvancedCriteria(new AdvancedCriteria(new SimpleCriterion("EmployeeId", DefaultOperators.Equals, employeeId)));
        DSResponse updateSalaryResp = updateSalaryReq.execute();

        DSResponse myResponse = new DSResponse().setSuccess();
        myResponse.addRelatedUpdate(updateSalaryResp);
        return myResponse;
    }
}

      Comment

        #4
        You're right, relatedUpdate you're expecting to not affect the GUI indeed should be skipped when updating the cache. To make it clear the reason for that is not the failed queue, but the fact that this particular relatedUpdate is marked as failed.

        This is fixed and will be available for download in nightly builds since Jan 29 (tomorrow).

        Comment

          #5
          Hi Isomorphic,

          thanks a lot. Just to double check:
          The request with the relatedUpdate and the relatedUpdate itself both have status:0, so they are OK themselfes (if I get this right). But both have queueStatus:-1.
          The only status:-1 is for the failed request (which also has a queueStatus:-1).

          Best regards
          Blama

          Comment

            #6
            QueueStatus is not important here. The flow for the response with relatedUpdate is:
            - if response has status<0 (any kind of failure) its error is handled and response does not proceed to updating caches on the client at all
            - if response is OK, then it proceeds to updating caches on the client and each relatedUpdate is checked for its status (*not* the queueStatus), so relatedUpdates with status<0 will be ignored and relatedUpdates with status=0 will proceed to update caches.

            Are you sure about relatedUpdate that is rolled back on server has status:0? This is not what we reproduced with your well shown use case and this is not what's expected. Since the transaction was rolled back on server and the request (producing this relatedUpdate) uses this transaction (cause its "add" operation and you've set the RPCManager), the status for this relatedUpdate is expected to be set to -10 (transaction failed).

            Comment

              #7
              Hi Isomorphic,

              thanks for the explanation.

              Regarding your questions, yes I'm sure.
              Please see the server log. Perhaps this is the 2nd issue I describe in #3. Even though there is a failed request (=Queue fails), there is a COMMIT and no ROLLBACK.
              I'll retest with a more current version, though. These results are from v12.0p_2020-03-11.

              This is the RPC Tab content for the two requests from the Queue:
              Code:
              Failed request:
{
    affectedRows:0,
    data:"Editing of Charles Madigen and Tamara Kane forbidden",
    invalidateCache:false,
    isDSResponse:true,
    operationType:"custom",
    queueStatus:-1,
    status:-1
}

Successful request:
{
    affectedRows:0,
    invalidateCache:false,
    isDSResponse:true,
    operationType:"custom",
    queueStatus:-1,
    relatedUpdates:[
        {
            data:[
                {
                    OrgUnit:"Management",
                    Salary:1000,
                    MaritalStatus:"married",
                    Email:"jlittle@server.com",
                    EmployeeStatus:"active",
                    userOrder:100,
                    ReportsTo:4,
                    Gender:"male",
                    EmployeeId:183,
                    Job:"Mgr Ther Gen",
                    Name:"Joan Little",
                    EmployeeType:"full time"
                }
            ],
            invalidateCache:false,
            isDSResponse:true,
            queueStatus:-1,
            affectedRows:1,
            operationType:"update",
            dataSource:"employees",
            status:0
        }
    ],
    status:0,
    data:null
}

              This is the server log for these:
              Code:
              === 2021-01-28 17:11:56,402 [4-45] INFO  RequestContext - URL: '/builtinds/sc/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 6.3; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0': Moz (Gecko) with Accept-Encoding header
=== 2021-01-28 17:11:56,414 [4-45] DEBUG XML - Parsed XML from (in memory stream): 9ms
=== 2021-01-28 17:11:56,418 [4-45] DEBUG RPCManager - Processing 2 requests.
=== 2021-01-28 17:11:56,419 [4-45] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    values:{
        OrgUnit:"Management",
        Salary:0,
        MaritalStatus:"single",
        Email:"tkane@server.com",
        EmployeeStatus:"active",
        userOrder:112,
        ReportsTo:4,
        Gender:"female",
        EmployeeId:182,
        Job:"Mgr Site Services",
        Name:"Tamara Kane",
        EmployeeType:"part time",
        _selection_1:true
    },
    operationConfig:{
        dataSource:"employees",
        repo:null,
        operationType:"custom",
        textMatchStyle:"exact"
    },
    appID:"builtinApplication",
    operation:"updateCustom",
    oldValues:{
        OrgUnit:"Management",
        Salary:0,
        MaritalStatus:"single",
        Email:"tkane@server.com",
        EmployeeStatus:"active",
        userOrder:112,
        ReportsTo:4,
        Gender:"female",
        EmployeeId:182,
        Job:"Mgr Site Services",
        Name:"Tamara Kane",
        EmployeeType:"part time",
        _selection_1:true
    },
    criteria:{
    }
}
=== 2021-01-28 17:11:56,421 [4-45] DEBUG RPCManager - Request #2 (DSRequest) payload: {
    values:{
        OrgUnit:"Management",
        Salary:0,
        MaritalStatus:"married",
        Email:"jlittle@server.com",
        EmployeeStatus:"active",
        userOrder:100,
        ReportsTo:4,
        Gender:"male",
        EmployeeId:183,
        Job:"Mgr Ther Gen",
        Name:"Joan Little",
        EmployeeType:"full time",
        _selection_1:true
    },
    operationConfig:{
        dataSource:"employees",
        repo:null,
        operationType:"custom",
        textMatchStyle:"exact"
    },
    appID:"builtinApplication",
    operation:"updateCustom",
    oldValues:{
        OrgUnit:"Management",
        Salary:0,
        MaritalStatus:"married",
        Email:"jlittle@server.com",
        EmployeeStatus:"active",
        userOrder:100,
        ReportsTo:4,
        Gender:"male",
        EmployeeId:183,
        Job:"Mgr Ther Gen",
        Name:"Joan Little",
        EmployeeType:"full time",
        _selection_1:true
    },
    criteria:{
    }
}
=== 2021-01-28 17:11:56,421 [4-45] INFO  IDACall - Performing 2 operation(s)
=== 2021-01-28 17:11:56,421 [4-45] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2021-01-28 17:11:56,421 [4-45] DEBUG DeclarativeSecurity - DataSource employees is not in the pre-checked list, processing...
=== 2021-01-28 17:11:56,422 [4-45] DEBUG DataSourceDMI - Freeing resources in DataSourceDMI...
=== 2021-01-28 17:11:56,422 [4-45] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2021-01-28 17:11:56,422 [4-45] DEBUG DeclarativeSecurity - DataSource employees is not in the pre-checked list, processing...
=== 2021-01-28 17:11:56,423 [4-45] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2021-01-28 17:11:56,423 [4-45] DEBUG DeclarativeSecurity - Request is not a client request, ignoring security checks.
=== 2021-01-28 17:11:56,425 [4-45] DEBUG ServerObject - Couldn't find a public method named: update on class: com.smartgwt.sample.server.listener.Employees
=== 2021-01-28 17:11:56,425 [4-45] DEBUG DataSourceDMI - DataSourceDMI: no public method name: update available on class: com.smartgwt.sample.server.listener.Employees - defaulting to builtin operations.
=== 2021-01-28 17:11:56,425 [4-45] DEBUG AppBase - [builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
=== 2021-01-28 17:11:56,425 [4-45] DEBUG AppBase - [builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
=== 2021-01-28 17:11:56,426 [4-45] INFO  SQLDataSource - [builtinApplication.null] Performing update operation with
    criteria: {fieldName:"EmployeeId",_constructor:"AdvancedCriteria",value:183,operator:"equals"}    values: {Salary:1000.0}
=== 2021-01-28 17:11:56,427 [4-45] DEBUG SQLConnectionManager - [builtinApplication.null] Borrowed connection '556364118'
=== 2021-01-28 17:11:56,427 [4-45] DEBUG SQLTransaction - [builtinApplication.null] Started new HSQLDB transaction "556364118"
=== 2021-01-28 17:11:56,427 [4-45] DEBUG SQLDataSource - [builtinApplication.null] Setting DSRequest as being part of a transaction
=== 2021-01-28 17:11:56,427 [4-45] INFO  SQLDriver - [builtinApplication.null] Executing SQL query on 'HSQLDB' using connection '556364118': UPDATE employeeTable SET Salary=1000.0 WHERE (employeeTable.EmployeeId = 183 AND employeeTable.EmployeeId IS NOT NULL)
=== 2021-01-28 17:11:56,428 [4-45] INFO  SQLDataSource - [builtinApplication.null] primaryKeys: {EmployeeId=183}
=== 2021-01-28 17:11:56,428 [4-45] DEBUG SQLDataSource - [builtinApplication.null] Gathered all keys.  lastPrimaryKeys is now {EmployeeId=183}
=== 2021-01-28 17:11:56,428 [4-45] DEBUG SQLDataSource - [builtinApplication.null] update operation affected 1 rows
=== 2021-01-28 17:11:56,428 [4-45] DEBUG DeclarativeSecurity - [builtinApplication.null] Processing security checks for DataSource null, field null
=== 2021-01-28 17:11:56,428 [4-45] DEBUG DeclarativeSecurity - [builtinApplication.null] Request is not a client request, ignoring security checks.
=== 2021-01-28 17:11:56,429 [4-45] DEBUG ServerObject - [builtinApplication.null] Couldn't find a public method named: fetch on class: com.smartgwt.sample.server.listener.Employees
=== 2021-01-28 17:11:56,429 [4-45] DEBUG DataSourceDMI - [builtinApplication.null] DataSourceDMI: no public method name: fetch available on class: com.smartgwt.sample.server.listener.Employees - defaulting to builtin operations.
=== 2021-01-28 17:11:56,429 [4-45] DEBUG AppBase - [builtinApplication.null, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
=== 2021-01-28 17:11:56,429 [4-45] DEBUG AppBase - [builtinApplication.null, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
=== 2021-01-28 17:11:56,429 [4-45] INFO  SQLDataSource - [builtinApplication.null, builtinApplication.null] Performing fetch operation with
    criteria: {EmployeeId:183}    values: {EmployeeId:183}
=== 2021-01-28 17:11:56,430 [4-45] INFO  SQLDataSource - [builtinApplication.null, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
=== 2021-01-28 17:11:56,431 [4-45] DEBUG SQLDataSource - [builtinApplication.null, builtinApplication.null] Using SQL Limit query
=== 2021-01-28 17:11:56,431 [4-45] DEBUG SQLDataSource - [builtinApplication.null, builtinApplication.null] SQL windowed select rows 0->-1, result size 1. Query: SELECT LIMIT 0 1  employeeTable.userOrder, employeeTable.Name, employeeTable.EmployeeId, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus FROM employeeTable WHERE (employeeTable.EmployeeId=183)
=== 2021-01-28 17:11:56,431 [4-45] DEBUG SQLDataSource - [builtinApplication.null, builtinApplication.null] SQL windowed select rows 0->-1, result size 1. Query: SELECT LIMIT 0 1  employeeTable.userOrder, employeeTable.Name, employeeTable.EmployeeId, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus FROM employeeTable WHERE (employeeTable.EmployeeId=183)
=== 2021-01-28 17:11:56,431 [4-45] DEBUG SQLDataSource - [builtinApplication.null, builtinApplication.null] Setting DSRequest as being part of a transaction
=== 2021-01-28 17:11:56,431 [4-45] INFO  SQLDataSource - [builtinApplication.null, builtinApplication.null] 22: Executing cache sync query on 'HSQLDB': SELECT LIMIT 0 1  employeeTable.userOrder, employeeTable.Name, employeeTable.EmployeeId, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus FROM employeeTable WHERE (employeeTable.EmployeeId=183)
=== 2021-01-28 17:11:56,432 [4-45] INFO  DSResponse - [builtinApplication.null] DSResponse: List with 1 items
=== 2021-01-28 17:11:56,432 [4-45] INFO  DSResponse - DSResponse: List with 1 items
=== 2021-01-28 17:11:56,432 [4-45] DEBUG DataSourceDMI - Freeing resources in DataSourceDMI...
=== 2021-01-28 17:11:56,432 [4-45] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2021-01-28 17:11:56,432 [4-45] DEBUG SQLTransaction - Committing HSQLDB transaction "556364118"
=== 2021-01-28 17:11:56,432 [4-45] DEBUG RPCManager - DMI response, dropExtraFields: false
=== 2021-01-28 17:11:56,432 [4-45] DEBUG RPCManager - DMI response, dropExtraFields: false
=== 2021-01-28 17:11:56,433 [4-45] DEBUG DataSourceDMI - Freeing QueueResources in DataSourceDMI
=== 2021-01-28 17:11:56,433 [4-45] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 22
=== 2021-01-28 17:11:56,433 [4-45] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 22
=== 2021-01-28 17:11:56,433 [4-45] DEBUG DataSourceDMI - Freeing QueueResources in DataSourceDMI
=== 2021-01-28 17:11:56,433 [4-45] DEBUG SQLTransaction - getConnection() looked for transactional connection for HSQLDB:  hashcode "556364118"
=== 2021-01-28 17:11:56,433 [4-45] WARN  SQLTransaction - Ending HSQLDB transaction "556364118"
=== 2021-01-28 17:11:56,433 [4-45] DEBUG SQLConnectionManager - About to close connection with hashcode "556364118"
=== 2021-01-28 17:11:56,433 [4-45] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 22
=== 2021-01-28 17:11:56,434 [4-45] INFO  Compression - /builtinds/sc/IDACall: 706 -> 382 bytes
              Best regards
              Blama
              Last edited by Blama; 28 Jan 2021, 09:21.

              Comment

                #8
                Hi Isomorphic,

                just to confirm, behaviour client side (w.r.t. to status -1/-10) and server side (w.r.t. to "COMMIT vs ROLLBACK") is the same in v12.0p_2021-01-16.

                Best regards
                Blama

                Comment

                  #9
                  The fact that committed transaction results in relatedUpdate response with status:0 is expected behavior. So, the real question is why transaction is committed, which is not expected. And that's what we still cannot reproduce on our end. Something must be affecting the transaction management in your environment, like transaction policy setting, please provide more details. Thank you.

                  Comment

                    #10
                    Hi Isomorphic,

                    I retested with version v12.0p_2021-01-29 you mentioned in #4 - 100% the same result.

                    W.r.t COMMIT/ROLLBACK: I do not have a special setting here. This time I just unpacked your zip, imported the project in Eclipse 2020-06 using Win10, changed/added the 3 source files from #3 and run using SuperDevMode in GWT 2.8.2. I still do have a commit in my log (see below).

                    My server.properties is default and does not mention anything specific towards transaction policy. My isomorphic_core_rpc.jar/framework.properties is of course unchanged and has these lines (expected)
                    Code:
                    # System-wide transaction setting
autoJoinTransactions: ANY_CHANGE
...
...
...
# Transactions are switched on at system level by default (see the plain "autoJoinTransactions"
# setting).  You can override that setting per-database with this commented-out property.
# Note that you can also enable/disable transactions on a per-DataSource and per-Operation
# basis - search the client docs for "autoJoinTransactions"
#sql.HSQLDB.autoJoinTransactions: NONE
                    Best regards
                    Blama



                    Full server log from server start to wrongly handled request:
                    Code:
                    Running CodeServer with parameters: [-noprecompile, -port, 9876, -sourceLevel, 1.8, -bindAddress, 127.0.0.1, -launcherDir, C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war, -logLevel, INFO, -style, OBFUSCATED, com.smartgwt.sample.BuiltInDS]
Super Dev Mode starting up
   workDir: C:\Users\st\AppData\Local\Temp\gwt-codeserver-7089409656162491024.tmp
log4j:WARN No appenders could be found for logger (org.eclipse.jetty.util.log).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
   Loading Java files in com.smartgwt.sample.BuiltInDS.
   Module setup completed in 4888 ms

The code server is ready at http://127.0.0.1:9876/
Code server started in 5.216 s ms
[WARN] Server class 'org.springframework.web.SpringServletContainerInitializer' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/spring-web-4.3.20.RELEASE.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
[WARN] Server class 'com.isomorphic.base.InitListener' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/isomorphic_core_rpc.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
[WARN] Server class 'org.apache.log4j.Logger' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/log4j-1.2.17.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
ISC: Configuring log4j from: file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/samples/built-in-ds/war/WEB-INF/classes/log4j.isc.config.xml
[WARN] Server class 'org.apache.commons.collections4.queue.CircularFifoQueue' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/commons-collections4-4.1.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
log4j:WARN No such property [encoding] in com.isomorphic.log.RevolvingMemoryAppender.
=== 2021-02-02 20:46:34,857 [main] INFO  ISCInit - Isomorphic SmartClient/SmartGWT Framework - Initializing
[WARN] Server class 'org.apache.commons.io.output.ProxyOutputStream' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/commons-io-2.5.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:34,865 [main] INFO  ConfigLoader - Attempting to load framework.properties from CLASSPATH
[WARN] Server class 'org.joda.time.DateTime' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/joda-time-2.9.9.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:34,897 [main] INFO  ConfigLoader - Successfully loaded framework.properties from CLASSPATH at location: jar:file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/isomorphic_core_rpc.jar!/framework.properties
=== 2021-02-02 20:46:34,898 [main] INFO  ConfigLoader - Attempting to load project.properties from CLASSPATH
=== 2021-02-02 20:46:34,899 [main] INFO  ConfigLoader - Unable to locate project.properties in CLASSPATH
=== 2021-02-02 20:46:34,904 [main] INFO  ConfigLoader - Successfully loaded isc_interfaces.properties from CLASSPATH at location: jar:file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/isomorphic_core_rpc.jar!/isc_interfaces.properties
=== 2021-02-02 20:46:34,904 [main] INFO  ConfigLoader - Attempting to load server.properties from CLASSPATH
=== 2021-02-02 20:46:34,906 [main] INFO  ConfigLoader - Successfully loaded server.properties from CLASSPATH at location: file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/samples/built-in-ds/war/WEB-INF/classes/server.properties
=== 2021-02-02 20:46:34,909 [main] INFO  Logger - Logging system started.
[WARN] Server class 'com.isomorphic.sql.DBDataSource' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/isomorphic_sql.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
[WARN] Server class 'org.hibernate.proxy.HibernateProxy' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/hibernate3.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
[WARN] Server class 'net.sf.cglib.transform.impl.InterceptFieldEnabled' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/cglib-2.2.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:34,926 [main] INFO  ISCInit - Bound DB defaultDatabase via JNDI at: isomorphic/jdbc/defaultDatabase
=== 2021-02-02 20:46:34,926 [main] INFO  ISCInit - Auto-detected webRoot - using: C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war
=== 2021-02-02 20:46:34,926 [main] INFO  ISCInit - Isomorphic SmartClient/SmartGWT Framework (v12.0p_2021-01-29/PowerEdition Deployment 2021-01-29) - Initialization Complete
[WARN] Server class 'com.isomorphic.compression.ServletCompression' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/isomorphic_compression.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
[WARN] Server class 'com.isomorphic.messaging.MessagingServlet' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/isomorphic_realtime_messaging.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
Linking modules
   Bootstrap link for command-line module 'com.smartgwt.sample.BuiltInDS'
      Linking module 'builtinds'
         Invoking Linker Cross-Site-Iframe
            Ignoring the following script tags in the gwt.xml file
sc/initsc.js
sc/modules/ISC_Core.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Foundation.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Containers.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Grids.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Forms.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_RichTextEditor.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Calendar.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_DataBinding.js?isc_version=12.0p_2021-01-29.js
sc/skins/Enterprise/load_skin.js

   Invoking Linker SmartGwtScriptInjector
      Creating loadScriptTagFiles.js to manually load the following script tags:
sc/initsc.js
sc/modules/ISC_Core.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Foundation.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Containers.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Grids.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Forms.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_RichTextEditor.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Calendar.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_DataBinding.js?isc_version=12.0p_2021-01-29.js
sc/skins/Enterprise/load_skin.js
[WARN] Server class 'org.apache.commons.fileupload.FileItemFactory' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/commons-fileupload-1.3.3.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
[WARN] Server class 'com.isomorphic.js.parser.JSParser' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/isomorphic_js_parser.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:41,529 [0-59] INFO  RequestContext - URL: '/builtinds/sc/DataSourceLoader', User-Agent: 'Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36': Safari with Accept-Encoding header
=== 2021-02-02 20:46:41,534 [0-58] INFO  Compression - /builtinds/builtinds.nocache.js: 2473 -> 1220 bytes
[WARN] Server class 'org.apache.commons.pool.KeyedPoolableObjectFactory' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/commons-pool-1.6.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
[WARN] Server class 'org.apache.commons.jxpath.ri.model.NodePointerFactory' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/commons-jxpath-1.3.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:41,549 [0-60] INFO  Compression - /builtinds/sc/initsc.js: 47 -> 72 bytes
=== 2021-02-02 20:46:41,561 [0-61] INFO  Compression - /builtinds/sc/modules/ISC_Containers.js: 168420 -> 39057 bytes
=== 2021-02-02 20:46:41,576 [0-58] INFO  Compression - /builtinds/sc/modules/ISC_Foundation.js: 381177 -> 88882 bytes
=== 2021-02-02 20:46:41,591 [0-61] INFO  Compression - /builtinds/sc/modules/ISC_RichTextEditor.js: 64415 -> 16755 bytes
=== 2021-02-02 20:46:41,600 [0-59] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\builtinds\sc\system\schema\builtinTypes.xml: 14ms
=== 2021-02-02 20:46:41,617 [0-58] INFO  Compression - /builtinds/sc/modules/ISC_Calendar.js: 292467 -> 70479 bytes
=== 2021-02-02 20:46:41,634 [0-59] INFO  PoolManager - SmartClient pooling started for 'simpleTypes' objects
=== 2021-02-02 20:46:41,639 [0-62] INFO  Compression - /builtinds/sc/modules/ISC_Grids.js: 1106717 -> 282017 bytes
=== 2021-02-02 20:46:41,639 [0-60] INFO  Compression - /builtinds/sc/modules/ISC_Forms.js: 1021442 -> 247658 bytes
=== 2021-02-02 20:46:41,644 [0-48] INFO  Compression - /builtinds/sc/modules/ISC_Core.js: 1285596 -> 336070 bytes
=== 2021-02-02 20:46:41,695 [0-61] INFO  Compression - /builtinds/sc/modules/ISC_DataBinding.js: 1006419 -> 241593 bytes
[WARN] Server class 'org.apache.commons.beanutils.DynaBean' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/commons-beanutils-1.0.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:41,746 [0-59] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\ds\supplyItem.ds.xml: 8ms
=== 2021-02-02 20:46:41,752 [0-59] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\builtinds\sc\system\schema\DataSource.ds.xml: 6ms
[WARN] Server class 'org.apache.velocity.context.Context' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/velocity-1.7.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:41,849 [0-59] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\builtinds\sc\system\schema\DataSourceField.ds.xml: 5ms
=== 2021-02-02 20:46:41,924 [0-59] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\builtinds\sc\system\schema\ValueMap.ds.xml: 6ms
=== 2021-02-02 20:46:41,933 [0-59] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\builtinds\sc\system\schema\Validator.ds.xml: 4ms
=== 2021-02-02 20:46:41,999 [0-59] DEBUG DataSourceLoader - For DataSource 'supplyItem', got instanceId 10
=== 2021-02-02 20:46:42,029 [0-59] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\ds\animals.ds.xml: 7ms
=== 2021-02-02 20:46:42,038 [0-59] DEBUG DataSourceLoader - For DataSource 'animals', got instanceId 14
=== 2021-02-02 20:46:42,050 [0-59] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\ds\employees.ds.xml: 4ms
=== 2021-02-02 20:46:42,063 [0-59] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\builtinds\sc\system\schema\ServerObject.ds.xml: 4ms
=== 2021-02-02 20:46:42,073 [0-59] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\builtinds\sc\system\schema\OperationBinding.ds.xml: 5ms
=== 2021-02-02 20:46:42,094 [0-59] DEBUG DataSourceLoader - For DataSource 'employees', got instanceId 22
=== 2021-02-02 20:46:42,099 [0-59] INFO  Compression - /builtinds/sc/DataSourceLoader: 4919 -> 1967 bytes
GET /recompile/builtinds
   Job com.smartgwt.sample.BuiltInDS_1_0
      starting job: com.smartgwt.sample.BuiltInDS_1_0
      binding: user.agent=safari
      Compiling module com.smartgwt.sample.BuiltInDS
         Unification traversed 605 fields and methods and 233 types. 0 are considered part of the current module and 8 had all of their fields and methods traversed.
         Compiling 1 permutation
            Compiling permutation 0...
            Linking per-type JS with 0 new/changed types.
            Source Maps Enabled
         Compile of permutations succeeded
         Compilation succeeded -- 2.792s
      Linking into C:\Users\st\AppData\Local\Temp\gwt-codeserver-7089409656162491024.tmp\com.smartgwt.sample.BuiltInDS\compile-2\war\builtinds; Writing extras to C:\Users\st\AppData\Local\Temp\gwt-codeserver-7089409656162491024.tmp\com.smartgwt.sample.BuiltInDS\compile-2\extras\builtinds
         Invoking Linker Cross-Site-Iframe
            Ignoring the following script tags in the gwt.xml file
sc/initsc.js
sc/modules/ISC_Core.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Foundation.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Containers.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Grids.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Forms.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_RichTextEditor.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Calendar.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_DataBinding.js?isc_version=12.0p_2021-01-29.js
sc/skins/Enterprise/load_skin.js

   Invoking Linker SmartGwtScriptInjector
      Creating loadScriptTagFiles.js to manually load the following script tags:
sc/initsc.js
sc/modules/ISC_Core.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Foundation.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Containers.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Grids.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Forms.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_RichTextEditor.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_Calendar.js?isc_version=12.0p_2021-01-29.js
sc/modules/ISC_DataBinding.js?isc_version=12.0p_2021-01-29.js
sc/skins/Enterprise/load_skin.js
         Link succeeded
         Linking succeeded -- 3.076s
      7.619s total -- Compile completed
=== 2021-02-02 20:46:50,281 [0-58] INFO  RequestContext - URL: '/builtinds/sc/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36': Safari with Accept-Encoding header
[WARN] Server class 'org.apache.commons.codec.net.URLCodec' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/commons-codec-1.10.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:50,306 [0-58] DEBUG XML - Parsed XML from (in memory stream): 8ms
=== 2021-02-02 20:46:50,313 [0-58] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\builtinds\sc\system\schema\List.ds.xml: 3ms
=== 2021-02-02 20:46:50,313 [0-58] DEBUG ProcessedFileCache - STALE object for file 'C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\builtinds\sc\system\schema\DataSource.ds.xml', reloading (file timestamp 1612298809513, cache timestamp 1612298792766)
=== 2021-02-02 20:46:50,318 [0-58] DEBUG XML - Parsed XML from C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war\builtinds\sc\system\schema\DataSource.ds.xml: 4ms
=== 2021-02-02 20:46:50,354 [0-58] DEBUG RPCManager - Processing 1 requests.
=== 2021-02-02 20:46:50,364 [0-58] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    criteria:{
        fieldName:"EmployeeId",
        operator:"lessOrEqual",
        value:190,
        _constructor:"AdvancedCriteria"
    },
    operationConfig:{
        dataSource:"employees",
        repo:null,
        operationType:"fetch",
        textMatchStyle:"substring"
    },
    startRow:0,
    endRow:75,
    sortBy:[
        "EmployeeId"
    ],
    componentId:"isc_ListGrid_0",
    appID:"builtinApplication",
    operation:"employees_fetch",
    oldValues:{
        fieldName:"EmployeeId",
        operator:"lessOrEqual",
        value:190,
        _constructor:"AdvancedCriteria"
    }
}
=== 2021-02-02 20:46:50,364 [0-58] INFO  IDACall - Performing 1 operation(s) [UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36]
=== 2021-02-02 20:46:50,364 [0-58] INFO  DSRequest - Executing employees.fetch
=== 2021-02-02 20:46:50,366 [0-58] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2021-02-02 20:46:50,366 [0-58] DEBUG DeclarativeSecurity - DataSource employees is not in the pre-checked list, processing...
[WARN] Server class 'org.apache.commons.lang.StringUtils' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/commons-lang-2.6.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:50,422 [0-58] DEBUG ServerObject - Couldn't find a public method named: fetch on class: com.smartgwt.sample.server.listener.Employees
=== 2021-02-02 20:46:50,422 [0-58] DEBUG DataSourceDMI - DataSourceDMI: no public method name: fetch available on class: com.smartgwt.sample.server.listener.Employees - defaulting to builtin operations.
=== 2021-02-02 20:46:50,423 [0-58] DEBUG AppBase - [builtinApplication.employees_fetch] No userTypes defined, allowing anyone access to all operations for this application
=== 2021-02-02 20:46:50,423 [0-58] DEBUG AppBase - [builtinApplication.employees_fetch] No public zero-argument method named '_employees_fetch' found, performing generic datasource operation
=== 2021-02-02 20:46:50,424 [0-58] INFO  SQLDataSource - [builtinApplication.employees_fetch] Performing fetch operation with
    criteria: {fieldName:"EmployeeId",operator:"lessOrEqual",value:190,_constructor:"AdvancedCriteria"}    values: {fieldName:"EmployeeId",operator:"lessOrEqual",value:190,_constructor:"AdvancedCriteria"}
=== 2021-02-02 20:46:50,429 [0-58] DEBUG SQLDriver - [builtinApplication.employees_fetch] HSQLDB: Initializing SQL config usint interface.type: driverManager with driver: org.hsqldb.jdbcDriver
[WARN] Server class 'org.hsqldb.jdbcDriver' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/hsqldb-2.3.4.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:50,433 [0-58] DEBUG SQLDriver - [builtinApplication.employees_fetch] org.hsqldb.jdbcDriver lookup successful
=== 2021-02-02 20:46:50,434 [0-58] DEBUG SQLDriver - [builtinApplication.employees_fetch] HSQLDB: Fetching connection via jdbc url jdbc:hsqldb:file:C:\Users\st\workspace\libs\smartgwtpower-12.0p_2021_01_29\samples\built-in-ds\war/WEB-INF/db/hsqldb/isomorphic
=== 2021-02-02 20:46:50,434 [0-58] DEBUG SQLDriver - [builtinApplication.employees_fetch] HSQLDB: Passing JDBC URL only to getConnection
log4j:WARN No appenders could be found for logger (hsqldb.db..ENGINE).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
=== 2021-02-02 20:46:51,087 [0-58] DEBUG SQLDriver - [builtinApplication.employees_fetch] HSQLDB: Database metadata: {
    driverName:"HSQL Database Engine Driver",
    driverMajorVersion:2,
    driverMinorVersion:3,
    databaseProductName:"HSQL Database Engine",
    databaseProductVersion:"2.3.4",
    databaseMinorVersion:3,
    databaseMajorVersion:2,
    JDBCMinorVersion:0,
    driverVersion:"2.3.4",
    JDBCMajorVersion:4
}
=== 2021-02-02 20:46:51,093 [0-58] DEBUG SQLDataSource - [builtinApplication.employees_fetch] DataSource 22 acquired SQLDriver instance 519731045 during initialization
=== 2021-02-02 20:46:51,101 [0-58] INFO  SQLDataSource - [builtinApplication.employees_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause ORDER BY $defaultOrderClause
=== 2021-02-02 20:46:51,101 [0-58] INFO  Velocity - [builtinApplication.employees_fetch] Velocity Tools not available - using standard Velocity Contexts.
=== 2021-02-02 20:46:51,108 [0-58] DEBUG Velocity - [builtinApplication.employees_fetch] Velocity config: {
}
[WARN] Server class 'org.apache.commons.collections.ExtendedProperties' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/commons-collections-3.2.2.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:51,164 [0-58] DEBUG SQLDataSource - [builtinApplication.employees_fetch] Executing row count query: SELECT COUNT(*) FROM $defaultTableClause WHERE $defaultWhereClause
=== 2021-02-02 20:46:51,165 [0-58] DEBUG SQLDataSource - [builtinApplication.employees_fetch] Eval'd row count query: SELECT COUNT(*) FROM employeeTable WHERE (employeeTable.EmployeeId <= 190 OR employeeTable.EmployeeId IS NULL)
[WARN] Server class 'com.isomorphic.hibernate.HibernateDataSource' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/isomorphic_hibernate.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:51,204 [0-58] INFO  PoolManager - [builtinApplication.employees_fetch] SmartClient pooling started for 'HSQLDB' objects
=== 2021-02-02 20:46:51,205 [0-58] DEBUG PoolableSQLConnectionFactory - [builtinApplication.employees_fetch] makeObject() created a pooled Connection '61466778'
[WARN] Server class 'org.apache.commons.dbcp.PoolableConnection' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/commons-dbcp-1.4.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:51,209 [0-58] DEBUG SQLConnectionManager - [builtinApplication.employees_fetch] Borrowed connection '61466778'
=== 2021-02-02 20:46:51,210 [0-58] INFO  SQLDriver - [builtinApplication.employees_fetch] Executing SQL query on 'HSQLDB' using connection '61466778': SELECT COUNT(*) FROM employeeTable WHERE (employeeTable.EmployeeId <= 190 OR employeeTable.EmployeeId IS NULL)
=== 2021-02-02 20:46:51,216 [0-58] DEBUG SQLDataSource - [builtinApplication.employees_fetch] Using SQL Limit query
=== 2021-02-02 20:46:51,216 [0-58] DEBUG SQLDataSource - [builtinApplication.employees_fetch] SQL windowed select rows 0->75, result size 75. Query: SELECT LIMIT 0 75  employeeTable.userOrder, employeeTable.Name, employeeTable.EmployeeId, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus FROM employeeTable WHERE (employeeTable.EmployeeId <= 190 OR employeeTable.EmployeeId IS NULL) ORDER BY employeeTable.EmployeeId
=== 2021-02-02 20:46:51,216 [0-58] DEBUG SQLDataSource - [builtinApplication.employees_fetch] SQL windowed select rows 0->75, result size 75. Query: SELECT LIMIT 0 75  employeeTable.userOrder, employeeTable.Name, employeeTable.EmployeeId, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus FROM employeeTable WHERE (employeeTable.EmployeeId <= 190 OR employeeTable.EmployeeId IS NULL) ORDER BY employeeTable.EmployeeId
=== 2021-02-02 20:46:51,216 [0-58] INFO  SQLDataSource - [builtinApplication.employees_fetch] 22: Executing  query on 'HSQLDB': SELECT LIMIT 0 75  employeeTable.userOrder, employeeTable.Name, employeeTable.EmployeeId, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus FROM employeeTable WHERE (employeeTable.EmployeeId <= 190 OR employeeTable.EmployeeId IS NULL) ORDER BY employeeTable.EmployeeId
=== 2021-02-02 20:46:51,219 [0-58] INFO  DSResponse - DSResponse: List with 10 items
=== 2021-02-02 20:46:51,219 [0-58] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 22
=== 2021-02-02 20:46:51,219 [0-58] DEBUG SQLDriver - Freeing SQLDriver dbConnection 61466778 for SQLDriver instance 519731045
=== 2021-02-02 20:46:51,219 [0-58] DEBUG SQLConnectionManager - About to close connection with hashcode "61466778"
=== 2021-02-02 20:46:51,219 [0-58] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2021-02-02 20:46:51,221 [0-58] DEBUG RPCManager - non-DMI response, dropExtraFields: false
=== 2021-02-02 20:46:51,224 [0-58] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 22
=== 2021-02-02 20:46:51,224 [0-58] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 22
=== 2021-02-02 20:46:51,224 [0-58] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 22
=== 2021-02-02 20:46:51,225 [0-58] INFO  Compression - /builtinds/sc/IDACall: 2493 -> 646 bytes
=== 2021-02-02 20:46:56,799 [0-60] INFO  RequestContext - URL: '/builtinds/sc/IDACall', User-Agent: 'Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36': Safari with Accept-Encoding header
=== 2021-02-02 20:46:56,811 [0-60] DEBUG XML - Parsed XML from (in memory stream): 9ms
=== 2021-02-02 20:46:56,814 [0-60] DEBUG RPCManager - Processing 2 requests.
=== 2021-02-02 20:46:56,816 [0-60] DEBUG RPCManager - Request #1 (DSRequest) payload: {
    values:{
        OrgUnit:"Management",
        Salary:0,
        MaritalStatus:"single",
        Email:"tkane@server.com",
        EmployeeStatus:"active",
        userOrder:112,
        ReportsTo:4,
        Gender:"female",
        EmployeeId:182,
        Job:"Mgr Site Services",
        Name:"Tamara Kane",
        EmployeeType:"part time",
        _selection_1:true
    },
    operationConfig:{
        dataSource:"employees",
        repo:null,
        operationType:"custom",
        textMatchStyle:"exact"
    },
    appID:"builtinApplication",
    operation:"updateCustom",
    oldValues:{
        OrgUnit:"Management",
        Salary:0,
        MaritalStatus:"single",
        Email:"tkane@server.com",
        EmployeeStatus:"active",
        userOrder:112,
        ReportsTo:4,
        Gender:"female",
        EmployeeId:182,
        Job:"Mgr Site Services",
        Name:"Tamara Kane",
        EmployeeType:"part time",
        _selection_1:true
    },
    criteria:{
    }
}
=== 2021-02-02 20:46:56,816 [0-60] DEBUG RPCManager - Request #2 (DSRequest) payload: {
    values:{
        OrgUnit:"Management",
        Salary:1000,
        MaritalStatus:"married",
        Email:"jlittle@server.com",
        EmployeeStatus:"active",
        userOrder:100,
        ReportsTo:4,
        Gender:"male",
        EmployeeId:183,
        Job:"Mgr Ther Gen",
        Name:"Joan Little",
        EmployeeType:"full time",
        _selection_1:true
    },
    operationConfig:{
        dataSource:"employees",
        repo:null,
        operationType:"custom",
        textMatchStyle:"exact"
    },
    appID:"builtinApplication",
    operation:"updateCustom",
    oldValues:{
        OrgUnit:"Management",
        Salary:1000,
        MaritalStatus:"married",
        Email:"jlittle@server.com",
        EmployeeStatus:"active",
        userOrder:100,
        ReportsTo:4,
        Gender:"male",
        EmployeeId:183,
        Job:"Mgr Ther Gen",
        Name:"Joan Little",
        EmployeeType:"full time",
        _selection_1:true
    },
    criteria:{
    }
}
=== 2021-02-02 20:46:56,816 [0-60] INFO  IDACall - Performing 2 operation(s) [UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36]
=== 2021-02-02 20:46:56,816 [0-60] INFO  DSRequest - Executing employees.custom[operationId: updateCustom]
=== 2021-02-02 20:46:56,816 [0-60] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2021-02-02 20:46:56,817 [0-60] DEBUG DeclarativeSecurity - DataSource employees is not in the pre-checked list, processing...
[WARN] Server class 'com.isomorphic.spring.SpringBeanFactory' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/isomorphic_spring.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
[WARN] Server class 'org.springframework.context.ApplicationContext' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/spring-context-4.3.20.RELEASE.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
[WARN] Server class 'org.springframework.core.env.EnvironmentCapable' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/spring-core-4.3.20.RELEASE.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
[WARN] Server class 'org.springframework.beans.factory.ListableBeanFactory' could not be found in the web app, but was found on the system classpath
   [WARN] Adding classpath entry 'file:/C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/lib/spring-beans-4.3.20.RELEASE.jar' to the web app classpath for this session
   For additional info see: file:/C:/eclipse/plugins/com.gwtplugins.gwt.eclipse.sdkbundle.gwt28_2.8.0.201710131939/gwt-2.8.2/doc/helpInfo/webAppClassPath.html
=== 2021-02-02 20:46:56,836 [0-60] DEBUG DataSourceDMI - Freeing resources in DataSourceDMI...
=== 2021-02-02 20:46:56,836 [0-60] INFO  DSRequest - Executing employees.custom[operationId: updateCustom]
=== 2021-02-02 20:46:56,836 [0-60] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2021-02-02 20:46:56,836 [0-60] DEBUG DeclarativeSecurity - DataSource employees is not in the pre-checked list, processing...
=== 2021-02-02 20:46:56,862 [0-60] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
=== 2021-02-02 20:46:56,862 [0-60] DEBUG DeclarativeSecurity - Request is not a client request, ignoring security checks.
=== 2021-02-02 20:46:56,865 [0-60] DEBUG ServerObject - Couldn't find a public method named: update on class: com.smartgwt.sample.server.listener.Employees
=== 2021-02-02 20:46:56,865 [0-60] DEBUG DataSourceDMI - DataSourceDMI: no public method name: update available on class: com.smartgwt.sample.server.listener.Employees - defaulting to builtin operations.
=== 2021-02-02 20:46:56,866 [0-60] DEBUG AppBase - [builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
=== 2021-02-02 20:46:56,866 [0-60] DEBUG AppBase - [builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
=== 2021-02-02 20:46:56,867 [0-60] INFO  SQLDataSource - [builtinApplication.null] Performing update operation with
    criteria: {fieldName:"EmployeeId",_constructor:"AdvancedCriteria",value:183,operator:"equals"}    values: {Salary:1000.0}
=== 2021-02-02 20:46:56,872 [0-60] DEBUG SQLConnectionManager - [builtinApplication.null] Borrowed connection '61466778'
=== 2021-02-02 20:46:56,873 [0-60] DEBUG SQLTransaction - [builtinApplication.null] Started new HSQLDB transaction "61466778"
=== 2021-02-02 20:46:56,874 [0-60] DEBUG SQLDataSource - [builtinApplication.null] Setting DSRequest as being part of a transaction
=== 2021-02-02 20:46:56,874 [0-60] INFO  SQLDriver - [builtinApplication.null] Executing SQL query on 'HSQLDB' using connection '61466778': UPDATE employeeTable SET Salary=1000.0 WHERE (employeeTable.EmployeeId = 183 AND employeeTable.EmployeeId IS NOT NULL)
=== 2021-02-02 20:46:56,881 [0-60] INFO  SQLDataSource - [builtinApplication.null] primaryKeys: {EmployeeId=183}
=== 2021-02-02 20:46:56,881 [0-60] DEBUG SQLDataSource - [builtinApplication.null] Gathered all keys.  lastPrimaryKeys is now {EmployeeId=183}
=== 2021-02-02 20:46:56,881 [0-60] DEBUG SQLDataSource - [builtinApplication.null] update operation affected 1 rows
=== 2021-02-02 20:46:56,882 [0-60] DEBUG DeclarativeSecurity - [builtinApplication.null] Processing security checks for DataSource null, field null
=== 2021-02-02 20:46:56,882 [0-60] DEBUG DeclarativeSecurity - [builtinApplication.null] Request is not a client request, ignoring security checks.
=== 2021-02-02 20:46:56,883 [0-60] DEBUG ServerObject - [builtinApplication.null] Couldn't find a public method named: fetch on class: com.smartgwt.sample.server.listener.Employees
=== 2021-02-02 20:46:56,883 [0-60] DEBUG DataSourceDMI - [builtinApplication.null] DataSourceDMI: no public method name: fetch available on class: com.smartgwt.sample.server.listener.Employees - defaulting to builtin operations.
=== 2021-02-02 20:46:56,883 [0-60] DEBUG AppBase - [builtinApplication.null, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
=== 2021-02-02 20:46:56,883 [0-60] DEBUG AppBase - [builtinApplication.null, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
=== 2021-02-02 20:46:56,883 [0-60] INFO  SQLDataSource - [builtinApplication.null, builtinApplication.null] Performing fetch operation with
    criteria: {EmployeeId:183}    values: {EmployeeId:183}
=== 2021-02-02 20:46:56,884 [0-60] INFO  SQLDataSource - [builtinApplication.null, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
=== 2021-02-02 20:46:56,884 [0-60] DEBUG SQLDataSource - [builtinApplication.null, builtinApplication.null] Using SQL Limit query
=== 2021-02-02 20:46:56,884 [0-60] DEBUG SQLDataSource - [builtinApplication.null, builtinApplication.null] SQL windowed select rows 0->-1, result size 1. Query: SELECT LIMIT 0 1  employeeTable.userOrder, employeeTable.Name, employeeTable.EmployeeId, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus FROM employeeTable WHERE (employeeTable.EmployeeId=183)
=== 2021-02-02 20:46:56,884 [0-60] DEBUG SQLDataSource - [builtinApplication.null, builtinApplication.null] SQL windowed select rows 0->-1, result size 1. Query: SELECT LIMIT 0 1  employeeTable.userOrder, employeeTable.Name, employeeTable.EmployeeId, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus FROM employeeTable WHERE (employeeTable.EmployeeId=183)
=== 2021-02-02 20:46:56,884 [0-60] DEBUG SQLDataSource - [builtinApplication.null, builtinApplication.null] Setting DSRequest as being part of a transaction
=== 2021-02-02 20:46:56,884 [0-60] INFO  SQLDataSource - [builtinApplication.null, builtinApplication.null] 22: Executing cache sync query on 'HSQLDB': SELECT LIMIT 0 1  employeeTable.userOrder, employeeTable.Name, employeeTable.EmployeeId, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus FROM employeeTable WHERE (employeeTable.EmployeeId=183)
=== 2021-02-02 20:46:56,885 [0-60] INFO  DSResponse - [builtinApplication.null] DSResponse: List with 1 items
=== 2021-02-02 20:46:56,885 [0-60] INFO  DSResponse - DSResponse: List with 1 items
=== 2021-02-02 20:46:56,885 [0-60] DEBUG DataSourceDMI - Freeing resources in DataSourceDMI...
=== 2021-02-02 20:46:56,885 [0-60] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
=== 2021-02-02 20:46:56,885 [0-60] DEBUG SQLTransaction - Committing HSQLDB transaction "61466778"
=== 2021-02-02 20:46:56,886 [0-60] DEBUG RPCManager - DMI response, dropExtraFields: false
=== 2021-02-02 20:46:56,886 [0-60] DEBUG RPCManager - DMI response, dropExtraFields: false
=== 2021-02-02 20:46:56,887 [0-60] DEBUG DataSourceDMI - Freeing QueueResources in DataSourceDMI
=== 2021-02-02 20:46:56,887 [0-60] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 22
=== 2021-02-02 20:46:56,887 [0-60] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 22
=== 2021-02-02 20:46:56,887 [0-60] DEBUG DataSourceDMI - Freeing QueueResources in DataSourceDMI
=== 2021-02-02 20:46:56,887 [0-60] DEBUG SQLTransaction - getConnection() looked for transactional connection for HSQLDB:  hashcode "61466778"
=== 2021-02-02 20:46:56,887 [0-60] WARN  SQLTransaction - Ending HSQLDB transaction "61466778"
=== 2021-02-02 20:46:56,887 [0-60] DEBUG SQLConnectionManager - About to close connection with hashcode "61466778"
=== 2021-02-02 20:46:56,888 [0-60] DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 22
=== 2021-02-02 20:46:56,888 [0-60] INFO  Compression - /builtinds/sc/IDACall: 706 -> 382 bytes
=== 2021-02-02 20:46:57,013 [0-48] INFO  RequestContext - URL: '/builtinds/sc/system/reference/skin/images/server_network_closed.png', User-Agent: 'Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36': Safari with Accept-Encoding header
=== 2021-02-02 20:46:57,013 [0-62] INFO  RequestContext - URL: '/builtinds/sc/system/reference/skin/images/opener_opened.png', User-Agent: 'Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36': Safari with Accept-Encoding header
=== 2021-02-02 20:46:57,016 [0-48] INFO  Download - File C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/samples/built-in-ds/war/builtinds/sc/system/reference/skin/images/server_network_closed.png not found, sending 404
=== 2021-02-02 20:46:57,016 [0-62] INFO  Download - File C:/Users/st/workspace/libs/smartgwtpower-12.0p_2021_01_29/samples/built-in-ds/war/builtinds/sc/system/reference/skin/images/opener_opened.png not found, sending 404
[WARN] 404 - GET /builtinds/sc/system/reference/skin/images/opener_opened.png (127.0.0.1) 343 bytes
   Request headers
[WARN] 404 - GET /builtinds/sc/system/reference/skin/images/server_network_closed.png (127.0.0.1) 351 bytes
   Request headers
            Host: 127.0.0.1:8888
Host: 127.0.0.1:8888
            Connection: keep-alive
      User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36
      Accept: image/avif,image/webp,image/apng,image/*,*/*;q=0.8
      Sec-Fetch-Site: same-origin
      Sec-Fetch-Mode: no-cors
      Sec-Fetch-Dest: image
      Referer: http://127.0.0.1:8888/builtinds/sc/system/helpers/Log.html
      Accept-Encoding: gzip, deflate, br
      Accept-Language: de-DE,de;q=0.9,en-US;q=0.8,en;q=0.7
      Connection: keep-alive
      User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36
      Accept: image/avif,image/webp,image/apng,image/*,*/*;q=0.8
      Sec-Fetch-Site: same-origin
      Sec-Fetch-Mode: no-cors
      Sec-Fetch-Dest: image
      Referer: http://127.0.0.1:8888/builtinds/sc/system/helpers/Log.html
Cookie: isc_cState=ready; GLog=%7B%0A%20%20%20%20trackRPC%3Atrue%2C%20%0A%20%20%20%20isc_pageURL%3A%22http%3A//127.0.0.1%3A8888/BuiltInDS.html%22%2C%20%0A%20%20%20%20isc_pageGUID%3A%222D3C8EDC-F9D5-4C05-85C6-A1A9617C26E5%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%3A-1277%2C%20%0A%20%20%20%20top%3A428%2C%20%0A%20%20%20%20width%3A1280%2C%20%0A%20%20%20%20height%3A629%0A%7D; JSESSIONID=he8gjul6ep0u1qlablf0ow179
      Accept-Encoding: gzip, deflate, br
      Accept-Language: de-DE,de;q=0.9,en-US;q=0.8,en;q=0.7
      Cookie: isc_cState=ready; GLog=%7B%0A%20%20%20%20trackRPC%3Atrue%2C%20%0A%20%20%20%20isc_pageURL%3A%22http%3A//127.0.0.1%3A8888/BuiltInDS.html%22%2C%20%0A%20%20%20%20isc_pageGUID%3A%222D3C8EDC-F9D5-4C05-85C6-A1A9617C26E5%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%3A-1277%2C%20%0A%20%20%20%20top%3A428%2C%20%0A%20%20%20%20width%3A1280%2C%20%0A%20%20%20%20height%3A629%0A%7D; JSESSIONID=he8gjul6ep0u1qlablf0ow179
      Response headers
Response headers
            Date: Tue, 02 Feb 2021 20:46:57 GMT
      Content-Type: text/html; charset=ISO-8859-1
      Cache-Control: must-revalidate,no-cache,no-store
      Content-Length: 351
Date: Tue, 02 Feb 2021 20:46:57 GMT
      Content-Type: text/html; charset=ISO-8859-1
      Cache-Control: must-revalidate,no-cache,no-store
      Content-Length: 343

                    Comment

                      #11
                      Ok, finally it's clear what's going on. The reason is that the behavior depends on the request processing order. Transaction is started when we hit first transactional request in a queue, which in your case it is the first *executed* nested 'add' request.

                      Your use case:
                      - 'custom' Request #1 fails (no transaction yet)
                      - 'custom' Request #2 (creates nested 'add' request)
                      ---- nested 'add' request (starts transaction and succeeds)

                      Alternative order:
                      - 'custom' Request #1 (creates nested 'add' request)
                      ---- nested 'add' request (starts transaction and succeeds)
                      - 'custom' Request #2 fails (since transaction is already created it is rolled back)

                      So, in your case there's no reason for the transaction to be rolled back cause there were no failures since it was started, so it is committed. In alternative use case transaction is already in progress when we hit failed request #2, so it is rolled back. To avoid this you could make you custom requests part of transaction so that any failure in your setup would mean failure for the complete queue and would issue the rollback:
                      Code:
                      public DSResponse updateCustom(DSRequest request, HttpServletRequest servletRequest) throws Exception {
        [b][B]// Make request part of transaction[/b][/B]
        [b][B]request.setPartOfTransaction(true);[/b][/B]

        Long employeeId = (Long) request.getValues().get("EmployeeId");

        if (employeeId.equals(4L) || employeeId.equals(182L))
            return new DSResponse().setFailure("Editing of Charles Madigen and Tamara Kane forbidden");

        DSRequest updateSalaryReq = new DSRequest(request.getDataSourceName(), DataSource.OP_UPDATE, request.getRPCManager());
        updateSalaryReq.setFieldValue("Salary", 1000);
        updateSalaryReq.setAdvancedCriteria(new AdvancedCriteria(new SimpleCriterion("EmployeeId", DefaultOperators.Equals, employeeId)));
        DSResponse updateSalaryResp = updateSalaryReq.execute();

        DSResponse myResponse = new DSResponse().setSuccess();
        myResponse.addRelatedUpdate(updateSalaryResp);
        return myResponse;
    }
                      Note that you would probably want to skip any DB updates if you already know they will be rolled back. So, with setting 'custom' requests as part of transaction or without, you may check request.getRPCManager().queueHasFailures() and skip creating unnecessary nested 'add' requests.

                      Comment

                      Previous template Next
                      Working...
                      X