Re: Buffer Requests Trace

Hello,

I changed the buffer manager code in order to generate a trace of page
requests from the buffer manager perspective. In summary, whenever
ReleaseBuffer() or ReleaseAndReadBuffer() are called, I print the page
currently being released which is identified by the tuple (tableSpace,
dbNode, relationNode, blockNumber).

I am now running a tpcc benchmark from http://oltpbenchmark.com/

Initially I create and load the database with a scale factor of 64. This
sums up to a database of around 6.7GB (~ 800k pages). Then I execute the
tpcc benchmark for 1 minute with only 1 terminal. Finally I analyse the
trace of the buffer requests made by the execution of the benchmark only
(creation and loading not considered).

Unfortunately, in the generated trace with over 2 million buffer requests,
only ~14k different pages are being accessed, out of the 800k of the whole
database. Am I missing something here?

Best regards.
--
Lucas Lersch

* Lucas Lersch (lucaslersch(at)gmail(dot)com) wrote:
> Unfortunately, in the generated trace with over 2 million buffer requests,
> only ~14k different pages are being accessed, out of the 800k of the whole
> database. Am I missing something here?

What do you have shared_buffers set to..?

Thanks,

Stephen

Sorry, I do not understand the question.

But I forgot to give an additional information: I am printing the page id
for the trace file in ReleaseBuffer() only if it is a shared buffer, I am
not considering local buffers. I assumed that local buffers were used only
for temporary tables.

On Tue, Oct 14, 2014 at 6:25 PM, Stephen Frost <sfrost(at)snowman(dot)net> wrote:

> * Lucas Lersch (lucaslersch(at)gmail(dot)com) wrote:
> > Unfortunately, in the generated trace with over 2 million buffer
> requests,
> > only ~14k different pages are being accessed, out of the 800k of the
> whole
> > database. Am I missing something here?
>
> What do you have shared_buffers set to..?
>
> Thanks,
>
> Stephen
>

--
Lucas Lersch

shared_buffers is 128MB and the version of pgsql is 9.3.5

On Tue, Oct 14, 2014 at 6:31 PM, Lucas Lersch <lucaslersch(at)gmail(dot)com> wrote:

> Sorry, I do not understand the question.
>
> But I forgot to give an additional information: I am printing the page id
> for the trace file in ReleaseBuffer() only if it is a shared buffer, I am
> not considering local buffers. I assumed that local buffers were used only
> for temporary tables.
>
> On Tue, Oct 14, 2014 at 6:25 PM, Stephen Frost <sfrost(at)snowman(dot)net> wrote:
>
>> * Lucas Lersch (lucaslersch(at)gmail(dot)com) wrote:
>> > Unfortunately, in the generated trace with over 2 million buffer
>> requests,
>> > only ~14k different pages are being accessed, out of the 800k of the
>> whole
>> > database. Am I missing something here?
>>
>> What do you have shared_buffers set to..?
>>
>> Thanks,
>>
>> Stephen
>>
>
>
>
> --
> Lucas Lersch
>

--
Lucas Lersch

* Lucas Lersch (lucaslersch(at)gmail(dot)com) wrote:
> shared_buffers is 128MB and the version of pgsql is 9.3.5

I suspect you're not tracking what you think you're tracking, which is
why I brought up shared_buffers.

~14k * 8192 (page size) = ~110MB

What it sounds like you're actually tracking are shared buffer requests
and not heap or index requests.

Now, perhaps the test you're running only touched 110MB of the 6G
database, but that seems pretty unlikely.

Thanks,

Stephen

Aren't heap and index requests supposed to go through the shared buffers
anyway?

On Tue, Oct 14, 2014 at 7:02 PM, Stephen Frost <sfrost(at)snowman(dot)net> wrote:

> * Lucas Lersch (lucaslersch(at)gmail(dot)com) wrote:
> > shared_buffers is 128MB and the version of pgsql is 9.3.5
>
> I suspect you're not tracking what you think you're tracking, which is
> why I brought up shared_buffers.
>
> ~14k * 8192 (page size) = ~110MB
>
> What it sounds like you're actually tracking are shared buffer requests
> and not heap or index requests.
>
> Now, perhaps the test you're running only touched 110MB of the 6G
> database, but that seems pretty unlikely.
>
> Thanks,
>
> Stephen
>

--
Lucas Lersch

* Lucas Lersch (lucaslersch(at)gmail(dot)com) wrote:
> Aren't heap and index requests supposed to go through the shared buffers
> anyway?

