Announcement

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

  • Blama
    replied
    Validation error server log (timestamps removed for better diff):
    Code:
    DEBUG RPCManager - Processing 1 requests.
    DEBUG RPCManager - Request #1 (DSRequest) payload: {
        values:{
            AVAILABLE:true,
            PRODUCTCATEGORY_ID:132,
            PRODUCTCATEGORY_NAME:"Hardware",
            SHORTNAME:"TEST",
            NAME:"TEST"
        },
        operationConfig:{
            dataSource:"T_PRODUCT",
            repo:null,
            operationType:"add",
            textMatchStyle:"exact"
        },
        componentId:"isc_ProductProductcategoryList_0",
        appID:"builtinApplication",
        operation:"T_PRODUCT_add",
        oldValues:{
            AVAILABLE:true,
            PRODUCTCATEGORY_ID:132,
            PRODUCTCATEGORY_NAME:"Hardware",
            SHORTNAME:"TEST",
            NAME:"TEST"
        },
        criteria:{
        }
    }
    INFO  LMSIDACall - Performing 1 operation(s)
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add] No userTypes defined, allowing anyone access to all operations for this application
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add] No public zero-argument method named '_T_PRODUCT_add' found, performing generic datasource operation
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Performing fetch operation with
        outputs: [PRODUCTCATEGORY_NAME, ID]    criteria: {PRODUCTCATEGORY_NAME:"Hardware",TENANT_ID:15}    values: {PRODUCTCATEGORY_NAME:"Hardware",TENANT_ID:15}
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause$defaultAnsiJoinClause WHERE $defaultWhereClause
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] 71541: Executing SQL query on 'Oracle': SELECT T_PRODUCT.ID, T_PRODUCTCATEGORY.NAME AS PRODUCTCATEGORY_NAME FROM T_PRODUCT JOIN T_PRODUCTCATEGORY ON T_PRODUCT.PRODUCTCATEGORY_ID = T_PRODUCTCATEGORY.ID WHERE (LOWER(T_PRODUCTCATEGORY.NAME)='hardware' AND T_PRODUCT.TENANT_ID=15)
    DEBUG SQLTransaction - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Started new Oracle transaction "138153241"
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Setting DSRequest as being part of a transaction
    INFO  SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Executing SQL query on 'Oracle' using connection '138153241': SELECT T_PRODUCT.ID, T_PRODUCTCATEGORY.NAME AS PRODUCTCATEGORY_NAME FROM T_PRODUCT JOIN T_PRODUCTCATEGORY ON T_PRODUCT.PRODUCTCATEGORY_ID = T_PRODUCTCATEGORY.ID WHERE (LOWER(T_PRODUCTCATEGORY.NAME)='hardware' AND T_PRODUCT.TENANT_ID=15)
    INFO  DSResponse - [builtinApplication.T_PRODUCT_add] DSResponse: List with 3 items
    DEBUG ValidationContext - [builtinApplication.T_PRODUCT_add] Adding validation errors at path '/T_PRODUCT/PRODUCTCATEGORY_NAME/PRODUCTCATEGORY_NAME': {errorMessage=Der Name wird bereits verwendet!}
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Performing fetch operation with
        outputs: [SHORTNAME, ID]    criteria: {SHORTNAME:"TEST",TENANT_ID:15}    values: {SHORTNAME:"TEST",TENANT_ID:15}
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] 71541: Executing SQL query on 'Oracle': SELECT T_PRODUCT.ID, T_PRODUCT.SHORTNAME FROM T_PRODUCT WHERE (LOWER(T_PRODUCT.SHORTNAME)='test' AND T_PRODUCT.TENANT_ID=15)
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Setting DSRequest as being part of a transaction
    INFO  SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Executing SQL query on 'Oracle' using connection '138153241': SELECT T_PRODUCT.ID, T_PRODUCT.SHORTNAME FROM T_PRODUCT WHERE (LOWER(T_PRODUCT.SHORTNAME)='test' AND T_PRODUCT.TENANT_ID=15)
    INFO  DSResponse - [builtinApplication.T_PRODUCT_add] DSResponse: List with 0 items
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Performing fetch operation with
        outputs: [ID, NAME]    criteria: {TENANT_ID:15,NAME:"TEST"}    values: {TENANT_ID:15,NAME:"TEST"}
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] 71541: Executing SQL query on 'Oracle': SELECT T_PRODUCT.ID, T_PRODUCT.NAME FROM T_PRODUCT WHERE (T_PRODUCT.TENANT_ID=15 AND LOWER(T_PRODUCT.NAME)='test')
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Setting DSRequest as being part of a transaction
    INFO  SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Executing SQL query on 'Oracle' using connection '138153241': SELECT T_PRODUCT.ID, T_PRODUCT.NAME FROM T_PRODUCT WHERE (T_PRODUCT.TENANT_ID=15 AND LOWER(T_PRODUCT.NAME)='test')
    INFO  DSResponse - [builtinApplication.T_PRODUCT_add] DSResponse: List with 0 items
    INFO  Validation - [builtinApplication.T_PRODUCT_add] Validation error: [
        {
            PRODUCTCATEGORY_NAME:{
                errorMessage:"Der Name wird bereits verwendet!"
            }
        }
    ]
    DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
    DEBUG SQLTransaction - Rolling back Oracle transaction "138153241"
    DEBUG SQLTransaction - Rolling back Oracle transaction "138153241"
    DEBUG SQLTransaction - Rolling back Oracle transaction "138153241"
    DEBUG SQLTransaction - Rolling back Oracle transaction "138153241"
    DEBUG RPCManager - non-DMI response, dropExtraFields: false
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 71541
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 72877
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 72876
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 72876
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 72877
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 72878
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 72878
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 7426
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 7426
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 71541
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 71541
    DEBUG SQLTransaction - getConnection() looked for transactional connection for Oracle:  hashcode "138153241"
    DEBUG SQLTransaction - Ending Oracle transaction "138153241"
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 71541
    DEBUG SQLTransaction - getConnection() looked for transactional connection for Oracle:  (connection is null)
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 71541
    DEBUG SQLTransaction - getConnection() looked for transactional connection for Oracle:  (connection is null)
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 71541
    INFO  Compression - /lms/lms/sc/IDACall: 240 -> 209 bytes
    Successful add log (timestamps removed for better diff):
    Code:
    DEBUG RPCManager - Processing 1 requests.
    DEBUG RPCManager - Request #1 (DSRequest) payload: {
        values:{
            AVAILABLE:true,
            PRODUCTCATEGORY_ID:13,
            PRODUCTCATEGORY_NAME:"Hardware",
            SHORTNAME:"TEST",
            NAME:"TEST"
        },
        operationConfig:{
            dataSource:"T_PRODUCT",
            repo:null,
            operationType:"add",
            textMatchStyle:"exact"
        },
        componentId:"isc_ProductProductcategoryList_0",
        appID:"builtinApplication",
        operation:"T_PRODUCT_add",
        oldValues:{
            AVAILABLE:true,
            PRODUCTCATEGORY_ID:13,
            PRODUCTCATEGORY_NAME:"Hardware",
            SHORTNAME:"TEST",
            NAME:"TEST"
        },
        criteria:{
        }
    }
    INFO  LMSIDACall - Performing 1 operation(s)
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add] No userTypes defined, allowing anyone access to all operations for this application
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add] No public zero-argument method named '_T_PRODUCT_add' found, performing generic datasource operation
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Performing fetch operation with
        outputs: [SHORTNAME, ID]    criteria: {SHORTNAME:"TEST",TENANT_ID:1}    values: {SHORTNAME:"TEST",TENANT_ID:1}
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] 846: Executing SQL query on 'Oracle': SELECT T_PRODUCT.ID, T_PRODUCT.SHORTNAME FROM T_PRODUCT WHERE (LOWER(T_PRODUCT.SHORTNAME)='test' AND T_PRODUCT.TENANT_ID=1)
    DEBUG SQLTransaction - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Started new Oracle transaction "295365807"
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Setting DSRequest as being part of a transaction
    INFO  SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Executing SQL query on 'Oracle' using connection '295365807': SELECT T_PRODUCT.ID, T_PRODUCT.SHORTNAME FROM T_PRODUCT WHERE (LOWER(T_PRODUCT.SHORTNAME)='test' AND T_PRODUCT.TENANT_ID=1)
    INFO  DSResponse - [builtinApplication.T_PRODUCT_add] DSResponse: List with 0 items
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Performing fetch operation with
        outputs: [ID, NAME]    criteria: {TENANT_ID:1,NAME:"TEST"}    values: {TENANT_ID:1,NAME:"TEST"}
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] 846: Executing SQL query on 'Oracle': SELECT T_PRODUCT.ID, T_PRODUCT.NAME FROM T_PRODUCT WHERE (T_PRODUCT.TENANT_ID=1 AND LOWER(T_PRODUCT.NAME)='test')
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Setting DSRequest as being part of a transaction
    INFO  SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Executing SQL query on 'Oracle' using connection '295365807': SELECT T_PRODUCT.ID, T_PRODUCT.NAME FROM T_PRODUCT WHERE (T_PRODUCT.TENANT_ID=1 AND LOWER(T_PRODUCT.NAME)='test')
    INFO  DSResponse - [builtinApplication.T_PRODUCT_add] DSResponse: List with 0 items
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add] Performing add operation with
        criteria: {AVAILABLE:true,PRODUCTCATEGORY_ID:13,PRODUCTCATEGORY_NAME:"Hardware",SHORTNAME:"TEST",NAME:"TEST",CREATED_BY:"1",CREATED_AT:new Date(1478609414484),MODIFIED_BY:"1",MODIFIED_AT:new Date(1478609414484)}    values: {AVAILABLE:true,PRODUCTCATEGORY_ID:13,PRODUCTCATEGORY_NAME:"Hardware",SHORTNAME:"TEST",NAME:"TEST",CREATED_BY:"1",CREATED_AT:new Date(1478609414484),MODIFIED_BY:"1",MODIFIED_AT:new Date(1478609414484),TENANT_ID:1}
    INFO  SQLValuesClause - [builtinApplication.T_PRODUCT_add] Ignored data for non-existent or included columns: [PRODUCTCATEGORY_NAME]
    DEBUG SQLValuesClause - [builtinApplication.T_PRODUCT_add] Sequences: {ID=__default}
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add] Setting DSRequest as being part of a transaction
    INFO  SQLDriver - [builtinApplication.T_PRODUCT_add] Executing SQL query on 'Oracle' using connection '295365807': INSERT INTO T_PRODUCT (AVAILABLE, CREATED_AT, CREATED_BY, MODIFIED_AT, MODIFIED_BY, NAME, PRODUCTCATEGORY_ID, SHORTNAME, TENANT_ID, ID) VALUES ('Y', TO_DATE('2016-11-08 13:50:14','YYYY-MM-DD HH24:MI:SS'), '1', TO_DATE('2016-11-08 13:50:14','YYYY-MM-DD HH24:MI:SS'), '1', 'TEST', 13, 'TEST', 1, T_PRODUCT_ID.NextVal)
    DEBUG SQLDriver - [builtinApplication.T_PRODUCT_add] SequenceMode is not JDBC_DRIVER, skipping search for generated values
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add] add operation affected 1 rows
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add] Setting DSRequest as being part of a transaction
    INFO  SQLDriver - [builtinApplication.T_PRODUCT_add] Executing SQL query on 'Oracle' using connection '295365807': SELECT T_PRODUCT_ID.CurrVal FROM DUAL
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add] primaryKeys: {ID=1116}
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add] Oracle getLastRow(): using default operationBinding
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Performing fetch operation with
        criteria: {_constructor:"AdvancedCriteria",criteria:[{fieldName:"TENANT_ID",value:1,operator:"equals"},{fieldName:"ID",value:"1116",operator:"iEquals"},{fieldName:"CREATED_BY_TENANT_ID",value:1,operator:"equals"},{fieldName:"MODIFIED_BY_TENANT_ID",value:1,operator:"equals"},{fieldName:"PRODUCTCATEGORY_TENANT_ID",value:1,operator:"equals"}],operator:"and"}    values: {_constructor:"AdvancedCriteria",criteria:[{fieldName:"TENANT_ID",value:1,operator:"equals"},{fieldName:"ID",value:"1116",operator:"iEquals"},{fieldName:"CREATED_BY_TENANT_ID",value:1,operator:"equals"},{fieldName:"MODIFIED_BY_TENANT_ID",value:1,operator:"equals"},{fieldName:"PRODUCTCATEGORY_TENANT_ID",value:1,operator:"equals"}],operator:"and"}
    INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause$defaultAnsiJoinClause WHERE $defaultWhereClause
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] JDBC driver windowed select rows 0->-1, result size 1. Query: SELECT T_PRODUCT.ID, T_PRODUCT.TENANT_ID, T_PRODUCT.CREATED_BY, T_PRODUCT.CREATED_AT, T_PRODUCT.MODIFIED_BY, T_PRODUCT.MODIFIED_AT, T_PRODUCT.SHORTNAME, T_PRODUCT.NAME, T_PRODUCT.DESCRIPTION, T_PRODUCT.PRODUCTCATEGORY_ID, T_PRODUCT.AVAILABLE, T_PRODUCTCATEGORY.NAME AS PRODUCTCATEGORY_NAME, USER_CREATED_BY.TENANT_ID AS CREATED_BY_TENANT_ID, USER_MODIFIED_BY.TENANT_ID AS MODIFIED_BY_TENANT_ID, T_PRODUCTCATEGORY.TENANT_ID AS PRODUCTCATEGORY_TENANT_ID FROM T_PRODUCT JOIN T_PRODUCTCATEGORY ON T_PRODUCT.PRODUCTCATEGORY_ID = T_PRODUCTCATEGORY.ID JOIN MV_USER_DATA USER_CREATED_BY ON T_PRODUCT.CREATED_BY = USER_CREATED_BY.ID JOIN MV_USER_DATA USER_MODIFIED_BY ON T_PRODUCT.MODIFIED_BY = USER_MODIFIED_BY.ID WHERE ((T_PRODUCT.TENANT_ID = 1 AND T_PRODUCT.TENANT_ID IS NOT NULL) AND (LOWER(T_PRODUCT.ID) = LOWER('1116') AND T_PRODUCT.ID IS NOT NULL) AND (USER_CREATED_BY.TENANT_ID = 1 AND USER_CREATED_BY.TENANT_ID IS NOT NULL) AND (USER_MODIFIED_BY.TENANT_ID = 1 AND USER_MODIFIED_BY.TENANT_ID IS NOT NULL) AND (T_PRODUCTCATEGORY.TENANT_ID = 1 AND T_PRODUCTCATEGORY.TENANT_ID IS NOT NULL))
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Setting DSRequest as being part of a transaction
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Using paging strategy 'jdbcScroll' - scrolling to absolute position 1
    DEBUG SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Scrolling / positioning took 0ms
    INFO  DSResponse - [builtinApplication.T_PRODUCT_add] DSResponse: List with 1 items
    INFO  DSResponse - DSResponse: List with 1 items
    DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
    DEBUG SQLTransaction - Committing Oracle transaction "295365807"
    DEBUG SQLTransaction - Committing Oracle transaction "295365807"
    DEBUG SQLTransaction - Committing Oracle transaction "295365807"
    DEBUG SQLTransaction - Committing Oracle transaction "295365807"
    DEBUG RPCManager - non-DMI response, dropExtraFields: false
    DEBUG SQLTransaction - getConnection() looked for transactional connection for Oracle:  hashcode "295365807"
    DEBUG SQLTransaction - Ending Oracle transaction "295365807"
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 846
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 818
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 817
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 817
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 818
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 819
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 819
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 371
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 371
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 846
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 846
    DEBUG SQLTransaction - getConnection() looked for transactional connection for Oracle:  (connection is null)
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 846
    DEBUG SQLTransaction - getConnection() looked for transactional connection for Oracle:  (connection is null)
    DEBUG SQLDataSource - About to clear SQLDriver state for DS instance 846
    INFO  Compression - /lms/lms/sc/IDACall: 450 -> 280 bytes
    The hint on the missing "Ignored data for non-existent or included columns" in the validation error case was most likely not helpful, as this happens at add-time, which the unsuccessful case never reaches.
    The question is:
    • Why is the unique check done for the included field?
    It would be great if you could look into this one. I'll help where I can, but as I myself see this only spurious, I don't know what I can do?

    Best regards
    Blama
    Last edited by Blama; 8 Nov 2016, 05:29.

    Leave a comment:


  • Blama
    replied
    Hi Isomorphic,

    exact the same thing is happening again now.
    "Funny" thing is that it does happen on the production server, but not on my test machine (both using v10.1p_2016-11-03 and the same source code). I again failed to create a testcase for it.
    I will post both logs, though. Perhaps this does help.

    Best regards
    Blama

    Leave a comment:


  • Blama
    replied
    Hi Isomorphic,

    besides some days passing and a server restart nothing was changed for sure. As it was a one time thing and I can't reproduce lets call it a mystery.

    Please note though that I don't think the error (if any) is with the copying the validators (I thought it was copied indeed, but the framework never needed to run the validators here because of the following).
    IMHO the problem started here: My log (contrary to the provided testcase) does not include this row: "Ignored data for non-existent or included columns: [ReportsToName]".
    If the data would have get filtered away, a validator later on would have had no work in the first place.

    Best regards
    Blama

    PS: Thanks for investigating here!

    Leave a comment:


  • Isomorphic
    replied
    We cannot reproduce this, and nor can we speculate as to how it might arise. We agree that your log seems to show unequivocally that we are running a validation on an included field, but the code which deals with copying the attributes of included fields to the target field in the including DataSource explicitly excludes all validators, and that part of the code has not changed since 2012.

    As a matter of interest, we see the exact pattern shown in your log if an isUnique validator is manually applied to the included field - is it possible that some kind of cut/paste error meant that the PRODUCTCATEGORY_NAME field actually did have such a validator defined at the time of your first test? If not then we're stumped - we will need a repro case to investigate further.

    Regards
    ​Isomorphic Software Support

    Leave a comment:


  • Isomorphic
    replied
    Hi Blama,
    Sorry for the silence - this is assigned to a developer, but nothing to report yet.
    We'll take a look and see if we can determine why this would be happening, bearing in mind your observations about it being not always reproducible / potentially reliant on another factor, and get back to you.

    Regards
    Isomorphic Software

    Leave a comment:


  • Blama
    replied
    Hi Isomorphic,

    I just restested with SNAPSHOT_v10.1d_2015-10-13 which does not show the behavior. I then tested again in the same installation where the log is from with *no changes* (still on v10.0p_2015-10-08, no new build/deploy. I restarted the server, though, but this should not matter). Now it does not show the issue. I'm pretty confused now but I know what I saw (and I do have the log). Is there a chance that this is depending on something else that can make the bug spurious? I do not think so, but the observation made is more than strange.

    Best regards
    Blama

    Leave a comment:


  • Blama
    replied
    Hi Isomorphic,

    did you figure out what is causing this? I know this is not a perfect testcase, but it shows the error and the area responsible for this is hopefully not to big.

    Best regards
    Blama

    Leave a comment:


  • Regression with unique validator unnecessary imported and run for includeFrom field

    Hi Isomorphic,

    I found a bug in v10.0p_2015-10-08/PowerEdition Deployment that was not there in August.
    For a includeFrom-field where the base field has a unique-validator, the validator seems to be included as well. This renders 1:n cardinalities to 1:1, as you can't have a parent entry more than once in a child table.
    I tried hard to create a testcase (I even "copied" the BuildInDS schema and data to Oracle, as I could not reproduce in HSQLDB), but was not able to do so. But I'm pretty sure you can find the problem from the last code changes in this area.

    This is the server log:
    Code:
    === 2015-10-09 23:09:02,310 [c-29] DEBUG RPCManager - Request #1 (DSRequest) payload: {
        values:{
            AVAILABLE:true,
            PRODUCTCATEGORY_ID:92,
            PRODUCTCATEGORY_NAME:"PARENTENTRY_NAME",
            SHORTNAME:"ChildEntry",
            NAME:"ChildEntry"
        },
        operationConfig:{
            dataSource:"T_PRODUCT",
            repo:null,
            operationType:"add",
            textMatchStyle:"exact"
        },
        componentId:"isc_ProductProductcategoryList_6",
        appID:"builtinApplication",
        operation:"T_PRODUCT_add",
        oldValues:{
            AVAILABLE:true,
            PRODUCTCATEGORY_ID:92,
            PRODUCTCATEGORY_NAME:"PARENTENTRY_NAME",
            SHORTNAME:"ChildEntry",
            NAME:"ChildEntry"
        },
        criteria:{
        }
    }
    === 2015-10-09 23:09:02,310 [c-29] INFO  LMSIDACall - Performing 1 operation(s)
    === 2015-10-09 23:09:02,311 [c-29] DEBUG AppBase - [builtinApplication.T_PRODUCT_add] No userTypes defined, allowing anyone access to all operations for this application
    === 2015-10-09 23:09:02,311 [c-29] DEBUG AppBase - [builtinApplication.T_PRODUCT_add] No public zero-argument method named '_T_PRODUCT_add' found, performing generic datasource operation
    === 2015-10-09 23:09:02,311 [c-29] DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    === 2015-10-09 23:09:02,311 [c-29] DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    === 2015-10-09 23:09:02,311 [c-29] INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Performing fetch operation with
        outputs: [NAME, ID]    criteria: {NAME:"ChildEntry",TENANT_ID:15}    values: {NAME:"ChildEntry",TENANT_ID:15}
    === 2015-10-09 23:09:02,312 [c-29] INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    === 2015-10-09 23:09:02,312 [c-29] INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] 688: Executing SQL query on 'Oracle': SELECT T_PRODUCT.ID, T_PRODUCT.NAME FROM T_PRODUCT WHERE (LOWER(T_PRODUCT.NAME)='childentry' AND T_PRODUCT.TENANT_ID=15)
    === 2015-10-09 23:09:02,312 [c-29] DEBUG SQLConnectionManager - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Borrowed connection '2087315966'
    === 2015-10-09 23:09:02,312 [c-29] DEBUG SQLTransaction - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Started new Oracle transaction "2087315966"
    === 2015-10-09 23:09:02,312 [c-29] DEBUG SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] About to execute SQL query in 'Oracle' using connection '2087315966'
    === 2015-10-09 23:09:02,312 [c-29] INFO  SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Executing SQL query on 'Oracle': SELECT T_PRODUCT.ID, T_PRODUCT.NAME FROM T_PRODUCT WHERE (LOWER(T_PRODUCT.NAME)='childentry' AND T_PRODUCT.TENANT_ID=15)
    === 2015-10-09 23:09:02,313 [c-29] INFO  DSResponse - [builtinApplication.T_PRODUCT_add, builtinApplication.null] DSResponse: List with 0 items
    === 2015-10-09 23:09:02,313 [c-29] DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    === 2015-10-09 23:09:02,313 [c-29] DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    === 2015-10-09 23:09:02,314 [c-29] INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Performing fetch operation with
        outputs: [ID, SHORTNAME]    criteria: {SHORTNAME:"ChildEntry",TENANT_ID:15}    values: {SHORTNAME:"ChildEntry",TENANT_ID:15}
    === 2015-10-09 23:09:02,314 [c-29] INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    === 2015-10-09 23:09:02,314 [c-29] INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] 688: Executing SQL query on 'Oracle': SELECT T_PRODUCT.ID, T_PRODUCT.SHORTNAME FROM T_PRODUCT WHERE (LOWER(T_PRODUCT.SHORTNAME)='childentry' AND T_PRODUCT.TENANT_ID=15)
    === 2015-10-09 23:09:02,314 [c-29] DEBUG SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] About to execute SQL query in 'Oracle' using connection '2087315966'
    === 2015-10-09 23:09:02,314 [c-29] INFO  SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Executing SQL query on 'Oracle': SELECT T_PRODUCT.ID, T_PRODUCT.SHORTNAME FROM T_PRODUCT WHERE (LOWER(T_PRODUCT.SHORTNAME)='childentry' AND T_PRODUCT.TENANT_ID=15)
    === 2015-10-09 23:09:02,315 [c-29] INFO  DSResponse - [builtinApplication.T_PRODUCT_add, builtinApplication.null] DSResponse: List with 0 items
    === 2015-10-09 23:09:02,315 [c-29] DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    === 2015-10-09 23:09:02,315 [c-29] DEBUG AppBase - [builtinApplication.T_PRODUCT_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    === 2015-10-09 23:09:02,315 [c-29] INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Performing fetch operation with
        outputs: [ID, PRODUCTCATEGORY_NAME]    criteria: {PRODUCTCATEGORY_NAME:"PARENTENTRY_NAME",TENANT_ID:15}    values: {PRODUCTCATEGORY_NAME:"PARENTENTRY_NAME",TENANT_ID:15}
    === 2015-10-09 23:09:02,316 [c-29] INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause$defaultAnsiJoinClause WHERE $defaultWhereClause
    === 2015-10-09 23:09:02,316 [c-29] INFO  SQLDataSource - [builtinApplication.T_PRODUCT_add, builtinApplication.null] 688: Executing SQL query on 'Oracle': SELECT T_PRODUCT.ID, T_PRODUCTCATEGORY.NAME AS PRODUCTCATEGORY_NAME FROM T_PRODUCT JOIN T_PRODUCTCATEGORY ON T_PRODUCT.PRODUCTCATEGORY_ID = T_PRODUCTCATEGORY.ID WHERE (LOWER(T_PRODUCTCATEGORY.NAME)='parententry_name' AND T_PRODUCT.TENANT_ID=15)
    === 2015-10-09 23:09:02,316 [c-29] DEBUG SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] About to execute SQL query in 'Oracle' using connection '2087315966'
    === 2015-10-09 23:09:02,316 [c-29] INFO  SQLDriver - [builtinApplication.T_PRODUCT_add, builtinApplication.null] Executing SQL query on 'Oracle': [B]SELECT T_PRODUCT.ID, T_PRODUCTCATEGORY.NAME AS PRODUCTCATEGORY_NAME FROM T_PRODUCT JOIN T_PRODUCTCATEGORY ON T_PRODUCT.PRODUCTCATEGORY_ID = T_PRODUCTCATEGORY.ID WHERE (LOWER(T_PRODUCTCATEGORY.NAME)='parententry_name' AND T_PRODUCT.TENANT_ID=15)[/B]
    === 2015-10-09 23:09:02,317 [c-29] INFO  DSResponse - [builtinApplication.T_PRODUCT_add, builtinApplication.null] DSResponse: List with 1 items
    === 2015-10-09 23:09:02,318 [c-29] DEBUG ValidationContext - [builtinApplication.T_PRODUCT_add] Adding validation errors at path '/T_PRODUCT/PRODUCTCATEGORY_NAME/PRODUCTCATEGORY_NAME': {errorMessage=Der Name wird bereits verwendet!}
    === 2015-10-09 23:09:02,318 [c-29] INFO  Validation - [builtinApplication.T_PRODUCT_add] Validation error: [
        {
            PRODUCTCATEGORY_NAME:{
                errorMessage:"Der Name wird bereits verwendet!"
            }
        }
    ]
    === 2015-10-09 23:09:02,318 [c-29] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
    === 2015-10-09 23:09:02,318 [c-29] DEBUG SQLTransaction - Rolling back Oracle transaction "2087315966"
    === 2015-10-09 23:09:02,318 [c-29] DEBUG RPCManager - non-DMI response, dropExtraFields: false
    === 2015-10-09 23:09:02,318 [c-29] DEBUG SQLTransaction - getConnection() found transactional connection for Oracle with hashcode "2087315966"
    === 2015-10-09 23:09:02,318 [c-29] DEBUG SQLTransaction - Ending Oracle transaction "2087315966"
    === 2015-10-09 23:09:02,319 [c-29] DEBUG SQLConnectionManager - About to close connection with hashcode "2087315966"
    === 2015-10-09 23:09:02,319 [c-29] DEBUG SQLTransaction - getConnection() found transactional connection for Oracle (connection is null)
    === 2015-10-09 23:09:02,319 [c-29] DEBUG SQLTransaction - getConnection() found transactional connection for Oracle (connection is null)
    === 2015-10-09 23:09:02,319 [c-29] INFO  Compression - /***/lms/sc/IDACall: 240 -> 209 bytes
    Please see the bold SELECT-statement. It contains a join, but should only be about T_PRODUCT.

    These are the .ds.xml, if needed:
    T_PRODUCT.ds.xml:
    Code:
    <DataSource dbName="Oracle" tableName="T_PRODUCT" ID="T_PRODUCT" serverType="sql"
        serverConstructor="com.lmscompany.lms.server.LMSSQLDataSource">
        <fields>
            <field primaryKey="true" hidden="true" name="ID" type="sequence" />
            <field hidden="true" name="TENANT_ID" type="integer" canEdit="false" />
            <field foreignKey="V_USER_CREATED_BY.ID" relatedTableAlias="USER_CREATED_BY" name="CREATED_BY" title="Erstellt von" type="creator" />
            <field name="CREATED_AT" title="Erstellt am" type="creatorTimestamp" />
            <field foreignKey="V_USER_MODIFIED_BY.ID" relatedTableAlias="USER_MODIFIED_BY" name="MODIFIED_BY" title="Geändert von" type="modifier" />
            <field name="MODIFIED_AT" title="Geändert am" type="modifierTimestamp" />
            <field name="SHORTNAME" title="Kurzname" length="30" type="text" escapeHTML="true" required="true">
                <validators>
                    <validator type="isUnique" errorMessage="Der Kurzname wird bereits verwendet!" />
                </validators>
            </field>
            <field name="NAME" title="Name" length="60" type="text" escapeHTML="true" required="true">
                <validators>
                    <validator type="isUnique" errorMessage="Der Name wird bereits verwendet!" />
                </validators>
            </field>
            <field name="DESCRIPTION" title="Beschreibung" length="1000" type="text" escapeHTML="true" />
            <field foreignKey="T_PRODUCTCATEGORY.ID" name="PRODUCTCATEGORY_ID" title="Produktkategorie" displayField="PRODUCTCATEGORY_NAME" type="integer" />
            <field name="PRODUCTCATEGORY_NAME" includeFrom="T_PRODUCTCATEGORY.NAME" title="Produktkategorie" length="60" type="text" escapeHTML="true"
                canEdit="false" />
            <field name="AVAILABLE" title="Verfügbar?" type="boolean" escapeHTML="true" sqlStorageStrategy="singleCharYN" required="true" />
            <!-- TENANT_IDs for WHERE-clause generation -->
            <field name="CREATED_BY_TENANT_ID" includeFrom="V_USER_CREATED_BY.TENANT_ID" hidden="true" />
            <field name="MODIFIED_BY_TENANT_ID" includeFrom="V_USER_MODIFIED_BY.TENANT_ID" hidden="true" />
            <field name="PRODUCTCATEGORY_TENANT_ID" includeFrom="T_PRODUCTCATEGORY.TENANT_ID" hidden="true" />
        </fields>
        <operationBindings>
        </operationBindings>
    </DataSource>
    T_PRODUCT_CATEGORY.ds.xml:
    Code:
    <DataSource dbName="Oracle" tableName="T_PRODUCTCATEGORY" ID="T_PRODUCTCATEGORY" serverType="sql"
        serverConstructor="com.lmscompany.lms.server.LMSSQLDataSource">
        <fields>
            <field primaryKey="true" hidden="true" name="ID" type="sequence" />
            <field hidden="true" name="TENANT_ID" type="integer" canEdit="false" />
            <field foreignKey="V_USER_CREATED_BY.ID" relatedTableAlias="USER_CREATED_BY" name="CREATED_BY" title="Erstellt von" type="creator" />
            <field name="CREATED_AT" title="Erstellt am" type="creatorTimestamp" />
            <field foreignKey="V_USER_MODIFIED_BY.ID" relatedTableAlias="USER_MODIFIED_BY" name="MODIFIED_BY" title="Geändert von" type="modifier" />
            <field name="MODIFIED_AT" title="Geändert am" type="modifierTimestamp" />
            <field name="SHORTNAME" title="Kurzname" length="30" type="text" escapeHTML="true" required="true">
                <validators>
                    <validator type="isUnique" errorMessage="Der Kurzname wird bereits verwendet!" />
                </validators>
            </field>
            <field name="NAME" title="Name" length="60" type="text" escapeHTML="true" required="true">
                <validators>
                    <validator type="isUnique" errorMessage="Der Name wird bereits verwendet!" />
                </validators>
            </field>
            <field name="DESCRIPTION" title="Beschreibung" length="1000" type="text" escapeHTML="true" />
        </fields>
        <operationBindings>
            <operationBinding operationType="add" />
            <operationBinding operationType="update" />
        </operationBindings>
    </DataSource>

    I attached my test case as files (add employees2 in the DataSourceLoader-string in the html as well!).
    Here is the add-log for the testcase:
    Code:
    === 2015-10-09 23:36:50,914 [3-31] DEBUG RPCManager - Request #1 (DSRequest) payload: {
        values:{
            Name:"TEST",
            ReportsTo:4,
            ReportsToName:"Charles Madigen",
            Job:"TEST1"
        },
        operationConfig:{
            dataSource:"employees",
            repo:null,
            operationType:"add",
            textMatchStyle:"exact"
        },
        componentId:"isc_ListGrid_0",
        appID:"builtinApplication",
        operation:"employees_add",
        oldValues:{
            Name:"TEST",
            ReportsTo:4,
            ReportsToName:"Charles Madigen",
            Job:"TEST1"
        },
        criteria:{
        }
    }
    === 2015-10-09 23:36:50,914 [3-31] INFO  IDACall - Performing 1 operation(s)
    === 2015-10-09 23:36:50,914 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'employees'
    === 2015-10-09 23:36:50,914 [3-31] DEBUG PoolableDataSourceFactory - Activated DataSource 29 of type 'employees'
    === 2015-10-09 23:36:50,915 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'employees2'
    === 2015-10-09 23:36:50,915 [3-31] DEBUG PoolableDataSourceFactory - Activated DataSource 25 of type 'employees2'
    === 2015-10-09 23:36:50,915 [3-31] DEBUG Relation - Caching instance of toDS 'employees2' in the DSRequest map
    === 2015-10-09 23:36:50,915 [3-31] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
    === 2015-10-09 23:36:50,915 [3-31] DEBUG DeclarativeSecurity - DataSource employees is not in the pre-checked list, processing...
    === 2015-10-09 23:36:50,916 [3-31] DEBUG AppBase - [builtinApplication.employees_add] No userTypes defined, allowing anyone access to all operations for this application
    === 2015-10-09 23:36:50,916 [3-31] DEBUG AppBase - [builtinApplication.employees_add] No public zero-argument method named '_employees_add' found, performing generic datasource operation
    === 2015-10-09 23:36:50,917 [3-31] DEBUG DeclarativeSecurity - [builtinApplication.employees_add] Processing security checks for DataSource null, field null
    === 2015-10-09 23:36:50,918 [3-31] DEBUG AppBase - [builtinApplication.employees_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    === 2015-10-09 23:36:50,918 [3-31] DEBUG AppBase - [builtinApplication.employees_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    === 2015-10-09 23:36:50,919 [3-31] INFO  SQLDataSource - [builtinApplication.employees_add, builtinApplication.null] Performing fetch operation with
        outputs: [Name, EmployeeId]    criteria: {Name:"TEST"}    values: {Name:"TEST"}
    === 2015-10-09 23:36:50,920 [3-31] INFO  SQLDataSource - [builtinApplication.employees_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
    === 2015-10-09 23:36:50,921 [3-31] INFO  SQLDataSource - [builtinApplication.employees_add, builtinApplication.null] 29: Executing SQL query on 'OracleAdmin': SELECT employeeTable.EmployeeId, employeeTable.Name FROM employeeTable WHERE (LOWER(employeeTable.Name)='test')
    === 2015-10-09 23:36:50,921 [3-31] DEBUG PoolableSQLConnectionFactory - [builtinApplication.employees_add, builtinApplication.null] Executing pingTest 'select 1 from dual' on connection 1265710057
    === 2015-10-09 23:36:50,923 [3-31] DEBUG SQLConnectionManager - [builtinApplication.employees_add, builtinApplication.null] Borrowed connection '1265710057'
    === 2015-10-09 23:36:50,923 [3-31] DEBUG SQLTransaction - [builtinApplication.employees_add, builtinApplication.null] Started new OracleAdmin transaction "1265710057"
    === 2015-10-09 23:36:50,923 [3-31] DEBUG SQLDriver - [builtinApplication.employees_add, builtinApplication.null] About to execute SQL query in 'OracleAdmin' using connection '1265710057'
    === 2015-10-09 23:36:50,923 [3-31] INFO  SQLDriver - [builtinApplication.employees_add, builtinApplication.null] Executing SQL query on 'OracleAdmin': SELECT employeeTable.EmployeeId, employeeTable.Name FROM employeeTable WHERE (LOWER(employeeTable.Name)='test')
    === 2015-10-09 23:36:50,930 [3-31] INFO  DSResponse - [builtinApplication.employees_add, builtinApplication.null] DSResponse: List with 0 items
    === 2015-10-09 23:36:50,931 [3-31] DEBUG DSRequest - [builtinApplication.employees_add] freeOnExecute is false for request of type fetch on DataSource employees - not freeing resources!
    === 2015-10-09 23:36:50,932 [3-31] INFO  SQLDataSource - [builtinApplication.employees_add] Performing add operation with
        criteria: {Name:"TEST",ReportsTo:4,ReportsToName:"Charles Madigen",Job:"TEST1"}    values: {Name:"TEST",ReportsTo:4,ReportsToName:"Charles Madigen",Job:"TEST1"}
    === 2015-10-09 23:36:50,933 [3-31] INFO  SQLValuesClause - [builtinApplication.employees_add] [B]Ignored data for non-existent or included columns: [ReportsToName][/B]
    === 2015-10-09 23:36:50,933 [3-31] DEBUG SQLValuesClause - [builtinApplication.employees_add] Sequences: {EmployeeId=__default}
    === 2015-10-09 23:36:50,935 [3-31] DEBUG SQLDriver - [builtinApplication.employees_add] About to execute SQL update in 'OracleAdmin' using connection'1265710057'
    === 2015-10-09 23:36:50,935 [3-31] INFO  SQLDriver - [builtinApplication.employees_add] Executing SQL update on 'OracleAdmin': INSERT INTO employeeTable (Job, Name, ReportsTo, EmployeeId) VALUES ('TEST1', 'TEST', 4, employeeTable_EmployeeId.NextVal)
    === 2015-10-09 23:36:50,939 [3-31] DEBUG SQLDriver - [builtinApplication.employees_add] SequenceMode is not JDBC_DRIVER, skipping search for generated values
    === 2015-10-09 23:36:50,939 [3-31] DEBUG SQLDataSource - [builtinApplication.employees_add] add operation affected 1 rows
    === 2015-10-09 23:36:50,942 [3-31] DEBUG SQLDriver - [builtinApplication.employees_add] About to execute SQL query in 'OracleAdmin' using connection '1265710057'
    === 2015-10-09 23:36:50,942 [3-31] INFO  SQLDriver - [builtinApplication.employees_add] Executing SQL query on 'OracleAdmin': SELECT employeeTable_EmployeeId.CurrVal FROM DUAL
    === 2015-10-09 23:36:50,945 [3-31] INFO  SQLDataSource - [builtinApplication.employees_add] primaryKeys: {EmployeeId=1000}
    === 2015-10-09 23:36:50,946 [3-31] DEBUG ISCKeyedObjectPool - [builtinApplication.employees_add] Borrowing object for 'employees'
    === 2015-10-09 23:36:50,949 [3-31] DEBUG PoolableDataSourceFactory - [builtinApplication.employees_add] Created DataSource 36 of type 'employees' and assigned it to thread qtp1028027903-31
    === 2015-10-09 23:36:50,949 [3-31] DEBUG PoolableDataSourceFactory - [builtinApplication.employees_add] Created DataSource 36 of type 'employees' in the pooling flow
    === 2015-10-09 23:36:50,949 [3-31] DEBUG PoolableDataSourceFactory - [builtinApplication.employees_add] Activated DataSource 36 of type 'employees'
    === 2015-10-09 23:36:50,949 [3-31] DEBUG DeclarativeSecurity - [builtinApplication.employees_add] Processing security checks for DataSource null, field null
    === 2015-10-09 23:36:50,950 [3-31] DEBUG DeclarativeSecurity - [builtinApplication.employees_add] DataSource employees is not in the pre-checked list, processing...
    === 2015-10-09 23:36:50,950 [3-31] DEBUG DeclarativeSecurity - [builtinApplication.employees_add] Processing security checks for DataSource employees2, field EmployeeId
    === 2015-10-09 23:36:50,950 [3-31] DEBUG DeclarativeSecurity - [builtinApplication.employees_add] DataSource employees2 is not in the pre-checked list, processing...
    === 2015-10-09 23:36:50,950 [3-31] DEBUG DeclarativeSecurity - [builtinApplication.employees_add] Processing security checks for DataSource employees2, field Name
    === 2015-10-09 23:36:50,950 [3-31] DEBUG DeclarativeSecurity - [builtinApplication.employees_add] DataSource employees2 is not in the pre-checked list, processing...
    === 2015-10-09 23:36:50,951 [3-31] DEBUG AppBase - [builtinApplication.employees_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
    === 2015-10-09 23:36:50,951 [3-31] DEBUG AppBase - [builtinApplication.employees_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
    === 2015-10-09 23:36:50,952 [3-31] INFO  SQLDataSource - [builtinApplication.employees_add, builtinApplication.null] Performing fetch operation with
        criteria: {EmployeeId:"1000"}    values: {EmployeeId:"1000"}
    === 2015-10-09 23:36:50,953 [3-31] INFO  SQLDataSource - [builtinApplication.employees_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause AND $defaultJoinWhereClause
    === 2015-10-09 23:36:50,954 [3-31] INFO  SQLDataSource - [builtinApplication.employees_add, builtinApplication.null] 19: Executing SQL query on 'OracleAdmin': SELECT employeeTable.EmployeeId, employeeTable.Name, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus, bugHereAsWell.Name AS ReportsToName FROM employeeTable bugHereAsWell, employeeTable WHERE (employeeTable.EmployeeId=1000) AND employeeTable.ReportsTo = bugHereAsWell.EmployeeId
    === 2015-10-09 23:36:50,954 [3-31] DEBUG SQLDriver - [builtinApplication.employees_add, builtinApplication.null] About to execute SQL query in 'OracleAdmin' using connection '1265710057'
    === 2015-10-09 23:36:50,954 [3-31] INFO  SQLDriver - [builtinApplication.employees_add, builtinApplication.null] Executing SQL query on 'OracleAdmin': SELECT employeeTable.EmployeeId, employeeTable.Name, employeeTable.ReportsTo, employeeTable.Job, employeeTable.Email, employeeTable.EmployeeType, employeeTable.EmployeeStatus, employeeTable.Salary, employeeTable.OrgUnit, employeeTable.Gender, employeeTable.MaritalStatus, bugHereAsWell.Name AS ReportsToName FROM employeeTable bugHereAsWell, employeeTable WHERE (employeeTable.EmployeeId=1000) AND employeeTable.ReportsTo = bugHereAsWell.EmployeeId
    === 2015-10-09 23:36:50,960 [3-31] INFO  DSResponse - [builtinApplication.employees_add, builtinApplication.null] DSResponse: List with 1 items
    === 2015-10-09 23:36:50,961 [3-31] DEBUG DSRequest - [builtinApplication.employees_add] freeOnExecute is false for request of type fetch on DataSource employees - not freeing resources!
    === 2015-10-09 23:36:50,961 [3-31] INFO  DSResponse - [builtinApplication.employees_add] DSResponse: List with 1 items
    === 2015-10-09 23:36:50,961 [3-31] DEBUG DSRequest - freeOnExecute is false for request of type add on DataSource employees - not freeing resources!
    === 2015-10-09 23:36:50,961 [3-31] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
    === 2015-10-09 23:36:50,961 [3-31] DEBUG SQLTransaction - Committing OracleAdmin transaction "1265710057"
    === 2015-10-09 23:36:50,963 [3-31] DEBUG RPCManager - non-DMI response, dropExtraFields: false
    === 2015-10-09 23:36:50,964 [3-31] DEBUG SQLTransaction - getConnection() found transactional connection for OracleAdmin with hashcode "1265710057"
    === 2015-10-09 23:36:50,964 [3-31] DEBUG SQLTransaction - Ending OracleAdmin transaction "1265710057"
    === 2015-10-09 23:36:50,965 [3-31] DEBUG SQLConnectionManager - About to close connection with hashcode "1265710057"
    === 2015-10-09 23:36:50,965 [3-31] DEBUG PoolableSQLConnectionFactory - Executing pingTest 'select 1 from dual' on connection 1265710057
    === 2015-10-09 23:36:50,966 [3-31] DEBUG PoolableDataSourceFactory - Cleared and passivated DataSource 25 of type 'employees2'
    === 2015-10-09 23:36:50,966 [3-31] DEBUG PoolableDataSourceFactory - Cleared and passivated DataSource 36 of type 'employees'
    === 2015-10-09 23:36:50,966 [3-31] DEBUG PoolableDataSourceFactory - Cleared and passivated DataSource 19 of type 'employees'
    === 2015-10-09 23:36:50,966 [3-31] DEBUG SQLTransaction - getConnection() found transactional connection for OracleAdmin (connection is null)
    === 2015-10-09 23:36:50,966 [3-31] DEBUG PoolableDataSourceFactory - Cleared and passivated DataSource 29 of type 'employees'
    === 2015-10-09 23:36:50,967 [3-31] DEBUG DSRequest - Ignoring freeResources call because this is not a primary request!
    === 2015-10-09 23:36:50,967 [3-31] DEBUG DSRequest - Ignoring freeQueueResources call because this is not a primary request!
    === 2015-10-09 23:36:50,967 [3-31] INFO  Compression - /builtinds/sc/IDACall: 239 -> 196 bytes
    Please note the "Ignored data for non-existent or included columns: [ReportsToName]". This is missing in the erroneous one, which does two unique-check queries.
    I'd think that this one is a pretty severe one.

    Best regards
    Blama
    Attached Files
    Last edited by Blama; 9 Jan 2017, 02:18. Reason: Removed sensitive information
Working...
X