Announcement

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

    Bug when updating a form having valuesManager

    I have a big problem with the newest SmartGWT versions and I think there is a bug.

    My testcase:
    Code:
    public class TestingModule implements EntryPoint {
    
    	ListGrid lg = new ListGrid();
    
    	public void onModuleLoad() {
    
    		final ValuesManager mainFormValuesManager = new ValuesManager();
    		mainFormValuesManager.setDataSource(DataSource.get("table"));
    		mainFormValuesManager.setSaveOperationType(DSOperationType.ADD);
    
    		DynamicForm singleFieldForm = new DynamicForm();
    		TextItem formItem = new TextItem("f_name", "Name");
    		singleFieldForm.setFields(formItem);
    		singleFieldForm.setDataSource(mainFormValuesManager.getDataSource());
    		singleFieldForm.setValuesManager(mainFormValuesManager);
    		mainFormValuesManager.addMember(singleFieldForm);
    
    		VLayout vlayout = new VLayout();
    		vlayout.setHeight100();
    		vlayout.setWidth100();
    		vlayout.addMember(singleFieldForm);
    
    		final IButton button = new IButton("Add");
    		button.addClickHandler(new ClickHandler() {
    
    			@Override
    			public void onClick(ClickEvent event) {
    				if (mainFormValuesManager.validate()) {
    					mainFormValuesManager.saveData(new DSCallback() {
    
    						@Override
    						public void execute(DSResponse dsResponse, Object data,
    								DSRequest dsRequest) {
    							SC.say("Correctly saved");
    						}
    					});
    				}
    			}
    		});
    
    		ListGrid lg = new ListGrid();
    		ListGridField idField = new ListGridField("f_schueler_id");
    		idField.setHidden(true);
    		ListGridField nameField = new ListGridField("f_name", "Name");
    		lg.setFields(nameField);
    		lg.setHeight100();
    		lg.setWidth100();
    		lg.setDataSource(DataSource.get("table"));
    		lg.setAutoFetchData(true);
    		lg.setSortField("f_name");
    
    		lg.addCellClickHandler(new CellClickHandler() {
    
    			@Override
    			public void onCellClick(CellClickEvent event) {
    				ListGridRecord clicked = event.getRecord();
    				Integer id = clicked.getAttributeAsInt("f_schueler_id");
    
    				mainFormValuesManager
    						.setSaveOperationType(DSOperationType.UPDATE);
    				Criteria c = new Criteria();
    				c.addCriteria("f_schueler_id", id);
    
    				mainFormValuesManager.fetchData(c);
    				button.setTitle("Update");
    			}
    		});
    
    		vlayout.addMember(button);
    		vlayout.addMember(lg);
    
    		vlayout.draw();
    	}
    
    }
    The datasource:
    Code:
    <DataSource ID="table" serverType="sql" tableName="t_schueler" 
    	 >
    
    	<fields>
    		<field name="f_schueler_id" type="sequence" primaryKey="true" />
    		<field name="f_name" type="text" required="true" />
    		
    	</fields>
    </DataSource>
    You have to have some values in the table.. There is nothing special about it.

    In order to reproduce the bug:
    1) Write some value to the "Name" field, e.g. "abc".
    2) Click on "Add". The value is added to the table.
    3) Double click on ANOTHER value of the listGrid. In my case, I double clicked on "Bob".
    The value "Bob" is shown in the form and the button text updated to "Update". The form is not longer an "add" form, but an "update" form.
    4) Click on the button "update". It should update the "Bob" record.

    The value "abc" is shown in the form after clicking on "update" !!!!!!!
    From now on, every time you click on "update", you will see "abc".
    This is NOT correct!
    And was not the case with earlier SmartGWT versions. I testet with the libs in my client's computer, and everything worked correctly. Unfortunately, I cannot downgrade to those old smartGWT libs because there I found another smartGWT bug, which was solved when upgrading smartGWT... so I am in a deadlock now!

    Using SmartGWT 4.1p Power (SmartClient Version: v9.1p_2014-08-19/PowerEdition Deployment (built 2014-08-19).
    I also tested with the latest SmartGWT Version (2014-09-03) but the bug is still there...
    Last edited by edulid; 3 Sep 2014, 13:13.

    #2
    Hello edulid, Hello Isomorphic,

    the chances that this is related are low, but I'll add the link to this thread anyway. I think I couldn't solve it at that time. Afterwards I changed the code for other reasons, so I can't retest now.

    Best regards,
    Blama

    Comment


      #3
      Just a note to say we're looking into this, but our initial investigation isn't reproducing the problem.
      Can we just clarify the steps

      - load the app. Assume you have a few lines of data.
      - enter a value (say "abc") and hit "Add" (a new row is successfully added)
      - select a row other than the new "abc" row - form item value changes to reflect this.
      - Modify the value (say enter "xxx") and hit update

      At this stage in our testing the selected record is modified correctly and the form item continues to show the saved value ("xxx"). Can you confirm exactly what behavior you're seeing?

      Thanks
      Isomorphic Software

      Comment


        #4
        Hi Isomorphic,

        the steps you mentioned are correct.
        The behavior I'm observing is that, after the last step, so after hitting the update button, the form item shows "abc" (the added value) instead of the updated value "xxx" which, as you mentioned, is modified correctly.

        From this moment on, I see "abc" every time I hit the update button after selecting some row.
        EVEN WITH ANOTHER BROWSER, so this is very strange. Say, AFTER the mentioned steps, I do the following:

        - Load the application with another browser
        - Click on a value to load it onto the form item.
        - Optionally change the value, but this is not necessary.
        - Hit update
        I then see "abc"! So this value is saved somewhere in the server, since I changed the browser!
        The only way to stop this behavior is to restart Apache.
        Last edited by edulid; 3 Sep 2014, 22:42.

        Comment


          #5
          There is no plausible mechanism by which framework code could be storing this value permanently at the JVM level (we do not put anything in the HttpSession at all) so you should investigate any custom logic you have added server-side - this is not a framework issue.

          Comment


            #6
            I don't have any server-side logic, since I created the testcase I posted here and that is all.
            With older versions of smartGWT the behavior is different, so it must be a framework issue. The only thing I changed is the smartGWT version. If I load the old version in my client's machine, the behavior is correct. If I load the new smartGWT version, the behavior is incorrect. So what other explanation do you have for this?

            Comment


              #7
              We weren't able to reproduce the issue with your test case, and again you seem to be claiming some kind of server-side persistence, which doesn't make sense.

              We'd suggest you very carefully check your environment to figure out how it differs from the standard SDK and/or try running your test code in a newly installed SDK without any resources from your existing project.

              You can also of course examine the logs to verify that the correct values are being passed to the server, and the correct SQL updates being generated.

              Comment


                #8
                As you suggested, I integrated my test case into a new project that doesn't use any resources from my existing project (I integrated it into your sample built-in-ds).
                I still observe the incorrect behavior.

                I just sent you an email to support@isomorphic.com with a link to the project, please check again if you observe this behavior.

                Comment


                  #9
                  Also, as you suggested, I checked the RPCs sent and I observe the following when UPDATING the row:

                  DSRequest
                  Code:
                  {
                      dataSource:"table", 
                      operationType:"update", 
                      componentId:"isc_ValuesManager_0", 
                      data:{
                          f_schueler_id:9270, 
                          f_name:"Abraham"
                      }, 
                      textMatchStyle:"exact", 
                      callback:{
                          target:[ValuesManager ID:isc_ValuesManager_0], 
                          methodName:"saveEditorReply"
                      }, 
                      showPrompt:true, 
                      prompt:"Saving form...", 
                      oldValues:{
                          f_schueler_id:9270, 
                          f_name:"Abraham"
                      }, 
                      requestId:"table$6273", 
                      internalClientContext:{
                      }, 
                      fallbackToEval:false, 
                      afterFlowCallback:"isc_ValuesManager_0.$49z(dsRequest, dsResponse, data)", 
                      editor:[ValuesManager ID:isc_ValuesManager_0], 
                      lastClientEventThreadCode:"MUP5", 
                      bypassCache:true
                  }
                  DSResponse:
                  Code:
                  [
                      {
                          affectedRows:1, 
                          data:[
                              {
                                  f_schueler_id:11797, 
                                  f_name:"abc"
                              }
                          ], 
                          invalidateCache:false, 
                          isDSResponse:true, 
                          operationType:"update", 
                          queueStatus:0, 
                          status:0
                      }
                  ]
                  So it seems that there is no server-side persistence, but that the update-request is returning an incorrect value:

                  update:
                  f_schueler_id:9270,
                  f_name:"Abraham"

                  update response:
                  f_schueler_id:11797,
                  f_name:"abc"

                  Both have different IDs, which doesn't make sense, since the update should return the updated record, i.e. the returned record should have the same ID as the updated record.
                  The returned record is "abc" with f_schueler_id=11797, which is exactly the record I previously added, which in turn explains why I am observing "abc" in the form field after executing the update, since this is the record returned by the update request.
                  Last edited by edulid; 4 Sep 2014, 00:39.

                  Comment


                    #10
                    Could you include all RPC Requests/Response and the matching server logs?

                    Is the data sent for an update enough? Is one of the fields PK? Is a PK defined in "table".ds.xml?

                    Comment


                      #11
                      Here are the steps with their respective RPCs:

                      - load the app. Assume you have a few lines of data.

                      DSRequest:
                      Code:
                      {
                          dataSource:"table", 
                          operationType:"fetch", 
                          componentId:"isc_ListGrid_0", 
                          data:{
                          }, 
                          startRow:0, 
                          endRow:75, 
                          sortBy:[
                              "f_name"
                          ], 
                          textMatchStyle:"substring", 
                          resultSet:[ResultSet ID:isc_ResultSet_0 (created by: isc_ListGrid_0)], 
                          callback:{
                              caller:[ResultSet ID:isc_ResultSet_0 (created by: isc_ListGrid_0)], 
                              methodName:"fetchRemoteDataReply"
                          }, 
                          willHandleError:true, 
                          showPrompt:true, 
                          prompt:"Finding Records that match your criteria...", 
                          oldValues:{
                          }, 
                          requestId:"table$6270", 
                          internalClientContext:{
                              requestIndex:1
                          }, 
                          fallbackToEval:false, 
                          bypassCache:true
                      }
                      Response:
                      Code:
                      [
                          {
                              affectedRows:0, 
                              data:[
                                  {
                                      f_schueler_id:10655, 
                                      f_name:" Kwak", 
                                      rowID:1
                                  }, 
                                  {
                                      f_schueler_id:10272, 
                                      f_name:" Jn", 
                                      rowID:2
                                  }, 
                      ...
                      - enter a value (say "abc") and hit "Add" (a new row is successfully added)

                      DSRequest:
                      Code:
                      {
                          dataSource:"table", 
                          operationType:"add", 
                          componentId:"isc_ValuesManager_0", 
                          data:{
                              f_name:"abc"
                          }, 
                          textMatchStyle:"exact", 
                          callback:{
                              target:[ValuesManager ID:isc_ValuesManager_0], 
                              methodName:"saveEditorReply"
                          }, 
                          showPrompt:true, 
                          prompt:"Saving form...", 
                          oldValues:{
                          }, 
                          requestId:"table$6271", 
                          internalClientContext:{
                          }, 
                          fallbackToEval:false, 
                          afterFlowCallback:"isc_ValuesManager_0.$49z(dsRequest, dsResponse, data)", 
                          editor:[ValuesManager ID:isc_ValuesManager_0], 
                          lastClientEventThreadCode:"MUP0", 
                          bypassCache:true
                      }
                      Response:
                      Code:
                      [
                          {
                              affectedRows:1, 
                              data:[
                                  {
                                      f_schueler_id:11798, 
                                      f_name:"abc"
                                  }
                              ], 
                              invalidateCache:false, 
                              isDSResponse:true, 
                              operationType:"add", 
                              queueStatus:0, 
                              status:0
                          }
                      ]
                      - select a row other than the new "abc" row - form item value changes to reflect this.

                      I select "Kwak".

                      DSRequest
                      Code:
                      {
                          dataSource:"table", 
                          operationType:"fetch", 
                          componentId:"isc_ValuesManager_0", 
                          data:{
                              f_schueler_id:10655
                          }, 
                          textMatchStyle:"exact", 
                          callback:{
                              target:[ValuesManager ID:isc_ValuesManager_0], 
                              methodName:"fetchDataReply"
                          }, 
                          showPrompt:true, 
                          oldValues:{
                              f_schueler_id:10655
                          }, 
                          requestId:"table$6272", 
                          fallbackToEval:false, 
                          lastClientEventThreadCode:"MUP7", 
                          bypassCache:true
                      }
                      Request:
                      Code:
                      [
                          {
                              affectedRows:0, 
                              data:[
                                  {
                                      f_schueler_id:10655, 
                                      f_name:" Kwak"
                                  }
                              ], 
                              endRow:1, 
                              invalidateCache:false, 
                              isDSResponse:true, 
                              operationType:"fetch", 
                              queueStatus:0, 
                              startRow:0, 
                              status:0, 
                              totalRows:1
                          }
                      ]

                      - Modify the value (say enter "xxx") and hit update

                      DSRequest:
                      Code:
                      {
                          dataSource:"table", 
                          operationType:"update", 
                          componentId:"isc_ValuesManager_0", 
                          data:{
                              f_schueler_id:10655, 
                              f_name:"xxx"
                          }, 
                          textMatchStyle:"exact", 
                          callback:{
                              target:[ValuesManager ID:isc_ValuesManager_0], 
                              methodName:"saveEditorReply"
                          }, 
                          showPrompt:true, 
                          prompt:"Saving form...", 
                          oldValues:{
                              f_schueler_id:10655, 
                              f_name:" Kwak"
                          }, 
                          requestId:"table$6273", 
                          internalClientContext:{
                          }, 
                          fallbackToEval:false, 
                          afterFlowCallback:"isc_ValuesManager_0.$49z(dsRequest, dsResponse, data)", 
                          editor:[ValuesManager ID:isc_ValuesManager_0], 
                          lastClientEventThreadCode:"MUP8", 
                          bypassCache:true
                      }
                      Response:
                      Code:
                      [
                          {
                              affectedRows:1, 
                              data:[
                                  {
                                      f_schueler_id:11798, 
                                      f_name:"abc"
                                  }
                              ], 
                              invalidateCache:false, 
                              isDSResponse:true, 
                              operationType:"update", 
                              queueStatus:0, 
                              status:0
                          }
                      ]
                      As you see, everything seems correct, only the last response is incorrect.

                      Yes, the data sent is enough for an update, check my table.ds.xml in the first post of this thread. "f_schueler_id" is a PK, as you can also see in table.ds.xml.

                      My complete server log:
                      Code:
                      === 2014-09-04 10:51:24,963 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'ntext'
                      === 2014-09-04 10:51:24,964 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'password'
                      === 2014-09-04 10:51:24,965 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'localeInt'
                      === 2014-09-04 10:51:24,966 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'localeFloat'
                      === 2014-09-04 10:51:24,967 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'localeCurrency'
                      === 2014-09-04 10:51:24,968 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'phoneNumber'
                      === 2014-09-04 10:51:24,969 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'regexp'
                      === 2014-09-04 10:51:24,970 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'identifier'
                      === 2014-09-04 10:51:24,971 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'URL'
                      === 2014-09-04 10:51:24,972 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'url'
                      === 2014-09-04 10:51:24,973 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'XPath'
                      === 2014-09-04 10:51:24,974 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'HTMLString'
                      === 2014-09-04 10:51:24,975 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'HTML'
                      === 2014-09-04 10:51:24,976 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'html'
                      === 2014-09-04 10:51:24,978 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'measure'
                      === 2014-09-04 10:51:24,979 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'integerOrAuto'
                      === 2014-09-04 10:51:24,980 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'integerOrIdentifier'
                      === 2014-09-04 10:51:24,981 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'handler'
                      === 2014-09-04 10:51:24,982 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'callback'
                      === 2014-09-04 10:51:24,983 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'action'
                      === 2014-09-04 10:51:24,985 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'setter'
                      === 2014-09-04 10:51:24,986 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'getter'
                      === 2014-09-04 10:51:24,987 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'tester'
                      === 2014-09-04 10:51:24,988 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'method'
                      === 2014-09-04 10:51:24,989 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'function'
                      === 2014-09-04 10:51:24,990 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'expression'
                      === 2014-09-04 10:51:24,991 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'className'
                      === 2014-09-04 10:51:24,992 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'valueMap'
                      === 2014-09-04 10:51:24,993 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'valignEnum'
                      === 2014-09-04 10:51:24,994 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'alignEnum'
                      === 2014-09-04 10:51:24,996 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'sideEnum'
                      === 2014-09-04 10:51:24,997 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'color'
                      === 2014-09-04 10:51:24,998 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'cssClass'
                      === 2014-09-04 10:51:24,998 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'modifier'
                      === 2014-09-04 10:51:24,999 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'modifierTimestamp'
                      === 2014-09-04 10:51:24,999 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'creator'
                      === 2014-09-04 10:51:25,000 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'creatorTimestamp'
                      === 2014-09-04 10:51:25,001 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'binary'
                      === 2014-09-04 10:51:25,002 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'imageFile'
                      === 2014-09-04 10:51:25,003 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'blob'
                      === 2014-09-04 10:51:25,004 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'clob'
                      === 2014-09-04 10:51:25,004 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'image'
                      === 2014-09-04 10:51:25,036 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'table'
                      === 2014-09-04 10:51:25,040 [3-27] DEBUG XML - Parsed XML from C:\Users\Eduardo\Documents\zedes2\built-in-ds\war\ds\table.ds.xml: 2ms
                      === 2014-09-04 10:51:25,040 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'DataSource'
                      === 2014-09-04 10:51:25,054 [3-27] DEBUG XML - Parsed XML from C:\Users\Eduardo\Documents\zedes2\built-in-ds\war\builtinds\sc\system\schema\DataSource.ds.xml: 13ms
                      === 2014-09-04 10:51:25,054 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object'
                      === 2014-09-04 10:51:25,054 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'fields'
                      === 2014-09-04 10:51:25,055 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'ID'
                      === 2014-09-04 10:51:25,056 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'inheritsFrom'
                      === 2014-09-04 10:51:25,056 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'useParentFieldOrder'
                      === 2014-09-04 10:51:25,057 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'useLocalFieldsOnly'
                      === 2014-09-04 10:51:25,058 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'restrictToParentFields'
                      === 2014-09-04 10:51:25,059 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'valueMap'
                      === 2014-09-04 10:51:25,060 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'dataFormat'
                      === 2014-09-04 10:51:25,062 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'useStrictJSON'
                      === 2014-09-04 10:51:25,062 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'noAutoFetch'
                      === 2014-09-04 10:51:25,063 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'serverType'
                      === 2014-09-04 10:51:25,064 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'callbackParam'
                      === 2014-09-04 10:51:25,065 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'requestProperties'
                      === 2014-09-04 10:51:25,067 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'addGlobalId'
                      === 2014-09-04 10:51:25,068 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'showPrompt'
                      === 2014-09-04 10:51:25,069 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'dataSourceVersion'
                      === 2014-09-04 10:51:25,070 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'dbName'
                      === 2014-09-04 10:51:25,071 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'schema'
                      === 2014-09-04 10:51:25,072 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'tableName'
                      === 2014-09-04 10:51:25,073 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'quoteTableName'
                      === 2014-09-04 10:51:25,074 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'serverObject'
                      === 2014-09-04 10:51:25,075 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'operationBindings'
                      === 2014-09-04 10:51:25,077 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'field'
                      === 2014-09-04 10:51:25,078 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'operationBinding'
                      === 2014-09-04 10:51:25,079 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'serviceNamespace'
                      === 2014-09-04 10:51:25,080 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'dataURL'
                      === 2014-09-04 10:51:25,081 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'dataProtocol'
                      === 2014-09-04 10:51:25,082 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'dataTransport'
                      === 2014-09-04 10:51:25,083 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'defaultParams'
                      === 2014-09-04 10:51:25,084 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'soapAction'
                      === 2014-09-04 10:51:25,085 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'jsonPrefix'
                      === 2014-09-04 10:51:25,085 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'jsonSuffix'
                      === 2014-09-04 10:51:25,086 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'messageTemplate'
                      === 2014-09-04 10:51:25,087 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'defaultCriteria'
                      === 2014-09-04 10:51:25,088 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'tagName'
                      === 2014-09-04 10:51:25,088 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'recordXPath'
                      === 2014-09-04 10:51:25,089 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'recordName'
                      === 2014-09-04 10:51:25,090 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'xmlNamespaces'
                      === 2014-09-04 10:51:25,091 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'dropExtraFields'
                      === 2014-09-04 10:51:25,092 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'schemaNamespace'
                      === 2014-09-04 10:51:25,093 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'mustQualify'
                      === 2014-09-04 10:51:25,094 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'xsdSimpleContent'
                      === 2014-09-04 10:51:25,095 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'xsdAnyElement'
                      === 2014-09-04 10:51:25,096 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'xsdAbstract'
                      === 2014-09-04 10:51:25,097 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'title'
                      === 2014-09-04 10:51:25,098 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'titleField'
                      === 2014-09-04 10:51:25,099 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'pluralTitle'
                      === 2014-09-04 10:51:25,100 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'clientOnly'
                      === 2014-09-04 10:51:25,101 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'testFileName'
                      === 2014-09-04 10:51:25,102 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'testData'
                      === 2014-09-04 10:51:25,103 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'cacheData'
                      === 2014-09-04 10:51:25,104 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'cacheAllData'
                      === 2014-09-04 10:51:25,104 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'cacheAcrossOperationIds'
                      === 2014-09-04 10:51:25,105 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'types'
                      === 2014-09-04 10:51:25,106 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'groups'
                      === 2014-09-04 10:51:25,107 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'methods'
                      === 2014-09-04 10:51:25,107 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'showSuperClassActions'
                      === 2014-09-04 10:51:25,108 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'createStandalone'
                      === 2014-09-04 10:51:25,109 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'useFlatFields'
                      === 2014-09-04 10:51:25,110 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'showLocalFieldsOnly'
                      === 2014-09-04 10:51:25,110 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'globalNamespaces'
                      === 2014-09-04 10:51:25,111 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'autoDeriveSchema'
                      === 2014-09-04 10:51:25,112 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'autoDeriveFKs'
                      === 2014-09-04 10:51:25,113 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'useLocalValidators'
                      === 2014-09-04 10:51:25,113 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'autoDeriveTitles'
                      === 2014-09-04 10:51:25,114 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'qualifyColumnNames'
                      === 2014-09-04 10:51:25,115 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'validateRelatedRecords'
                      === 2014-09-04 10:51:25,115 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'requiresAuthentication'
                      === 2014-09-04 10:51:25,116 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'requiresRoles'
                      === 2014-09-04 10:51:25,117 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'requires'
                      === 2014-09-04 10:51:25,117 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'beanClassName'
                      === 2014-09-04 10:51:25,118 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'autoJoinTransactions'
                      === 2014-09-04 10:51:25,119 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'sparseUpdates'
                      === 2014-09-04 10:51:25,120 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'noNullUpdates'
                      === 2014-09-04 10:51:25,120 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'canExport'
                      === 2014-09-04 10:51:25,121 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'progressiveLoading'
                      === 2014-09-04 10:51:25,122 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'allowAdvancedCriteria'
                      === 2014-09-04 10:51:25,122 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'scriptImport'
                      === 2014-09-04 10:51:25,123 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'script'
                      === 2014-09-04 10:51:25,124 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'allowClientRequestedSummaries'
                      === 2014-09-04 10:51:25,124 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'translatePatternOperators'
                      === 2014-09-04 10:51:25,166 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'DataSourceField'
                      === 2014-09-04 10:51:25,179 [3-27] DEBUG XML - Parsed XML from C:\Users\Eduardo\Documents\zedes2\built-in-ds\war\builtinds\sc\system\schema\DataSourceField.ds.xml: 12ms
                      === 2014-09-04 10:51:25,180 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object'
                      === 2014-09-04 10:51:25,180 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'fields'
                      === 2014-09-04 10:51:25,181 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'name'
                      === 2014-09-04 10:51:25,182 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'type'
                      === 2014-09-04 10:51:25,183 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'disabled'
                      === 2014-09-04 10:51:25,184 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'idAllowed'
                      === 2014-09-04 10:51:25,184 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'required'
                      === 2014-09-04 10:51:25,185 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'valueMap'
                      === 2014-09-04 10:51:25,186 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'validators'
                      === 2014-09-04 10:51:25,186 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'length'
                      === 2014-09-04 10:51:25,187 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'decimalPad'
                      === 2014-09-04 10:51:25,188 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'decimalPrecision'
                      === 2014-09-04 10:51:25,188 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'xmlRequired'
                      === 2014-09-04 10:51:25,189 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'xmlMaxOccurs'
                      === 2014-09-04 10:51:25,189 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'xmlMinOccurs'
                      === 2014-09-04 10:51:25,190 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'xmlNonEmpty'
                      === 2014-09-04 10:51:25,191 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'xsElementRef'
                      === 2014-09-04 10:51:25,191 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'canHide'
                      === 2014-09-04 10:51:25,192 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'xmlAttribute'
                      === 2014-09-04 10:51:25,193 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'mustQualify'
                      === 2014-09-04 10:51:25,193 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'valueXPath'
                      === 2014-09-04 10:51:25,194 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'childrenProperty'
                      === 2014-09-04 10:51:25,195 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'title'
                      === 2014-09-04 10:51:25,196 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'prompt'
                      === 2014-09-04 10:51:25,197 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'detail'
                      === 2014-09-04 10:51:25,198 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'canEdit'
                      === 2014-09-04 10:51:25,199 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'canSave'
                      === 2014-09-04 10:51:25,199 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'canView'
                      === 2014-09-04 10:51:25,200 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'inapplicable'
                      === 2014-09-04 10:51:25,201 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'advanced'
                      === 2014-09-04 10:51:25,202 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'visibility'
                      === 2014-09-04 10:51:25,202 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'hidden'
                      === 2014-09-04 10:51:25,203 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'primaryKey'
                      === 2014-09-04 10:51:25,204 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'foreignKey'
                      === 2014-09-04 10:51:25,205 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'rootValue'
                      === 2014-09-04 10:51:25,206 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'includeFrom'
                      === 2014-09-04 10:51:25,207 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'includeVia'
                      === 2014-09-04 10:51:25,208 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'relatedTableAlias'
                      === 2014-09-04 10:51:25,209 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'showFileInline'
                      === 2014-09-04 10:51:25,209 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'escapeHTML'
                      === 2014-09-04 10:51:25,210 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'imageWidth'
                      === 2014-09-04 10:51:25,211 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'imageHeight'
                      === 2014-09-04 10:51:25,211 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'nativeName'
                      === 2014-09-04 10:51:25,212 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'nativeFK'
                      === 2014-09-04 10:51:25,213 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'autoDeriveFKs'
                      === 2014-09-04 10:51:25,214 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'fieldName'
                      === 2014-09-04 10:51:25,215 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'multiple'
                      === 2014-09-04 10:51:25,216 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'validateEachItem'
                      === 2014-09-04 10:51:25,217 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'pickListFields'
                      === 2014-09-04 10:51:25,218 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'canFilter'
                      === 2014-09-04 10:51:25,218 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'ignore'
                      === 2014-09-04 10:51:25,219 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'unknownType'
                      === 2014-09-04 10:51:25,220 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'canSortClientOnly'
                      === 2014-09-04 10:51:25,221 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'childTagName'
                      === 2014-09-04 10:51:25,221 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'basic'
                      === 2014-09-04 10:51:25,222 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'maxFileSize'
                      === 2014-09-04 10:51:25,223 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'frozen'
                      === 2014-09-04 10:51:25,223 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'canExport'
                      === 2014-09-04 10:51:25,224 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'sqlStorageStrategy'
                      === 2014-09-04 10:51:25,224 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'encodeInResponse'
                      === 2014-09-04 10:51:25,225 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'mimeType'
                      === 2014-09-04 10:51:25,226 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'ignoreTextMatchStyle'
                      === 2014-09-04 10:51:25,226 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'lenientXPath'
                      === 2014-09-04 10:51:25,227 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'summaryFunction'
                      === 2014-09-04 10:51:25,228 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'joinString'
                      === 2014-09-04 10:51:25,228 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'joinPrefix'
                      === 2014-09-04 10:51:25,229 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'joinSuffix'
                      === 2014-09-04 10:51:25,230 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'allowClientRequestedSummaries'
                      === 2014-09-04 10:51:25,235 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'field'
                      === 2014-09-04 10:51:25,302 [3-27] DEBUG DataSourceLoader - For DataSource 'table', got instanceId 6
                      === 2014-09-04 10:51:25,325 [3-27] INFO  Compression - /builtinds/sc/DataSourceLoader: 629 -> 356 bytes
                      === 2014-09-04 10:51:25,475 [3-31] INFO  Compression - /builtinds/hosted.html: 0 -> 20 bytes
                      === 2014-09-04 10:51:25,476 [3-31] ERROR Compression - Caught exception in doFilter() - for URI: /builtinds/hosted.html
                      java.lang.IllegalStateException: NO CONTENT
                      	at org.eclipse.jetty.http.HttpGenerator.addContent(HttpGenerator.java:176)
                      	at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:155)
                      	at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:107)
                      	at java.io.ByteArrayOutputStream.writeTo(ByteArrayOutputStream.java:154)
                      	at com.isomorphic.compression.ServletCompression.compressAndSend(ServletCompression.java:159)
                      	at com.isomorphic.servlet.CompressionFilter.doFilter(CompressionFilter.java:387)
                      	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1474)
                      	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:499)
                      	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
                      	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:557)
                      	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231)
                      	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1086)
                      	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:428)
                      	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
                      	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1020)
                      	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
                      	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
                      	at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:68)
                      	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
                      	at org.eclipse.jetty.server.Server.handle(Server.java:370)
                      	at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:489)
                      	at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:949)
                      	at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:1011)
                      	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:644)
                      	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
                      	at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
                      	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:668)
                      	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
                      	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
                      	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
                      	at java.lang.Thread.run(Thread.java:745)
                      
                      === 2014-09-04 10:51:38,187 [3-29] INFO  RequestContext - URL: '/favicon.ico', User-Agent: 'Mozilla/5.0 (Windows NT 6.3; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0': Moz (Gecko) with Accept-Encoding header
                      === 2014-09-04 10:51:38,188 [3-31] 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
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: Cookie:isc_cState=ready; JSESSIONID=c7snbany7hysalqx61pc1lw9; GLog=%7B%0D%20%20%20%20left%3A321%2C%20%0D%20%20%20%20top%3A175%2C%20%0D%20%20%20%20width%3A1366%2C%20%0D%20%20%20%20height%3A714%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A4%0D%20%20%20%20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%2C%20%0D%20%20%20%20trackRPC%3Atrue%0D%7D
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: Host:127.0.0.1:8888
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: Accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: Content-Length:1094
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: Accept-Language:de-de,de;q=0.8,en-us;q=0.5,en;q=0.3
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: Pragma:no-cache
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: Connection:keep-alive
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: Referer:http://127.0.0.1:8888/BuiltInDS.html?gwt.codesvr=127.0.0.1:9997
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: User-Agent:Mozilla/5.0 (Windows NT 6.3; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0
                      === 2014-09-04 10:51:38,195 [3-31] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
                      === 2014-09-04 10:51:38,196 [3-31] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
                      === 2014-09-04 10:51:38,196 [3-31] DEBUG IDACall - session exists: c7snbany7hysalqx61pc1lw9
                      === 2014-09-04 10:51:38,196 [3-31] DEBUG IDACall - remote user: null
                      === 2014-09-04 10:51:38,219 [3-31] DEBUG XML - Parsed XML from (in memory stream): 3ms
                      === 2014-09-04 10:51:38,219 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'transaction'
                      === 2014-09-04 10:51:38,220 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object'
                      === 2014-09-04 10:51:38,221 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'List'
                      === 2014-09-04 10:51:38,223 [3-31] DEBUG XML - Parsed XML from C:\Users\Eduardo\Documents\zedes2\built-in-ds\war\builtinds\sc\system\schema\List.ds.xml: 1ms
                      === 2014-09-04 10:51:38,224 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'DataSource'
                      === 2014-09-04 10:51:38,227 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'elem'
                      === 2014-09-04 10:51:38,230 [3-31] DEBUG RPCManager - Processing 1 requests.
                      === 2014-09-04 10:51:38,248 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'table'
                      === 2014-09-04 10:51:38,248 [3-31] DEBUG DSRequest - Caching instance 6 of DS table from DSRequest.getDataSource()
                      === 2014-09-04 10:51:38,249 [3-31] DEBUG RPCManager - Request #1 (DSRequest) payload: {
                          criteria:{
                          },
                          operationConfig:{
                              dataSource:"table",
                              operationType:"fetch",
                              textMatchStyle:"substring"
                          },
                          startRow:0,
                          endRow:75,
                          sortBy:[
                              "f_name"
                          ],
                          componentId:"isc_ListGrid_0",
                          appID:"builtinApplication",
                          operation:"table_fetch",
                          oldValues:{
                          }
                      }
                      === 2014-09-04 10:51:38,250 [3-31] INFO  IDACall - Performing 1 operation(s)
                      === 2014-09-04 10:51:38,253 [3-31] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
                      === 2014-09-04 10:51:38,253 [3-31] DEBUG DeclarativeSecurity - DataSource table is not in the pre-checked list, processing...
                      === 2014-09-04 10:51:38,262 [3-31] DEBUG AppBase - [builtinApplication.table_fetch] No userTypes defined, allowing anyone access to all operations for this application
                      === 2014-09-04 10:51:38,262 [3-31] DEBUG AppBase - [builtinApplication.table_fetch] No public zero-argument method named '_table_fetch' found, performing generic datasource operation
                      === 2014-09-04 10:51:38,263 [3-31] INFO  SQLDataSource - [builtinApplication.table_fetch] Performing fetch operation with
                      	criteria: {}	values: {}
                      === 2014-09-04 10:51:38,276 [3-31] INFO  SQLWhereClause - [builtinApplication.table_fetch] empty condition
                      === 2014-09-04 10:51:38,277 [3-31] INFO  SQLDataSource - [builtinApplication.table_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause ORDER BY $defaultOrderClause
                      === 2014-09-04 10:51:38,383 [3-31] DEBUG SQLDataSource - [builtinApplication.table_fetch] Executing row count query: SELECT COUNT(*) FROM $defaultTableClause WHERE $defaultWhereClause
                      === 2014-09-04 10:51:38,383 [3-31] DEBUG SQLDataSource - [builtinApplication.table_fetch] Eval'd row count query: SELECT COUNT(*) FROM t_schueler WHERE ('1'='1')
                      === 2014-09-04 10:51:38,447 [3-31] INFO  PoolManager - [builtinApplication.table_fetch] SmartClient pooling started for 'SQLSERVER' objects
                      === 2014-09-04 10:51:38,448 [3-31] DEBUG PoolableSQLConnectionFactory - [builtinApplication.table_fetch] Initializing SQL config for 'SQLSERVER' from system config - using DriverManager:  com.microsoft.sqlserver.jdbc.SQLServerDriver
                      === 2014-09-04 10:51:38,448 [3-31] DEBUG PoolableSQLConnectionFactory - [builtinApplication.table_fetch] com.microsoft.sqlserver.jdbc.SQLServerDriver lookup successful
                      === 2014-09-04 10:51:38,448 [3-31] DEBUG PoolableSQLConnectionFactory - [builtinApplication.table_fetch] DriverManager fetching connection for SQLSERVER via jdbc url jdbc:sqlserver://localhost;UserName=test;password=test;databaseName=zedes2
                      === 2014-09-04 10:51:38,448 [3-31] DEBUG PoolableSQLConnectionFactory - [builtinApplication.table_fetch] Passing JDBC URL only to getConnection
                      === 2014-09-04 10:51:38,691 [3-31] DEBUG PoolableSQLConnectionFactory - [builtinApplication.table_fetch] makeObject() created a pooled Connection '1542626358'
                      === 2014-09-04 10:51:38,697 [3-31] DEBUG SQLConnectionManager - [builtinApplication.table_fetch] Borrowed connection '1542626358'
                      === 2014-09-04 10:51:38,697 [3-31] DEBUG SQLDriver - [builtinApplication.table_fetch] About to execute SQL query in 'SQLSERVER' using connection '1542626358'
                      === 2014-09-04 10:51:38,697 [3-31] INFO  SQLDriver - [builtinApplication.table_fetch] Executing SQL query on 'SQLSERVER': SELECT COUNT(*) FROM t_schueler WHERE ('1'='1')
                      === 2014-09-04 10:51:38,759 [3-31] DEBUG PoolableSQLConnectionFactory - [builtinApplication.table_fetch] DriverManager fetching connection for SQLSERVER via jdbc url jdbc:sqlserver://localhost;UserName=test;password=test;databaseName=zedes2
                      === 2014-09-04 10:51:38,759 [3-31] DEBUG PoolableSQLConnectionFactory - [builtinApplication.table_fetch] Passing JDBC URL only to getConnection
                      === 2014-09-04 10:51:38,774 [3-31] DEBUG SQLConnectionManager - [builtinApplication.table_fetch] Borrowed UNPOOLED connection '1219948854'
                      === 2014-09-04 10:51:38,781 [3-31] DEBUG SQLServerDriver - [builtinApplication.table_fetch] SQL Server version is '12.00.2000'
                      === 2014-09-04 10:51:38,781 [3-31] DEBUG SQLDataSource - [builtinApplication.table_fetch] Using SQL Limit query
                      === 2014-09-04 10:51:38,782 [3-31] DEBUG SQLDataSource - [builtinApplication.table_fetch] SQL windowed select rows 0->75, result size 75. Query: SELECT * FROM (SELECT *, ROW_NUMBER() OVER (ORDER BY f_name) AS rowID FROM (SELECT TOP 100 PERCENT  t_schueler.f_schueler_id, t_schueler.f_name FROM t_schueler WHERE ('1'='1') ORDER BY t_schueler.f_name) x) y WHERE y.rowID BETWEEN 1 AND 75
                      === 2014-09-04 10:51:38,782 [3-31] DEBUG SQLDataSource - [builtinApplication.table_fetch] SQL windowed select rows 0->75, result size 75. Query: SELECT * FROM (SELECT *, ROW_NUMBER() OVER (ORDER BY f_name) AS rowID FROM (SELECT TOP 100 PERCENT  t_schueler.f_schueler_id, t_schueler.f_name FROM t_schueler WHERE ('1'='1') ORDER BY t_schueler.f_name) x) y WHERE y.rowID BETWEEN 1 AND 75
                      === 2014-09-04 10:51:38,809 [3-31] INFO  DSResponse - [builtinApplication.table_fetch] DSResponse: List with 75 items
                      === 2014-09-04 10:51:38,810 [3-31] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
                      === 2014-09-04 10:51:38,811 [3-31] DEBUG RPCManager - non-DMI response, dropExtraFields: false
                      === 2014-09-04 10:51:38,820 [3-31] DEBUG SQLDriver - Freeing SQLDriver dbConnection 1542626358
                      === 2014-09-04 10:51:38,820 [3-31] DEBUG SQLConnectionManager - About to close ISCPoolableConnection with hashcode "1542626358"
                      === 2014-09-04 10:51:38,821 [3-31] INFO  Compression - /builtinds/sc/IDACall: 3692 -> 955 bytes
                      === 2014-09-04 10:51:47,480 [3-27] 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
                      === 2014-09-04 10:51:47,480 [3-27] DEBUG IDACall - Header Name:Value pair: Cookie:isc_cState=ready; JSESSIONID=c7snbany7hysalqx61pc1lw9; GLog=%7B%0D%20%20%20%20left%3A321%2C%20%0D%20%20%20%20top%3A175%2C%20%0D%20%20%20%20width%3A1366%2C%20%0D%20%20%20%20height%3A714%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A4%0D%20%20%20%20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%2C%20%0D%20%20%20%20trackRPC%3Atrue%0D%7D
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: Host:127.0.0.1:8888
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: Accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: Content-Length:677
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: Accept-Language:de-de,de;q=0.8,en-us;q=0.5,en;q=0.3
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: Pragma:no-cache
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: Connection:keep-alive
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: Referer:http://127.0.0.1:8888/builtinds/sc/system/helpers/Log.html
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: User-Agent:Mozilla/5.0 (Windows NT 6.3; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - session exists: c7snbany7hysalqx61pc1lw9
                      === 2014-09-04 10:51:47,481 [3-27] DEBUG IDACall - remote user: null
                      === 2014-09-04 10:51:47,486 [3-27] DEBUG XML - Parsed XML from (in memory stream): 2ms
                      === 2014-09-04 10:51:47,486 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'transaction'
                      === 2014-09-04 10:51:47,487 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object'
                      === 2014-09-04 10:51:47,487 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'List'
                      === 2014-09-04 10:51:47,488 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'elem'
                      === 2014-09-04 10:51:47,489 [3-30] INFO  RequestContext - URL: '/favicon.ico', User-Agent: 'Mozilla/5.0 (Windows NT 6.3; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0': Moz (Gecko) with Accept-Encoding header
                      === 2014-09-04 10:51:47,489 [3-27] DEBUG RPCManager - Processing 1 requests.
                      === 2014-09-04 10:51:47,490 [3-27] DEBUG RPCManager - Request #1 (RPCRequest) data: {
                          appID:"isc_builtin",
                          className:"builtin",
                          methodName:"getAvailableScriptEngines",
                          arguments:[
                          ],
                          is_ISC_RPC_DMI:true
                      }
                      === 2014-09-04 10:51:47,490 [3-27] INFO  IDACall - Performing 1 operation(s)
                      === 2014-09-04 10:51:47,501 [3-27] DEBUG XML - Parsed XML from jar:file:/C:/Users/Eduardo/Documents/zedes2/libs/smartgwt-4.1p/smartgwtpower-4.1p/lib/isomorphic_core_rpc.jar!/isc_builtin.app.xml: 4ms
                      === 2014-09-04 10:51:47,501 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'Application'
                      === 2014-09-04 10:51:47,503 [3-27] DEBUG XML - Parsed XML from C:\Users\Eduardo\Documents\zedes2\built-in-ds\war\builtinds\sc\system\schema\Application.ds.xml: 1ms
                      === 2014-09-04 10:51:47,504 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'DataSource'
                      === 2014-09-04 10:51:47,507 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'field'
                      === 2014-09-04 10:51:47,508 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'DataSourceField'
                      === 2014-09-04 10:51:47,509 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'ServerObject'
                      === 2014-09-04 10:51:47,512 [3-27] DEBUG XML - Parsed XML from C:\Users\Eduardo\Documents\zedes2\built-in-ds\war\builtinds\sc\system\schema\ServerObject.ds.xml: 2ms
                      === 2014-09-04 10:51:47,512 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object'
                      === 2014-09-04 10:51:47,512 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'fields'
                      === 2014-09-04 10:51:47,513 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'ID'
                      === 2014-09-04 10:51:47,513 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'valueMap'
                      === 2014-09-04 10:51:47,514 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'lookupStyle'
                      === 2014-09-04 10:51:47,515 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'attributeName'
                      === 2014-09-04 10:51:47,515 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'attributeScope'
                      === 2014-09-04 10:51:47,516 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'bean'
                      === 2014-09-04 10:51:47,517 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'visibleMethods'
                      === 2014-09-04 10:51:47,518 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'dropExtraFields'
                      === 2014-09-04 10:51:47,519 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'Method'
                      === 2014-09-04 10:51:47,522 [3-27] DEBUG XML - Parsed XML from C:\Users\Eduardo\Documents\zedes2\built-in-ds\war\builtinds\sc\system\schema\Method.ds.xml: 2ms
                      === 2014-09-04 10:51:47,522 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object'
                      === 2014-09-04 10:51:47,522 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'name'
                      === 2014-09-04 10:51:47,523 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'fields'
                      === 2014-09-04 10:51:47,531 [3-27] DEBUG RPCDMI - appConfig: isc.Application.create({
                          rpcBindings:[
                              {
                                  ID:"builtin",
                                  className:"com.isomorphic.rpc.BuiltinRPC",
                                  visibleMethods:[
                                      {
                                          name:"downloadWSDL"
                                      },
                                      {
                                          name:"downloadClientContent"
                                      },
                                      {
                                          name:"downloadClientExport"
                                      },
                                      {
                                          name:"xmlToJS"
                                      },
                                      {
                                          name:"uploadProgressCheck"
                                      },
                                      {
                                          name:"saveFile"
                                      },
                                      {
                                          name:"appendToFile"
                                      },
                                      {
                                          name:"loadFile"
                                      },
                                      {
                                          name:"deleteFile"
                                      },
                                      {
                                          name:"loadSharedXML"
                                      },
                                      {
                                          name:"saveSharedXML"
                                      },
                                      {
                                          name:"getAvailableScriptEngines"
                                      },
                                      {
                                          name:"devConsoleEvalServerScript"
                                      },
                                      {
                                          name:"evalJava"
                                      },
                                      {
                                          name:"getLogNames"
                                      },
                                      {
                                          name:"getLogEntries"
                                      },
                                      {
                                          name:"clearLogEntries"
                                      },
                                      {
                                          name:"getLogThresholds"
                                      },
                                      {
                                          name:"setLogThreshold"
                                      },
                                      {
                                          name:"setTemporaryLogThreshold"
                                      },
                                      {
                                          name:"revertTemporaryLogThresholds"
                                      },
                                      {
                                          name:"getPdfObject"
                                      },
                                      {
                                          name:"exportImage"
                                      },
                                      {
                                          name:"areServerTimingsTracked"
                                      },
                                      {
                                          name:"trackServerTimings"
                                      }
                                  ]
                              },
                              {
                                  ID:"builtin_tools",
                                  className:"com.isomorphic.tools.BuiltinRPC",
                                  visibleMethods:[
                                      {
                                          name:"getDataSourceFromTable"
                                      },
                                      {
                                          name:"getDataSourceJSONFromTable"
                                      },
                                      {
                                          name:"getDataSourceFromHibernateMapping"
                                      },
                                      {
                                          name:"getDataSourceJSONFromHibernateMapping"
                                      },
                                      {
                                          name:"getTables"
                                      },
                                      {
                                          name:"getFieldsFromTable"
                                      },
                                      {
                                          name:"getBeanFields"
                                      },
                                      {
                                          name:"getHibernateBeans"
                                      },
                                      {
                                          name:"getDatabaseProductNameAndVersion"
                                      },
                                      {
                                          name:"getDatabaseTableTypes"
                                      },
                                      {
                                          name:"setAttributes"
                                      },
                                      {
                                          name:"clearAttributes"
                                      },
                                      {
                                          name:"getAttributes"
                                      },
                                      {
                                          name:"getAttribute"
                                      },
                                      {
                                          name:"getDataSourceConfigFromJavaClass"
                                      },
                                      {
                                          args:"cName",
                                          language:"groovy",
                                          name:"getJavaSource",
                                          script:"\n                    if (!com.isomorphic.auth.DevModeAuthFilter.devModeAuthorized(request)) throw new Exception(\"Not Authorized\");                    \n                    //import org.apache.bcel.Repository;\n\n                    try {\n                        return org.apache.bcel.Repository.lookupClass(cName).toString();\n                    } catch (Throwable e) {\n                        return \"Unable to reverse engineer class \"+cName+\": \"+e.getMessage();\n                    }\n                "
                                      },
                                      {
                                          name:"loadDataSource"
                                      },
                                      {
                                          name:"dsFromXML"
                                      },
                                      {
                                          name:"dsConfigFromXML"
                                      },
                                      {
                                          name:"getDefinedDataSources"
                                      }
                                  ]
                              },
                              {
                                  ID:"builtin_adminconsole",
                                  className:"com.isomorphic.tools.AdminConsole",
                                  visibleMethods:[
                                      {
                                          name:"getDefinedDatabases"
                                      },
                                      {
                                          name:"testDB"
                                      },
                                      {
                                          name:"saveDBConfig"
                                      },
                                      {
                                          name:"setDefaultDB"
                                      },
                                      {
                                          name:"importDataSources"
                                      },
                                      {
                                          name:"discoverJNDIDatabases"
                                      }
                                  ]
                              }
                          ]
                      })
                      
                      === 2014-09-04 10:51:47,540 [3-27] DEBUG RPCDMI - rpc returned data
                      === 2014-09-04 10:51:47,540 [3-27] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
                      === 2014-09-04 10:51:47,541 [3-27] INFO  Compression - /builtinds/sc/IDACall: 92 -> 97 bytes
                      === 2014-09-04 10:51:48,890 [3-31] 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
                      === 2014-09-04 10:51:48,890 [3-31] DEBUG IDACall - Header Name:Value pair: Cookie:isc_cState=ready; JSESSIONID=c7snbany7hysalqx61pc1lw9; GLog=%7B%0D%20%20%20%20left%3A321%2C%20%0D%20%20%20%20top%3A175%2C%20%0D%20%20%20%20width%3A1364%2C%20%0D%20%20%20%20height%3A705%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A4%0D%20%20%20%20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%2C%20%0D%20%20%20%20trackRPC%3Atrue%0D%7D
                      === 2014-09-04 10:51:48,890 [3-31] DEBUG IDACall - Header Name:Value pair: Host:127.0.0.1:8888
                      === 2014-09-04 10:51:48,890 [3-31] DEBUG IDACall - Header Name:Value pair: Accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
                      === 2014-09-04 10:51:48,890 [3-31] DEBUG IDACall - Header Name:Value pair: Content-Length:675
                      === 2014-09-04 10:51:48,890 [3-31] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
                      === 2014-09-04 10:51:48,891 [3-31] DEBUG IDACall - Header Name:Value pair: Accept-Language:de-de,de;q=0.8,en-us;q=0.5,en;q=0.3
                      === 2014-09-04 10:51:48,891 [3-31] DEBUG IDACall - Header Name:Value pair: Pragma:no-cache
                      === 2014-09-04 10:51:48,891 [3-31] DEBUG IDACall - Header Name:Value pair: Connection:keep-alive
                      === 2014-09-04 10:51:48,891 [3-31] DEBUG IDACall - Header Name:Value pair: Referer:http://127.0.0.1:8888/builtinds/sc/system/helpers/Log.html
                      === 2014-09-04 10:51:48,891 [3-31] DEBUG IDACall - Header Name:Value pair: User-Agent:Mozilla/5.0 (Windows NT 6.3; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0
                      === 2014-09-04 10:51:48,891 [3-31] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
                      === 2014-09-04 10:51:48,891 [3-31] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
                      === 2014-09-04 10:51:48,891 [3-31] DEBUG IDACall - session exists: c7snbany7hysalqx61pc1lw9
                      === 2014-09-04 10:51:48,891 [3-31] DEBUG IDACall - remote user: null
                      === 2014-09-04 10:51:48,897 [3-31] DEBUG XML - Parsed XML from (in memory stream): 3ms
                      === 2014-09-04 10:51:48,898 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'transaction'
                      === 2014-09-04 10:51:48,898 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object'
                      === 2014-09-04 10:51:48,899 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'List'
                      === 2014-09-04 10:51:48,900 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'elem'
                      === 2014-09-04 10:51:48,901 [3-31] DEBUG RPCManager - Processing 1 requests.
                      === 2014-09-04 10:51:48,902 [3-31] DEBUG RPCManager - Request #1 (RPCRequest) data: {
                          appID:"isc_builtin",
                          className:"builtin",
                          methodName:"areServerTimingsTracked",
                          arguments:[
                          ],
                          is_ISC_RPC_DMI:true
                      }
                      === 2014-09-04 10:51:48,902 [3-31] INFO  IDACall - Performing 1 operation(s)
                      === 2014-09-04 10:51:48,904 [3-31] DEBUG RPCDMI - appConfig: isc.Application.create({
                          rpcBindings:[
                              {
                                  ID:"builtin",
                                  className:"com.isomorphic.rpc.BuiltinRPC",
                                  visibleMethods:[
                                      {
                                          name:"downloadWSDL"
                                      },
                                      {
                                          name:"downloadClientContent"
                                      },
                                      {
                                          name:"downloadClientExport"
                                      },
                                      {
                                          name:"xmlToJS"
                                      },
                                      {
                                          name:"uploadProgressCheck"
                                      },
                                      {
                                          name:"saveFile"
                                      },
                                      {
                                          name:"appendToFile"
                                      },
                                      {
                                          name:"loadFile"
                                      },
                                      {
                                          name:"deleteFile"
                                      },
                                      {
                                          name:"loadSharedXML"
                                      },
                                      {
                                          name:"saveSharedXML"
                                      },
                                      {
                                          name:"getAvailableScriptEngines"
                                      },
                                      {
                                          name:"devConsoleEvalServerScript"
                                      },
                                      {
                                          name:"evalJava"
                                      },
                                      {
                                          name:"getLogNames"
                                      },
                                      {
                                          name:"getLogEntries"
                                      },
                                      {
                                          name:"clearLogEntries"
                                      },
                                      {
                                          name:"getLogThresholds"
                                      },
                                      {
                                          name:"setLogThreshold"
                                      },
                                      {
                                          name:"setTemporaryLogThreshold"
                                      },
                                      {
                                          name:"revertTemporaryLogThresholds"
                                      },
                                      {
                                          name:"getPdfObject"
                                      },
                                      {
                                          name:"exportImage"
                                      },
                                      {
                                          name:"areServerTimingsTracked"
                                      },
                                      {
                                          name:"trackServerTimings"
                                      }
                                  ]
                              },
                              {
                                  ID:"builtin_tools",
                                  className:"com.isomorphic.tools.BuiltinRPC",
                                  visibleMethods:[
                                      {
                                          name:"getDataSourceFromTable"
                                      },
                                      {
                                          name:"getDataSourceJSONFromTable"
                                      },
                                      {
                                          name:"getDataSourceFromHibernateMapping"
                                      },
                                      {
                                          name:"getDataSourceJSONFromHibernateMapping"
                                      },
                                      {
                                          name:"getTables"
                                      },
                                      {
                                          name:"getFieldsFromTable"
                                      },
                                      {
                                          name:"getBeanFields"
                                      },
                                      {
                                          name:"getHibernateBeans"
                                      },
                                      {
                                          name:"getDatabaseProductNameAndVersion"
                                      },
                                      {
                                          name:"getDatabaseTableTypes"
                                      },
                                      {
                                          name:"setAttributes"
                                      },
                                      {
                                          name:"clearAttributes"
                                      },
                                      {
                                          name:"getAttributes"
                                      },
                                      {
                                          name:"getAttribute"
                                      },
                                      {
                                          name:"getDataSourceConfigFromJavaClass"
                                      },
                                      {
                                          args:"cName",
                                          language:"groovy",
                                          name:"getJavaSource",
                                          script:"\n                    if (!com.isomorphic.auth.DevModeAuthFilter.devModeAuthorized(request)) throw new Exception(\"Not Authorized\");                    \n                    //import org.apache.bcel.Repository;\n\n                    try {\n                        return org.apache.bcel.Repository.lookupClass(cName).toString();\n                    } catch (Throwable e) {\n                        return \"Unable to reverse engineer class \"+cName+\": \"+e.getMessage();\n                    }\n                "
                                      },
                                      {
                                          name:"loadDataSource"
                                      },
                                      {
                                          name:"dsFromXML"
                                      },
                                      {
                                          name:"dsConfigFromXML"
                                      },
                                      {
                                          name:"getDefinedDataSources"
                                      }
                                  ]
                              },
                              {
                                  ID:"builtin_adminconsole",
                                  className:"com.isomorphic.tools.AdminConsole",
                                  visibleMethods:[
                                      {
                                          name:"getDefinedDatabases"
                                      },
                                      {
                                          name:"testDB"
                                      },
                                      {
                                          name:"saveDBConfig"
                                      },
                                      {
                                          name:"setDefaultDB"
                                      },
                                      {
                                          name:"importDataSources"
                                      },
                                      {
                                          name:"discoverJNDIDatabases"
                                      }
                                  ]
                              }
                          ]
                      })
                      
                      === 2014-09-04 10:51:48,906 [3-31] DEBUG RPCDMI - rpc returned RPCResponse
                      === 2014-09-04 10:51:48,906 [3-31] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
                      === 2014-09-04 10:51:48,907 [3-31] INFO  Compression - /builtinds/sc/IDACall: 68 -> 74 bytes
                      === 2014-09-04 10:54:24,100 [3-29] 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
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Cookie:isc_cState=ready; JSESSIONID=c7snbany7hysalqx61pc1lw9; GLog=%7B%0D%20%20%20%20left%3A321%2C%20%0D%20%20%20%20top%3A175%2C%20%0D%20%20%20%20width%3A1364%2C%20%0D%20%20%20%20height%3A705%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A4%0D%20%20%20%20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%2C%20%0D%20%20%20%20trackRPC%3Atrue%0D%7D
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Host:127.0.0.1:8888
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Content-Length:904
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Accept-Language:de-de,de;q=0.8,en-us;q=0.5,en;q=0.3
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Pragma:no-cache
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Connection:keep-alive
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Referer:http://127.0.0.1:8888/BuiltInDS.html?gwt.codesvr=127.0.0.1:9997
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: User-Agent:Mozilla/5.0 (Windows NT 6.3; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - session exists: c7snbany7hysalqx61pc1lw9
                      === 2014-09-04 10:54:24,105 [3-29] DEBUG IDACall - remote user: null
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG XML - Parsed XML from (in memory stream): 0ms
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG ISCKeyedObjectPool - Borrowing object for 'transaction'
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object'
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG ISCKeyedObjectPool - Borrowing object for 'List'
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG ISCKeyedObjectPool - Borrowing object for 'elem'
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG RPCManager - Processing 1 requests.
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG ISCKeyedObjectPool - Borrowing object for 'table'
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG DSRequest - Caching instance 6 of DS table from DSRequest.getDataSource()
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG RPCManager - Request #1 (DSRequest) payload: {
                          values:{
                              f_name:"abc"
                          },
                          operationConfig:{
                              dataSource:"table",
                              operationType:"add",
                              textMatchStyle:"exact"
                          },
                          componentId:"isc_ValuesManager_0",
                          appID:"builtinApplication",
                          operation:"table_add",
                          oldValues:{
                          },
                          criteria:{
                          }
                      }
                      === 2014-09-04 10:54:24,106 [3-29] INFO  IDACall - Performing 1 operation(s)
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG DeclarativeSecurity - DataSource table is not in the pre-checked list, processing...
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG AppBase - [builtinApplication.table_add] No userTypes defined, allowing anyone access to all operations for this application
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG AppBase - [builtinApplication.table_add] No public zero-argument method named '_table_add' found, performing generic datasource operation
                      === 2014-09-04 10:54:24,106 [3-29] INFO  SQLDataSource - [builtinApplication.table_add] Performing add operation with
                      	criteria: {f_name:"abc"}	values: {f_name:"abc"}
                      === 2014-09-04 10:54:24,106 [3-29] DEBUG SQLValuesClause - [builtinApplication.table_add] Sequences: {f_schueler_id=__default}
                      === 2014-09-04 10:54:24,122 [3-29] DEBUG SQLConnectionManager - [builtinApplication.table_add] Borrowed connection '1542626358'
                      === 2014-09-04 10:54:24,122 [3-29] DEBUG SQLTransaction - [builtinApplication.table_add] Started new SQLSERVER transaction "1542626358"
                      === 2014-09-04 10:54:24,122 [3-29] DEBUG SQLDriver - [builtinApplication.table_add] About to execute SQL update in 'SQLSERVER' using connection'1542626358'
                      === 2014-09-04 10:54:24,122 [3-29] INFO  SQLDriver - [builtinApplication.table_add] Executing SQL update on 'SQLSERVER': INSERT INTO t_schueler (f_name) VALUES ('abc')
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG SQLDriver - [builtinApplication.table_add] Found 1 sequence(s)/autoGenerated PK field(s): [f_schueler_id]
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG SQLDriver - [builtinApplication.table_add] Discovered zero or one generated key via JDBC: {f_schueler_id=11798}
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG SQLDataSource - [builtinApplication.table_add] add operation affected 1 rows
                      === 2014-09-04 10:54:24,137 [3-29] INFO  SQLDataSource - [builtinApplication.table_add] primaryKeys: {}
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG SQLDataSource - [builtinApplication.table_add] Added JDBC-generated values to the list of primaryKeys.  Key values are now: {f_schueler_id=11798}
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG DeclarativeSecurity - [builtinApplication.table_add] Processing security checks for DataSource null, field null
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG DeclarativeSecurity - [builtinApplication.table_add] DataSource table is not in the pre-checked list, processing...
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG AppBase - [builtinApplication.table_add, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG AppBase - [builtinApplication.table_add, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
                      === 2014-09-04 10:54:24,137 [3-29] INFO  SQLDataSource - [builtinApplication.table_add, builtinApplication.null] Performing fetch operation with
                      	criteria: {f_schueler_id:11798}	values: {f_schueler_id:11798}
                      === 2014-09-04 10:54:24,137 [3-29] INFO  SQLDataSource - [builtinApplication.table_add, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
                      === 2014-09-04 10:54:24,137 [3-29] INFO  SQLDataSource - [builtinApplication.table_add, builtinApplication.null] 6: Executing SQL query on 'SQLSERVER': SELECT t_schueler.f_schueler_id, t_schueler.f_name FROM t_schueler WHERE (t_schueler.f_schueler_id=11798)
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG SQLDriver - [builtinApplication.table_add, builtinApplication.null] About to execute SQL query in 'SQLSERVER' using connection '1542626358'
                      === 2014-09-04 10:54:24,137 [3-29] INFO  SQLDriver - [builtinApplication.table_add, builtinApplication.null] Executing SQL query on 'SQLSERVER': SELECT t_schueler.f_schueler_id, t_schueler.f_name FROM t_schueler WHERE (t_schueler.f_schueler_id=11798)
                      === 2014-09-04 10:54:24,137 [3-29] INFO  DSResponse - [builtinApplication.table_add, builtinApplication.null] DSResponse: List with 1 items
                      === 2014-09-04 10:54:24,137 [3-29] INFO  DSResponse - [builtinApplication.table_add] DSResponse: List with 1 items
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG SQLTransaction - Committing SQLSERVER transaction "1542626358"
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG RPCManager - non-DMI response, dropExtraFields: false
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG SQLTransaction - getConnection() found transactional connection for SQLSERVER with hashcode "1542626358"
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG SQLTransaction - Ending SQLSERVER transaction "1542626358"
                      === 2014-09-04 10:54:24,137 [3-29] DEBUG SQLConnectionManager - About to close ISCPoolableConnection with hashcode "1542626358"
                      === 2014-09-04 10:54:24,137 [3-29] INFO  Compression - /builtinds/sc/IDACall: 188 -> 165 bytes
                      === 2014-09-04 10:55:19,026 [3-31] 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
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: Cookie:isc_cState=ready; JSESSIONID=c7snbany7hysalqx61pc1lw9; GLog=%7B%0D%20%20%20%20left%3A321%2C%20%0D%20%20%20%20top%3A175%2C%20%0D%20%20%20%20width%3A1364%2C%20%0D%20%20%20%20height%3A705%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A4%0D%20%20%20%20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%2C%20%0D%20%20%20%20trackRPC%3Atrue%0D%7D
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: Host:127.0.0.1:8888
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: Accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: Content-Length:1038
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: Accept-Language:de-de,de;q=0.8,en-us;q=0.5,en;q=0.3
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: Pragma:no-cache
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: Connection:keep-alive
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: Referer:http://127.0.0.1:8888/BuiltInDS.html?gwt.codesvr=127.0.0.1:9997
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: User-Agent:Mozilla/5.0 (Windows NT 6.3; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0
                      === 2014-09-04 10:55:19,041 [3-31] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG IDACall - session exists: c7snbany7hysalqx61pc1lw9
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG IDACall - remote user: null
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG XML - Parsed XML from (in memory stream): 0ms
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'transaction'
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object'
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'List'
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'elem'
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG RPCManager - Processing 1 requests.
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG ISCKeyedObjectPool - Borrowing object for 'table'
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG DSRequest - Caching instance 6 of DS table from DSRequest.getDataSource()
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG RPCManager - Request #1 (DSRequest) payload: {
                          criteria:{
                              f_schueler_id:10655
                          },
                          operationConfig:{
                              dataSource:"table",
                              operationType:"fetch",
                              textMatchStyle:"exact"
                          },
                          componentId:"isc_ValuesManager_0",
                          appID:"builtinApplication",
                          operation:"table_fetch",
                          oldValues:{
                              f_schueler_id:10655
                          }
                      }
                      === 2014-09-04 10:55:19,042 [3-31] INFO  IDACall - Performing 1 operation(s)
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG DeclarativeSecurity - DataSource table is not in the pre-checked list, processing...
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG AppBase - [builtinApplication.table_fetch] No userTypes defined, allowing anyone access to all operations for this application
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG AppBase - [builtinApplication.table_fetch] No public zero-argument method named '_table_fetch' found, performing generic datasource operation
                      === 2014-09-04 10:55:19,042 [3-31] INFO  SQLDataSource - [builtinApplication.table_fetch] Performing fetch operation with
                      	criteria: {f_schueler_id:10655}	values: {f_schueler_id:10655}
                      === 2014-09-04 10:55:19,042 [3-31] INFO  SQLDataSource - [builtinApplication.table_fetch] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
                      === 2014-09-04 10:55:19,042 [3-31] INFO  SQLDataSource - [builtinApplication.table_fetch] 6: Executing SQL query on 'SQLSERVER': SELECT t_schueler.f_schueler_id, t_schueler.f_name FROM t_schueler WHERE (t_schueler.f_schueler_id=10655)
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG SQLConnectionManager - [builtinApplication.table_fetch] Borrowed connection '1542626358'
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG SQLDriver - [builtinApplication.table_fetch] About to execute SQL query in 'SQLSERVER' using connection '1542626358'
                      === 2014-09-04 10:55:19,042 [3-31] INFO  SQLDriver - [builtinApplication.table_fetch] Executing SQL query on 'SQLSERVER': SELECT t_schueler.f_schueler_id, t_schueler.f_name FROM t_schueler WHERE (t_schueler.f_schueler_id=10655)
                      === 2014-09-04 10:55:19,042 [3-31] INFO  DSResponse - [builtinApplication.table_fetch] DSResponse: List with 1 items
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
                      === 2014-09-04 10:55:19,042 [3-31] DEBUG RPCManager - non-DMI response, dropExtraFields: false
                      === 2014-09-04 10:55:19,057 [3-31] DEBUG SQLDriver - Freeing SQLDriver dbConnection 1542626358
                      === 2014-09-04 10:55:19,057 [3-31] DEBUG SQLConnectionManager - About to close ISCPoolableConnection with hashcode "1542626358"
                      === 2014-09-04 10:55:19,057 [3-31] INFO  Compression - /builtinds/sc/IDACall: 224 -> 187 bytes
                      === 2014-09-04 10:56:14,052 [3-27] 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
                      === 2014-09-04 10:56:14,052 [3-27] DEBUG IDACall - Header Name:Value pair: Cookie:isc_cState=ready; JSESSIONID=c7snbany7hysalqx61pc1lw9; GLog=%7B%0D%20%20%20%20left%3A321%2C%20%0D%20%20%20%20top%3A175%2C%20%0D%20%20%20%20width%3A1364%2C%20%0D%20%20%20%20height%3A705%2C%20%0D%20%20%20%20priorityDefaults%3A%7B%0D%20%20%20%20%20%20%20%20Log%3A4%0D%20%20%20%20%7D%2C%20%0D%20%20%20%20defaultPriority%3A3%2C%20%0D%20%20%20%20trackRPC%3Atrue%0D%7D
                      === 2014-09-04 10:56:14,052 [3-27] DEBUG IDACall - Header Name:Value pair: Host:127.0.0.1:8888
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - Header Name:Value pair: Accept:text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - Header Name:Value pair: Content-Length:1243
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - Header Name:Value pair: Content-Type:application/x-www-form-urlencoded; charset=UTF-8
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - Header Name:Value pair: Accept-Language:de-de,de;q=0.8,en-us;q=0.5,en;q=0.3
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - Header Name:Value pair: Pragma:no-cache
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - Header Name:Value pair: Connection:keep-alive
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - Header Name:Value pair: Referer:http://127.0.0.1:8888/BuiltInDS.html?gwt.codesvr=127.0.0.1:9997
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - Header Name:Value pair: User-Agent:Mozilla/5.0 (Windows NT 6.3; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - Header Name:Value pair: Cache-Control:no-cache
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - Header Name:Value pair: Accept-Encoding:gzip, deflate
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - session exists: c7snbany7hysalqx61pc1lw9
                      === 2014-09-04 10:56:14,059 [3-27] DEBUG IDACall - remote user: null
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG XML - Parsed XML from (in memory stream): 0ms
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'transaction'
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'Object'
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'List'
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'elem'
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG RPCManager - Processing 1 requests.
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG ISCKeyedObjectPool - Borrowing object for 'table'
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG DSRequest - Caching instance 6 of DS table from DSRequest.getDataSource()
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG RPCManager - Request #1 (DSRequest) payload: {
                          criteria:{
                              f_schueler_id:10655
                          },
                          values:{
                              f_schueler_id:10655,
                              f_name:"xxx"
                          },
                          operationConfig:{
                              dataSource:"table",
                              operationType:"update",
                              textMatchStyle:"exact"
                          },
                          componentId:"isc_ValuesManager_0",
                          appID:"builtinApplication",
                          operation:"table_update",
                          oldValues:{
                              f_schueler_id:10655,
                              f_name:" Kwak"
                          }
                      }
                      === 2014-09-04 10:56:14,060 [3-27] INFO  IDACall - Performing 1 operation(s)
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG DeclarativeSecurity - Processing security checks for DataSource null, field null
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG DeclarativeSecurity - DataSource table is not in the pre-checked list, processing...
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG AppBase - [builtinApplication.table_update] No userTypes defined, allowing anyone access to all operations for this application
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG AppBase - [builtinApplication.table_update] No public zero-argument method named '_table_update' found, performing generic datasource operation
                      === 2014-09-04 10:56:14,060 [3-27] INFO  SQLDataSource - [builtinApplication.table_update] Performing update operation with
                      	criteria: {f_schueler_id:10655}	values: {f_schueler_id:10655,f_name:"xxx"}
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG SQLConnectionManager - [builtinApplication.table_update] Borrowed connection '1542626358'
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG SQLTransaction - [builtinApplication.table_update] Started new SQLSERVER transaction "1542626358"
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG SQLDriver - [builtinApplication.table_update] About to execute SQL update in 'SQLSERVER' using connection'1542626358'
                      === 2014-09-04 10:56:14,060 [3-27] INFO  SQLDriver - [builtinApplication.table_update] Executing SQL update on 'SQLSERVER': UPDATE t_schueler SET f_name='xxx' WHERE (t_schueler.f_schueler_id=10655)
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG SQLDataSource - [builtinApplication.table_update] update operation affected 1 rows
                      === 2014-09-04 10:56:14,060 [3-27] INFO  SQLDataSource - [builtinApplication.table_update] primaryKeys: {f_schueler_id=10655}
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG SQLDataSource - [builtinApplication.table_update] Added JDBC-generated values to the list of primaryKeys.  Key values are now: {f_schueler_id=11798}
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG DeclarativeSecurity - [builtinApplication.table_update] Processing security checks for DataSource null, field null
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG DeclarativeSecurity - [builtinApplication.table_update] DataSource table is not in the pre-checked list, processing...
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG AppBase - [builtinApplication.table_update, builtinApplication.null] No userTypes defined, allowing anyone access to all operations for this application
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG AppBase - [builtinApplication.table_update, builtinApplication.null] No public zero-argument method named '_null' found, performing generic datasource operation
                      === 2014-09-04 10:56:14,060 [3-27] INFO  SQLDataSource - [builtinApplication.table_update, builtinApplication.null] Performing fetch operation with
                      	criteria: {f_schueler_id:11798}	values: {f_schueler_id:11798}
                      === 2014-09-04 10:56:14,060 [3-27] INFO  SQLDataSource - [builtinApplication.table_update, builtinApplication.null] derived query: SELECT $defaultSelectClause FROM $defaultTableClause WHERE $defaultWhereClause
                      === 2014-09-04 10:56:14,060 [3-27] INFO  SQLDataSource - [builtinApplication.table_update, builtinApplication.null] 6: Executing SQL query on 'SQLSERVER': SELECT t_schueler.f_schueler_id, t_schueler.f_name FROM t_schueler WHERE (t_schueler.f_schueler_id=11798)
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG SQLDriver - [builtinApplication.table_update, builtinApplication.null] About to execute SQL query in 'SQLSERVER' using connection '1542626358'
                      === 2014-09-04 10:56:14,060 [3-27] INFO  SQLDriver - [builtinApplication.table_update, builtinApplication.null] Executing SQL query on 'SQLSERVER': SELECT t_schueler.f_schueler_id, t_schueler.f_name FROM t_schueler WHERE (t_schueler.f_schueler_id=11798)
                      === 2014-09-04 10:56:14,060 [3-27] INFO  DSResponse - [builtinApplication.table_update, builtinApplication.null] DSResponse: List with 1 items
                      === 2014-09-04 10:56:14,060 [3-27] INFO  DSResponse - [builtinApplication.table_update] DSResponse: List with 1 items
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG RPCManager - Content type for RPC transaction: text/plain; charset=UTF-8
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG SQLTransaction - Committing SQLSERVER transaction "1542626358"
                      === 2014-09-04 10:56:14,060 [3-27] DEBUG RPCManager - non-DMI response, dropExtraFields: false
                      === 2014-09-04 10:56:14,076 [3-27] DEBUG SQLTransaction - getConnection() found transactional connection for SQLSERVER with hashcode "1542626358"
                      === 2014-09-04 10:56:14,076 [3-27] DEBUG SQLTransaction - Ending SQLSERVER transaction "1542626358"
                      === 2014-09-04 10:56:14,076 [3-27] DEBUG SQLConnectionManager - About to close ISCPoolableConnection with hashcode "1542626358"
                      === 2014-09-04 10:56:14,076 [3-27] INFO  Compression - /builtinds/sc/IDACall: 191 -> 167 bytes
                      === 2014-09-04 10:59:06,519 [3-29] INFO  RequestContext - URL: '/builtinds/sc/system/development/ISC_ServerLogViewer.js', User-Agent: 'Mozilla/5.0 (Windows NT 6.3; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0': Moz (Gecko) with Accept-Encoding header
                      === 2014-09-04 10:59:06,524 [3-29] INFO  Download - done streaming: C:/Users/Eduardo/Documents/zedes2/built-in-ds/war/builtinds/sc/system/development/ISC_ServerLogViewer.js
                      === 2014-09-04 10:59:06,526 [3-29] INFO  Compression - /builtinds/sc/system/development/ISC_ServerLogViewer.js: 9051 -> 3104 bytes
                      === 2014-09-04 10:59:06,832 [3-30] 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
                      === 2014-09-04 10:59:06,845 [3-30] INFO  Compression - /builtinds/sc/IDACall: 81 -> 86 bytes
                      === 2014-09-04 10:59:06,937 [3-29] 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
                      The java.lang.IllegalStateException: NO CONTENT only occurs when using jetty.. when using apache, I have the same behavior but without the exception
                      Last edited by edulid; 4 Sep 2014, 01:01.

                      Comment


                        #12
                        Hi edulid,

                        you are correct, this looks really weird.

                        I remember having a problem with stale DS-definitions clientside while developing (when using "unconfigured" Tomcat, it allows the browser to cache the result of the DSLoader-call (GET)), which leaded to strange results in my case.
                        Could you clear your cache and try again?

                        Best regards,
                        Blama
                        Last edited by Blama; 4 Sep 2014, 01:12. Reason: log request removed

                        Comment


                          #13
                          I have cleared the cache many times since I observe this behavior, and it is always the same.
                          So this doesn't change anything.

                          You can see the server log for my last request in my last post, 2014-09-04 10:56:14,060 DEBUG RPCManager downwards.
                          Last edited by edulid; 4 Sep 2014, 01:17.

                          Comment


                            #14
                            Hi edulid, Hi Isomorphic,

                            yes, we were crossposting / you updated your post.

                            It has nothing to do with the cache issues I mentioned.

                            Error happens in the last of this rows:
                            Code:
                            === 2014-09-04 10:56:14,060 [3-27] INFO  SQLDriver - [builtinApplication.table_update] Executing SQL update on 'SQLSERVER': UPDATE t_schueler SET f_name='xxx' WHERE (t_schueler.f_schueler_id=10655)
                            === 2014-09-04 10:56:14,060 [3-27] DEBUG SQLDataSource - [builtinApplication.table_update] update operation affected 1 rows
                            === 2014-09-04 10:56:14,060 [3-27] INFO  SQLDataSource - [builtinApplication.table_update] primaryKeys: {f_schueler_id=10655}
                            === 2014-09-04 10:56:14,060 [3-27] DEBUG SQLDataSource - [builtinApplication.table_update] Added JDBC-generated values to the list of primaryKeys.  Key values are now: {f_schueler_id=11798}
                            For update, no sequence calls should be necessary. So it seems to be a bug, perhaps related to this thread.

                            Best regards,
                            Blama

                            Comment


                              #15
                              Just a note to say one of our developers is looking into how you could be getting this issue / behavior. We'll follow up when we have more information

                              Regards
                              Isomorphic Software

                              Comment

                              Working...
                              X