Sure they do, but a given page in shared_buffers can be used over and
over again for different heap and index pages..

Thanks,

Stephen

I see this... but ReleaseBuffer() simply decrements the reference count of
page the buffer currently holds. Assuming that a ReadBuffer() -
ReleaseBuffer() pattern is used for interacting with the shared_buffers,
there will be a ReleaseBuffer() call for any page (heap or index) "loaded"
into the shared_buffers.

On Tue, Oct 14, 2014 at 7:21 PM, Stephen Frost <sfrost(at)snowman(dot)net> wrote:

> * Lucas Lersch (lucaslersch(at)gmail(dot)com) wrote:
> > Aren't heap and index requests supposed to go through the shared buffers
> > anyway?
>
> Sure they do, but a given page in shared_buffers can be used over and
> over again for different heap and index pages..
>
> Thanks,
>
> Stephen
>

--
Lucas Lersch

* Lucas Lersch (lucaslersch(at)gmail(dot)com) wrote:
> I see this... but ReleaseBuffer() simply decrements the reference count of
> page the buffer currently holds. Assuming that a ReadBuffer() -
> ReleaseBuffer() pattern is used for interacting with the shared_buffers,
> there will be a ReleaseBuffer() call for any page (heap or index) "loaded"
> into the shared_buffers.

Not sure what you're getting at here. This was the original comment
that I was addressing:

-----------
Unfortunately, in the generated trace with over 2 million buffer requests,
only ~14k different pages are being accessed, out of the 800k of the whole
database. Am I missing something here?
-----------

So, there's 2MM buffer requests with only ~14k different pages even
though the database consists of ~800k different pages.

Either your short benchmark is only hitting ~14k different pages out of
the ~800k, or what you're actually looking at are the ~14k pages (eh,
more like 16k, but whatever) of the shared_buffer cache. Somewhere in
your analysis of the 2MM buffer requests you reduced the set of buffer
requests down to the set of "~14k different pages" that you're asking
about here.

What would be helpful here would be actual code changes you made (eg: a
patch), the resulting buffer request data (or at least a snippet of it),
and exactly how you did your analysis to come up with the ~14k number.

Thanks

Stephen

On 14 October 2014 17:08, Lucas Lersch <lucaslersch(at)gmail(dot)com> wrote:

> Unfortunately, in the generated trace with over 2 million buffer requests,
> only ~14k different pages are being accessed, out of the 800k of the whole
> database. Am I missing something here?

We can't tell what you're doing just by knowing the number of unique
items in your list.

--
Simon Riggs http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

Sorry for taking so long to answer. I am sending attached the patch with
the changes I did to pgsql code. I followed the steps for compiling and
installing pgsql from:
http://www.postgresql.org/docs/current/static/install-short.html

In summary, the page_id of the page being released in ReleaseBuffer() and
ReleaseAndReadBuffer() is written to the file: /usr/loca/pgsql/data/trace.
This file is created manually.

I have also created a PrivateDirtyFlag for each backend, in analogy to the
PrivateRefCount. I use this to keep track if the current backend performed
an update operation in a page in the buffer pool or simply a read operation
(it is not relevant now). The trace file consists of one line for each
ReleaseBuffer() or ReleaseAndReadBuffer() call. The line has the format:

operation,tblSpace,dbNode,relNode,blockNumber

Once the trace file is complete after the execution of the tpcc benchmark,
I use the following bash script to get only unique pages:

cut -d',' -f2-5 trace | sort -n -t',' -k1 -k2 -k3 -k4 | uniq

Today I realized that I was making a mistake in executing the
oltpbenchmark application. From the 64 warehouses created for tpcc, only 1
was being accessed (the 14k distinct pages that I mentioned). I increased
the "terminal" option of the tpcc benchmark from 1 to 64, resulting in one
terminal for each warehouse.

This provided me with a higher number of distinct pages being
accessed. Unfortunately, from the 800k pages in the database (64
warehouses), executing tpcc for 10min resulted in 400k distinct pages being
accessed. This number is much better than the previous results, but I think
it is still not realistic.

I would like to thank you guys for all the attention given to my problem :)

On Wed, Oct 15, 2014 at 9:49 AM, Simon Riggs <simon(at)2ndquadrant(dot)com> wrote:

