Обсуждение: Last log line for log_temp_files is disassociated with query

Folks,

I've been trying to write some tools which (for example) give how much
total temp file space was used by specific individual slow queries.  And
this turns out to be inordinately hard to do because of how
log_temp_files works.

In many cases, this is what I see (9.2.4):

session_line_num|message|query
423|temporary file: path ...procid.0 file size: 525122|SELECT ...
424|temporary file: path ...procid.1 file size: 622044|SELECT ...
425|duration: 17078.635 ms  execute <unnamed>: SELECT ...|NULL
426|temporary file: path ...procid.0 file size: 1771353|NULL

... that is, for some reason, the last log line reported by
log_temp_files becomes disassociated with the query which was using temp
space in the first place.  Often, that last file is the biggest one, as
well.

Is this a fixable bug?  It would make parsing the log for temp file
usage MUCH easier.

Hey, Peter G: there's a feature request for pg_stat_statements: record
cumulative on-disk sort size.

-- 
Josh Berkus
PostgreSQL Experts Inc.
http://pgexperts.com

On 06/07/2013 04:52 PM, Josh Berkus wrote:
> In many cases, this is what I see (9.2.4):
> 
> session_line_num|message|query
> 423|temporary file: path ...procid.0 file size: 525122|SELECT ...
> 424|temporary file: path ...procid.1 file size: 622044|SELECT ...
> 425|duration: 17078.635 ms  execute <unnamed>: SELECT ...|NULL
> 426|temporary file: path ...procid.0 file size: 1771353|NULL

Sorry, that last line should be:

426|temporary file: path ...procid.2 file size: 1771353|NULL


-- 
Josh Berkus
PostgreSQL Experts Inc.
http://pgexperts.com

Josh Berkus <josh@agliodbs.com> writes:
> ... that is, for some reason, the last log line reported by
> log_temp_files becomes disassociated with the query which was using temp
> space in the first place.  Often, that last file is the biggest one, as
> well.

> Is this a fixable bug?

Without a concrete test case, it's hard to say.
        regards, tom lane