[teiid-issues] [JBoss JIRA] (TEIID-3596) Command logging: last command's log is not ended

[Steven Hawkins (JIRA)]

     [ https://issues.jboss.org/browse/TEIID-3596?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Steven Hawkins closed TEIID-3596.
---------------------------------


> Command logging: last command's log is not ended
> ------------------------------------------------
>
>                 Key: TEIID-3596
>                 URL: https://issues.jboss.org/browse/TEIID-3596
>             Project: Teiid
>          Issue Type: Bug
>          Components: Query Engine
>    Affects Versions: 8.7.1.6_2
>            Reporter: Jan Stastny
>            Assignee: Steven Hawkins
>
> There are incomplete entries when performing queries on some vdb and examining the org.teiid.COMMAND_LOG entries in server.log.
> From the logs it seems, that the closing entry for a user command is not logged until either another command is performed or the server is shut down.
> The following logs appears right after the command is performed:
> {code:plain}
> [org.teiid.COMMAND_LOG] (New I/O worker #64)         START USER COMMAND:     startTime=2015-07-28 13:43:18.441       requestID=rfFDiTxhxLGL.0        txID=null       sessionID=rfFDiTxhxLGL  applicationName=JDBC    principal=user at teiid-security   vdbName=Portfolio       vdbVersion=1    sql=select * from product
> [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue1)       START DATA SRC COMMAND: startTime=2015-07-28 13:43:18.54        requestID=rfFDiTxhxLGL.0        sourceCommandID=0       executionID=0   txID=null       modelName=Accounts      translatorName=translator-h2    sessionID=rfFDiTxhxLGL  principal=user at teiid-security   sql=SELECT g_0.ID, g_0.SYMBOL, g_0.COMPANY_NAME FROM Accounts.PRODUCT AS g_0
> [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue2)       END SRC COMMAND:        endTime=2015-07-28 13:43:18.548 requestID=rfFDiTxhxLGL.0        sourceCommandID=0       executionID=0   txID=null       modelName=Accounts      translatorName=translator-h2    sessionID=rfFDiTxhxLGL  principal=user at teiid-security   finalRowCount=25
> {code}
> while the following appers only when the server is shut down (notice the time difference between this one and preceding ones):
> {code:plain}
> [org.teiid.COMMAND_LOG] (New I/O worker #64)         CANCEL USER COMMAND:    endTime=2015-07-28 13:43:29.152 requestID=rfFDiTxhxLGL.0        txID=null       sessionID=rfFDiTxhxLGL  principal=user at teiid-security   vdbName=Portfolio       vdbVersion=1    finalRowCount=null
> {code}
> If there is another command following, the previous command log entry is completed (but it can take even minutes):
> {code:plain}
> [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue3)       END USER COMMAND:       endTime=2015-07-28 14:18:59.511 requestID=q97k+Z4gwV64.0        txID=null       sessionID=q97k+Z4gwV64  principal=user at teiid-security   vdbName=Portfolio       vdbVersion=1    finalRowCount=25
> {code}
> Also the ending log entry of one command and opening entry of another appear in any order.



--
This message was sent by Atlassian JIRA
(v6.4.11#64026)