Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

Commit40b9b95

Browse files
committed
New GUC, track_iotiming, to track I/O timings.
Currently, the only way to see the numbers this gathers is viaEXPLAIN (ANALYZE, BUFFERS), but the plan is to add visibility throughthe stats collector and pg_stat_statements in subsequent patches.Ants Aasma, reviewed by Greg Smith, with some further changes by me.
1 parent98316e2 commit40b9b95

File tree

8 files changed

+72
-0
lines changed

8 files changed

+72
-0
lines changed

‎doc/src/sgml/config.sgml

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4284,6 +4284,21 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
42844284
</listitem>
42854285
</varlistentry>
42864286

4287+
<varlistentry id="guc-track-iotiming" xreflabel="track_iotiming">
4288+
<term><varname>track_iotiming</varname> (<type>boolean</type>)</term>
4289+
<indexterm>
4290+
<primary><varname>track_iotiming</> configuration parameter</primary>
4291+
</indexterm>
4292+
<listitem>
4293+
<para>
4294+
Enables timing of database I/O calls. This parameter is off by
4295+
default, because it will repeatedly query the operating system for
4296+
the current time, which may cause significant overhead on some
4297+
platforms. Only superusers can change this setting.
4298+
</para>
4299+
</listitem>
4300+
</varlistentry>
4301+
42874302
<varlistentry id="guc-track-functions" xreflabel="track_functions">
42884303
<term><varname>track_functions</varname> (<type>enum</type>)</term>
42894304
<indexterm>

‎src/backend/commands/explain.c

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1236,6 +1236,8 @@ ExplainNode(PlanState *planstate, List *ancestors,
12361236
usage->local_blks_written>0);
12371237
boolhas_temp= (usage->temp_blks_read>0||
12381238
usage->temp_blks_written>0);
1239+
boolhas_timing= (!INSTR_TIME_IS_ZERO(usage->time_read)||
1240+
!INSTR_TIME_IS_ZERO(usage->time_write));
12391241

12401242
/* Show only positive counter values. */
12411243
if (has_shared||has_local||has_temp)
@@ -1291,6 +1293,20 @@ ExplainNode(PlanState *planstate, List *ancestors,
12911293
}
12921294
appendStringInfoChar(es->str,'\n');
12931295
}
1296+
1297+
/* As above, show only positive counter values. */
1298+
if (has_timing)
1299+
{
1300+
appendStringInfoSpaces(es->str,es->indent*2);
1301+
appendStringInfoString(es->str,"I/O Timings:");
1302+
if (!INSTR_TIME_IS_ZERO(usage->time_read))
1303+
appendStringInfo(es->str," read=%0.2f",
1304+
INSTR_TIME_GET_MILLISEC(usage->time_read));
1305+
if (!INSTR_TIME_IS_ZERO(usage->time_write))
1306+
appendStringInfo(es->str," write=%0.2f",
1307+
INSTR_TIME_GET_MILLISEC(usage->time_write));
1308+
appendStringInfoChar(es->str,'\n');
1309+
}
12941310
}
12951311
else
12961312
{
@@ -1304,6 +1320,8 @@ ExplainNode(PlanState *planstate, List *ancestors,
13041320
ExplainPropertyLong("Local Written Blocks",usage->local_blks_written,es);
13051321
ExplainPropertyLong("Temp Read Blocks",usage->temp_blks_read,es);
13061322
ExplainPropertyLong("Temp Written Blocks",usage->temp_blks_written,es);
1323+
ExplainPropertyFloat("I/O Read Time",INSTR_TIME_GET_MILLISEC(usage->time_read),3,es);
1324+
ExplainPropertyFloat("I/O Write Time",INSTR_TIME_GET_MILLISEC(usage->time_write),3,es);
13071325
}
13081326
}
13091327

‎src/backend/executor/instrument.c

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -145,4 +145,6 @@ BufferUsageAccumDiff(BufferUsage *dst,
145145
dst->local_blks_written+=add->local_blks_written-sub->local_blks_written;
146146
dst->temp_blks_read+=add->temp_blks_read-sub->temp_blks_read;
147147
dst->temp_blks_written+=add->temp_blks_written-sub->temp_blks_written;
148+
INSTR_TIME_ACCUM_DIFF(dst->time_read,add->time_read,sub->time_read);
149+
INSTR_TIME_ACCUM_DIFF(dst->time_write,add->time_write,sub->time_write);
148150
}