> On 14 October 2014 17:08, Lucas Lersch <lucaslersch(at)gmail(dot)com> wrote:
>
> > Unfortunately, in the generated trace with over 2 million buffer
> requests,
> > only ~14k different pages are being accessed, out of the 800k of the
> whole
> > database. Am I missing something here?
>
> We can't tell what you're doing just by knowing the number of unique
> items in your list.
>
> --
> Simon Riggs http://www.2ndQuadrant.com/
> PostgreSQL Development, 24x7 Support, Training & Services
>

--
Lucas Lersch

On 15 October 2014 12:49, Lucas Lersch <lucaslersch(at)gmail(dot)com> wrote:
> Sorry for taking so long to answer. I am sending attached the patch with the
> changes I did to pgsql code. I followed the steps for compiling and
> installing pgsql from:
> http://www.postgresql.org/docs/current/static/install-short.html

Are you recording the bufferid or the blockid?

--
Simon Riggs http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

I am recording the BufferDesc.tag.blockNum for the buffer along with the
spcNode, dbNode, relNode, also present in the tag.

On Wed, Oct 15, 2014 at 2:27 PM, Simon Riggs <simon(at)2ndquadrant(dot)com> wrote:

> On 15 October 2014 12:49, Lucas Lersch <lucaslersch(at)gmail(dot)com> wrote:
> > Sorry for taking so long to answer. I am sending attached the patch with
> the
> > changes I did to pgsql code. I followed the steps for compiling and
> > installing pgsql from:
> > http://www.postgresql.org/docs/current/static/install-short.html
>
> Are you recording the bufferid or the blockid?
>
> --
> Simon Riggs http://www.2ndQuadrant.com/
> PostgreSQL Development, 24x7 Support, Training & Services
>

--
Lucas Lersch

On 15 October 2014 13:44, Lucas Lersch <lucaslersch(at)gmail(dot)com> wrote:

> I am recording the BufferDesc.tag.blockNum for the buffer along with the
> spcNode, dbNode, relNode, also present in the tag.

The TPC-C I/O is random, so if you run it for longer you should see a wider set.

Cacheing isn't possible as a way to improve txn rates.

Check that you're touching all tables.

--
Simon Riggs http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services

So is it a possible normal behavior that running tpcc for 10min only access
50% of the database? Furthermore, is there a guideline of parameters for
tpcc (# of warehouses, execution time, operations weight)?

On Wed, Oct 15, 2014 at 3:09 PM, Simon Riggs <simon(at)2ndquadrant(dot)com> wrote:

> On 15 October 2014 13:44, Lucas Lersch <lucaslersch(at)gmail(dot)com> wrote:
>
> > I am recording the BufferDesc.tag.blockNum for the buffer along with the
> > spcNode, dbNode, relNode, also present in the tag.
>
> The TPC-C I/O is random, so if you run it for longer you should see a
> wider set.
>
> Cacheing isn't possible as a way to improve txn rates.
>
> Check that you're touching all tables.
>
> --
> Simon Riggs http://www.2ndQuadrant.com/
> PostgreSQL Development, 24x7 Support, Training & Services
>

--
Lucas Lersch

* Lucas Lersch (lucaslersch(at)gmail(dot)com) wrote:
> So is it a possible normal behavior that running tpcc for 10min only access
> 50% of the database? Furthermore, is there a guideline of parameters for
> tpcc (# of warehouses, execution time, operations weight)?

Depends- you may be aware that we support index-only scans in certain
situations. This means that only the index page for a given relation
(and the visibility map) are accessed, and the heap is not.

Thanks,

Stephen

I got the following numbers from my tpcc database:

Data size: ~6059MB
Index size: ~1390MB
Total size: ~7400MB

Even considering index-only scans, the ratio of around 50% of the database
pages being accessed seems unrealistic to me.

On Wed, Oct 15, 2014 at 3:50 PM, Stephen Frost <sfrost(at)snowman(dot)net> wrote:

> * Lucas Lersch (lucaslersch(at)gmail(dot)com) wrote:
> > So is it a possible normal behavior that running tpcc for 10min only
> access
> > 50% of the database? Furthermore, is there a guideline of parameters for
> > tpcc (# of warehouses, execution time, operations weight)?
>
> Depends- you may be aware that we support index-only scans in certain
> situations. This means that only the index page for a given relation
> (and the visibility map) are accessed, and the heap is not.
>
> Thanks,
>
> Stephen
>

--
Lucas Lersch

On Wed, Oct 15, 2014 at 6:22 AM, Lucas Lersch <lucaslersch(at)gmail(dot)com> wrote:

> So is it a possible normal behavior that running tpcc for 10min only
> access 50% of the database? Furthermore, is there a guideline of parameters
> for tpcc (# of warehouses, execution time, operations weight)?
>
>
I'm not familiar with your benchmarking tool. With the one I am most
familiar with, pgbench, if you run it against a database which is too big
to fit in memory, it can take a very long time to touch each page once,
because the constant random disk reads makes it run very slowly. Maybe
that is something to consider here--how many transactions were actually
executed during your 10 min run?

Also, the tool might build tables that are only used under certain run
options. Perhaps you just aren't choosing the options which invoke usage
of those tables. Since you have the trace data, it should be pretty easy
to count how many distinct blocks are accessed from each relation, and
compare that to the size of the relations to see which relations are unused
or lightly used.

Cheers,

Jeff

Answering your first question: running tpcc for 1 minute, in a database
with 64 warehouses (6~7GB), with a buffer pool of 128MB (around 1.8% of
database size) and a hit ratio of ~91%, I get a throughput of 45~50
transactions per second.

I did some experiments and I got the following information about my tpcc
database and benchmark. The database is created with 64 warehouses.

Table | Index | Data Size | Index Size
| Total
------------+--------------------------------------+-----------+------------+---------
stock | stock_pkey | 2209 MB | 263 MB
| 2472 MB
order_line | order_line_pkey | 2041 MB | 678 MB
| 2719 MB
customer | idx_customer_name | 1216 MB | 146 MB
| 1420 MB
customer | customer_pkey | 1216 MB | 58 MB
| 1420 MB
history | | 164 MB |
| 164 MB
oorder | oorder_pkey | 134 MB | 68 MB
| 362 MB
oorder | idx_order | 134 MB | 80 MB
| 362 MB
oorder | oorder_o_w_id_o_d_id_o_c_id_o_id_key | 134 MB | 80 MB
| 362 MB
new_order | new_order_pkey | 27 MB | 17 MB
| 45 MB
item | item_pkey | 10168 kB | 2208 kB
| 12 MB
district | district_pkey | 776 kB | 72 kB
| 880 kB
warehouse | warehouse_pkey | 384 kB | 16 kB
| 432 kB

By executing the tpcc benchmark for 1 minute I get about 2.9 million buffer
requests. The distribution of these requests in the relations and indexes
are (in descending order):

customer 1383399
stock_pkey 442600
stock 321370
order_line 255314
order_line_pkey 156132
oorder 58665
oorder_pkey 57895
customer_pkey 44471
new_order_pkey 39552
idx_customer_name 28286
new_order 25861
item_pkey 11702
item 11606
district 11389
district_pkey 7575
warehouse 5276
idx_order 4072
oorder_o_w_id_o_d_id_o_c_id_o_id_key 2410
warehouse_pkey 1998
history 1958

All this information seems normal to me. However, from the 2.9 million
buffer requests over ~800k pages, only ~150k distinct pages are being
requested. This behavior could be explained by the benchmark accessing only
a small set of the 64 warehouses instead of having a normal distributed
access over the 64 warehouses. In other words, I think that the execution
time of the benchmark is irrelevant, assuming that the transactions follow
a normal distribution regarding accesses to warehouses.

On Wed, Oct 15, 2014 at 7:41 PM, Jeff Janes <jeff(dot)janes(at)gmail(dot)com> wrote:

> On Wed, Oct 15, 2014 at 6:22 AM, Lucas Lersch <lucaslersch(at)gmail(dot)com>
> wrote:
>
>> So is it a possible normal behavior that running tpcc for 10min only
>> access 50% of the database? Furthermore, is there a guideline of parameters
>> for tpcc (# of warehouses, execution time, operations weight)?
>>
>>
> I'm not familiar with your benchmarking tool. With the one I am most
> familiar with, pgbench, if you run it against a database which is too big
> to fit in memory, it can take a very long time to touch each page once,
> because the constant random disk reads makes it run very slowly. Maybe
> that is something to consider here--how many transactions were actually
> executed during your 10 min run?
>
> Also, the tool might build tables that are only used under certain run
> options. Perhaps you just aren't choosing the options which invoke usage
> of those tables. Since you have the trace data, it should be pretty easy
> to count how many distinct blocks are accessed from each relation, and
> compare that to the size of the relations to see which relations are unused
> or lightly used.
>
> Cheers,
>
> Jeff
>

--
Lucas Lersch