[ https://issues.jboss.org/browse/TEIID-3596?page=com.atlassian.jira.plugin... ] Steven Hawkins commented on TEIID-3596: --------------------------------------- There is probably not an issue here - at least not a Teiid issue. CANCEL USER COMMAND: rfFDiTxhxLGL.0 implies that the client had not closed the ResultSet/Statement prior to server shutdown. It is entirely expected that the server will consider the request open. I don't entirely follow. If there is another command on the same client Statement, then the previous one will be implicitly closed. > 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@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@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@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@teiid-security vdbName=Portfolio vdbVersion=1 finalRowCount=null > {code} > {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@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.3.15#6346)