‎src/backend/storage/buffer/bufmgr.c

Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,7 @@
6767
boolzero_damaged_pages= false;
6868
intbgwriter_lru_maxpages=100;
6969
doublebgwriter_lru_multiplier=2.0;
70+
booltrack_iotiming= false;
7071

7172
/*
7273
* How many buffers PrefetchBuffer callers should try to stay ahead of their
@@ -437,8 +438,21 @@ ReadBuffer_common(SMgrRelation smgr, char relpersistence, ForkNumber forkNum,
437438
MemSet((char*)bufBlock,0,BLCKSZ);
438439
else
439440
{
441+
instr_timeio_start,
442+
io_time;
443+
444+
if (track_iotiming)
445+
INSTR_TIME_SET_CURRENT(io_start);
446+
440447
smgrread(smgr,forkNum,blockNum, (char*)bufBlock);
441448

449+
if (track_iotiming)
450+
{
451+
INSTR_TIME_SET_CURRENT(io_time);
452+
INSTR_TIME_SUBTRACT(io_time,io_start);
453+
INSTR_TIME_ADD(pgBufferUsage.time_read,io_time);
454+
}
455+
442456
/* check for garbage data */
443457
if (!PageHeaderIsValid((PageHeader)bufBlock))
444458
{
@@ -1874,6 +1888,7 @@ FlushBuffer(volatile BufferDesc *buf, SMgrRelation reln)
18741888
{
18751889
XLogRecPtrrecptr;
18761890
ErrorContextCallbackerrcontext;
1891+
instr_timeio_start,io_end;
18771892

18781893
/*
18791894
* Acquire the buffer's io_in_progress lock. If StartBufferIO returns
@@ -1921,12 +1936,21 @@ FlushBuffer(volatile BufferDesc *buf, SMgrRelation reln)
19211936
buf->flags &= ~BM_JUST_DIRTIED;
19221937
UnlockBufHdr(buf);
19231938

1939+
if (track_iotiming)
1940+
INSTR_TIME_SET_CURRENT(io_start);
1941+
19241942
smgrwrite(reln,
19251943
buf->tag.forkNum,
19261944
buf->tag.blockNum,
19271945
(char*)BufHdrGetBlock(buf),
19281946
false);
19291947

1948+
if (track_iotiming)
1949+
{
1950+
INSTR_TIME_SET_CURRENT(io_end);
1951+
INSTR_TIME_ACCUM_DIFF(pgBufferUsage.time_write,io_end,io_start);
1952+
}
1953+
19301954
pgBufferUsage.shared_blks_written++;
19311955

19321956
/*

‎src/backend/utils/misc/guc.c

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1018,6 +1018,15 @@ static struct config_bool ConfigureNamesBool[] =
10181018
true,
10191019
NULL,NULL,NULL
10201020
},
1021+
{
1022+
{"track_iotiming",PGC_SUSET,STATS_COLLECTOR,
1023+
gettext_noop("Collects timing information for database IO activity."),
1024+
NULL
1025+
},
1026+
&track_iotiming,
1027+
false,
1028+
NULL,NULL,NULL
1029+
},
10211030

10221031
{
10231032
{"update_process_title",PGC_SUSET,STATS_COLLECTOR,

‎src/backend/utils/misc/postgresql.conf.sample

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -424,6 +424,7 @@
424424

425425
#track_activities = on
426426
#track_counts = on
427+
#track_iotiming = off
427428
#track_functions = none# none, pl, all
428429
#track_activity_query_size = 1024 # (change requires restart)
429430
#update_process_title = on

‎src/include/executor/instrument.h

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -28,6 +28,8 @@ typedef struct BufferUsage
2828
longlocal_blks_written;/* # of local disk blocks written */
2929
longtemp_blks_read;/* # of temp blocks read */
3030
longtemp_blks_written;/* # of temp blocks written */
31+
instr_timetime_read;/* time spent reading */
32+
instr_timetime_write;/* time spent writing */
3133
}BufferUsage;
3234

3335
/* Flag bits included in InstrAlloc's instrument_options bitmask */

‎src/include/storage/bufmgr.h

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -48,6 +48,7 @@ extern PGDLLIMPORT int NBuffers;
4848
externboolzero_damaged_pages;
4949
externintbgwriter_lru_maxpages;
5050
externdoublebgwriter_lru_multiplier;
51+
externbooltrack_iotiming;
5152
externinttarget_prefetch_pages;
5253

5354
/* in buf_init.c */

0 commit comments

Comments
 (0)
[8]ページ先頭
©2009-2025 Movatter.jp