Uploaded image for project: 'Teiid'
  1. Teiid
  2. TEIID-1884

COMMAND Logging incorrectly reporting END USER COMMAND record count in EDS for forward only resultsets

    XMLWordPrintable

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Done
    • 7.1, 7.2, 7.3, 7.4, 7.5, 7.6
    • 7.7, 8.0
    • Query Engine
    • None
    • Hide

      Reproduced at below details:
      jdbc:teiid:CIStest@mm://vm178.gsslab.rdu.redhat.com:31000
      EDS_HOME= /opt/jboss/jboss-soa-p-5/jboss-as/server/default

      COMMAND logging is reporting incorrect row counts for commands. Executing both of below queries results in finalRowCount=1 for END SRC COMMAND and finalRowCount=0 for END USER COMMAND. Actual row counts are indicated after each query. While the data source command could be considered 1 row (these are queries against a webservice, so returning 1 XML string may indicate a correct value of finalRowCount=1), the user command should be reporting the number of rows returned to the user.

      ------------------------------------------------
      queries executed against vm178
      ------------------------------------------------
      select * from CIS_Test.GetLanguageName where LanguageISOCode='fin'
      1 row

      select * from CIS_Test.GetListOfLanguageNames
      406 rows

      ------------------------------------------------
      content of vm178 teiid-command.log after executing above queries
      ------------------------------------------------

      2011-12-20 22:04:25,819 DEBUG [org.teiid.COMMAND_LOG] (New I/O server worker #1-2 START USER COMMAND: startTime=2011-12-20 22:04:25.819 requestID=gxd9n5MXK4Pz.0 txID=null sessionID=gxd9n5MXK4Pz applicationName=JDBC principal=user@teiid-security vdbName=CIStest vdbVersion=1 sql=select * from CIS_Test.GetLanguageName where LanguageISOCode='fin'
      2011-12-20 22:04:26,450 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue3 START DATA SRC COMMAND: startTime=2011-12-20 22:04:26.45 requestID=gxd9n5MXK4Pz.0 sourceCommandID=7 txID=null modelName=CountryInfoService connectorBindingName=ws sessionID=gxd9n5MXK4Pz principal=user@teiid-security sql=EXEC CountryInfoService.invoke('SOAP11', null, 'org.teiid.core.types.SQLXMLImpl@e11764', null)
      2011-12-20 22:04:27,011 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue5 END SRC COMMAND: endTime=2011-12-20 22:04:27.011 requestID=gxd9n5MXK4Pz.0 sourceCommandID=7 txID=null modelName=CountryInfoService connectorBindingName=ws sessionID=gxd9n5MXK4Pz principal=user@teiid-security finalRowCount=1
      2011-12-20 22:04:27,243 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue6 END USER COMMAND: endTime=2011-12-20 22:04:27.243 requestID=gxd9n5MXK4Pz.0 txID=null sessionID=gxd9n5MXK4Pz principal=user@teiid-security vdbName=CIStest vdbVersion=1 finalRowCount=0
      2011-12-20 22:12:18,230 DEBUG [org.teiid.COMMAND_LOG] (New I/O server worker #1-2 START USER COMMAND: startTime=2011-12-20 22:12:18.23 requestID=gxd9n5MXK4Pz.1 txID=null sessionID=gxd9n5MXK4Pz applicationName=JDBC principal=user@teiid-security vdbName=CIStest vdbVersion=1 sql=select * from CIS_Test.GetListOfLanguageNames
      2011-12-20 22:12:18,249 DEBUG [org.teiid.COMMAND_LOG] (Worker3_QueryProcessorQueue8 START DATA SRC COMMAND: startTime=2011-12-20 22:12:18.249 requestID=gxd9n5MXK4Pz.1 sourceCommandID=7 txID=null modelName=CountryInfoService connectorBindingName=ws sessionID=gxd9n5MXK4Pz principal=user@teiid-security sql=EXEC CountryInfoService.invoke('SOAP11', 'ListOfLanguagesByName', 'org.teiid.core.types.SQLXMLImpl@1f91fcd', null)
      2011-12-20 22:12:19,139 DEBUG [org.teiid.COMMAND_LOG] (Worker3_QueryProcessorQueue10 END SRC COMMAND: endTime=2011-12-20 22:12:19.139 requestID=gxd9n5MXK4Pz.1 sourceCommandID=7 txID=null modelName=CountryInfoService connectorBindingName=ws sessionID=gxd9n5MXK4Pz principal=user@teiid-security finalRowCount=1
      2011-12-20 22:12:19,476 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue11 END USER COMMAND: endTime=2011-12-20 22:12:19.476 requestID=gxd9n5MXK4Pz.1 txID=null sessionID=gxd9n5MXK4Pz principal=user@teiid-security vdbName=CIStest vdbVersion=1 finalRowCount=0

      Show
      Reproduced at below details: jdbc:teiid:CIStest@mm://vm178.gsslab.rdu.redhat.com:31000 EDS_HOME= /opt/jboss/jboss-soa-p-5/jboss-as/server/default COMMAND logging is reporting incorrect row counts for commands. Executing both of below queries results in finalRowCount=1 for END SRC COMMAND and finalRowCount=0 for END USER COMMAND. Actual row counts are indicated after each query. While the data source command could be considered 1 row (these are queries against a webservice, so returning 1 XML string may indicate a correct value of finalRowCount=1), the user command should be reporting the number of rows returned to the user. ------------------------------------------------ queries executed against vm178 ------------------------------------------------ select * from CIS_Test.GetLanguageName where LanguageISOCode='fin' 1 row select * from CIS_Test.GetListOfLanguageNames 406 rows ------------------------------------------------ content of vm178 teiid-command.log after executing above queries ------------------------------------------------ 2011-12-20 22:04:25,819 DEBUG [org.teiid.COMMAND_LOG] (New I/O server worker #1-2 START USER COMMAND: startTime=2011-12-20 22:04:25.819 requestID=gxd9n5MXK4Pz.0 txID=null sessionID=gxd9n5MXK4Pz applicationName=JDBC principal=user@teiid-security vdbName=CIStest vdbVersion=1 sql=select * from CIS_Test.GetLanguageName where LanguageISOCode='fin' 2011-12-20 22:04:26,450 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue3 START DATA SRC COMMAND: startTime=2011-12-20 22:04:26.45 requestID=gxd9n5MXK4Pz.0 sourceCommandID=7 txID=null modelName=CountryInfoService connectorBindingName=ws sessionID=gxd9n5MXK4Pz principal=user@teiid-security sql=EXEC CountryInfoService.invoke('SOAP11', null, 'org.teiid.core.types.SQLXMLImpl@e11764', null) 2011-12-20 22:04:27,011 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue5 END SRC COMMAND: endTime=2011-12-20 22:04:27.011 requestID=gxd9n5MXK4Pz.0 sourceCommandID=7 txID=null modelName=CountryInfoService connectorBindingName=ws sessionID=gxd9n5MXK4Pz principal=user@teiid-security finalRowCount=1 2011-12-20 22:04:27,243 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue6 END USER COMMAND: endTime=2011-12-20 22:04:27.243 requestID=gxd9n5MXK4Pz.0 txID=null sessionID=gxd9n5MXK4Pz principal=user@teiid-security vdbName=CIStest vdbVersion=1 finalRowCount=0 2011-12-20 22:12:18,230 DEBUG [org.teiid.COMMAND_LOG] (New I/O server worker #1-2 START USER COMMAND: startTime=2011-12-20 22:12:18.23 requestID=gxd9n5MXK4Pz.1 txID=null sessionID=gxd9n5MXK4Pz applicationName=JDBC principal=user@teiid-security vdbName=CIStest vdbVersion=1 sql=select * from CIS_Test.GetListOfLanguageNames 2011-12-20 22:12:18,249 DEBUG [org.teiid.COMMAND_LOG] (Worker3_QueryProcessorQueue8 START DATA SRC COMMAND: startTime=2011-12-20 22:12:18.249 requestID=gxd9n5MXK4Pz.1 sourceCommandID=7 txID=null modelName=CountryInfoService connectorBindingName=ws sessionID=gxd9n5MXK4Pz principal=user@teiid-security sql=EXEC CountryInfoService.invoke('SOAP11', 'ListOfLanguagesByName', 'org.teiid.core.types.SQLXMLImpl@1f91fcd', null) 2011-12-20 22:12:19,139 DEBUG [org.teiid.COMMAND_LOG] (Worker3_QueryProcessorQueue10 END SRC COMMAND: endTime=2011-12-20 22:12:19.139 requestID=gxd9n5MXK4Pz.1 sourceCommandID=7 txID=null modelName=CountryInfoService connectorBindingName=ws sessionID=gxd9n5MXK4Pz principal=user@teiid-security finalRowCount=1 2011-12-20 22:12:19,476 DEBUG [org.teiid.COMMAND_LOG] (Worker2_QueryProcessorQueue11 END USER COMMAND: endTime=2011-12-20 22:12:19.476 requestID=gxd9n5MXK4Pz.1 txID=null sessionID=gxd9n5MXK4Pz principal=user@teiid-security vdbName=CIStest vdbVersion=1 finalRowCount=0

    Description

      Running a query [1] that returns 406 rows in sql client, near the end of my log I get this output [2].

      [1] select * from CIS_Test.GetListOfLanguageNames
      [2] 2011-12-28 12:34:34,169 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue26) END USER COMMAND: endTime=2011-12-28 12:34:34.169 requestID=EED0CMZyYmnc.7 txID=null sessionID=EED0CMZyYmnc principal=teiid@teiid-security vdbName=CIStest vdbVersion=1 finalRowCount=0

      Attachments

        Activity

          People

            rhn-engineering-shawkins Steven Hawkins
            rhn-support-jolee Johnathon Lee
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: