Re: Identity projection - Mailing list pgsql-hackers

Hello, sorry for long absense,

#  I had unexpected and urgent time-consuming tasks... :-(

I have had a bit more precise inspection by two aspects, and they
seemd showing that the difference should be the execution time of
ExecProject.

I'll be able to back fully next week with reviesed patch, and to
take some other pathes to review...


============
> Although I said as following, the gain seems a bit larger... I'll
> recheck the testing conditions...

I had inspected more precisely on two aspects maginifying the
effect of this patch by putting 300 columns into table.


First, explain analyze says the difference caused by this patch
is only in the actual time of Result node.

orig$ psql -c 'explain analyze select * from parenta'                         QUERY PLAN
--------------------------------------------------------------------------Result  (cost=0.00..176667.00 rows=1000001
width=1202)       (actual time=0.013.. *2406.792* rows=1000000 loops=1)  ->  Append  (cost=0.00..176667.00 rows=1000001
width=1202)             (actual time=0.011..412.749 rows=1000000 loops=1)        ->  Seq Scan on parenta
(cost=0.00..0.00rows=1 width=1228)                                 (actual time=0.001..0.001 rows=0 loops=1)        ->
SeqScan on childa000 parenta                           (cost=0.00..176667.00 rows=1000000 width=1202)
       (actual time=0.009..334.633 rows=1000000 loops=1)Total runtime: 2446.474 ms
 
(5 rows)

patched$ psql -c 'explain analyze select * from parenta'                         QUERY PLAN
--------------------------------------------------------------------------Result  (cost=0.00..176667.00 rows=1000001
width=1202)       (actual time=0.011.. *507.239* rows=1000000 loops=1)  ->  Append  (cost=0.00..176667.00 rows=1000001
width=1202)             (actual time=0.011..419.420 rows=1000000 loops=1)        ->  Seq Scan on parenta
(cost=0.00..0.00rows=1 width=1228)                                 (actual time=0.000..0.000 rows=0 loops=1)        ->
SeqScan on childa000 parenta                           (cost=0.00..176667.00 rows=1000000 width=1202)
       (actual time=0.010..335.721 rows=1000000 loops=1)Total runtime: 545.879 ms
 
(5 rows)

Second, the results of configure --enable-profiling shows that
the exectime of ExecProject chages greately. This is consistent
with what explain showed.

orig:>  %   cumulative   self              self     total           > time   seconds   seconds    calls   s/call
s/call name    > 60.29      1.26     1.26  1000005     0.00     0.00  slot_deform_tuple
 
!> 30.14      1.89     0.63  1000000     0.00     0.00  ExecProject>  3.35      1.96     0.07  3000004     0.00
0.00 ExecProcNode>  0.96      1.98     0.02  1000002     0.00     0.00  ExecScan>  0.96      2.00     0.02   166379
0.00    0.00  TerminateBufferIO>  0.48      2.01     0.01  3000004     0.00     0.00  InstrStartNode>  0.48      2.02
 0.01  3000004     0.00     0.00  InstrStopNode
 
!>  0.48      2.03     0.01  1000001     0.00     0.00  ExecResult>  0.48      2.04     0.01   830718     0.00     0.00
LWLockAcquire>  0.48      2.05     0.01   506834     0.00     0.00  hash_search_with_hash_value>  0.48      2.06
0.01  341656     0.00     0.00  LockBuffer>  0.48      2.07     0.01   168383     0.00     0.00  ReadBuffer_common>
0.48     2.08     0.01        4     0.00     0.00  InstrEndLoop>  0.48      2.09     0.01
ExecCleanTargetListLength> 0.00      2.09     0.00  2000005     0.00     0.00  MemoryContextReset
 

patched:>   %   cumulative   self              self     total           >  time   seconds   seconds    calls  ms/call
ms/call name    >  23.08      0.03     0.03  3000004     0.00     0.00  ExecProcNode>  15.38      0.05     0.02
1000002    0.00     0.00  heapgettup_pagemode>  15.38      0.07     0.02   830718     0.00     0.00  LWLockAcquire>
7.69     0.08     0.01  2000005     0.00     0.00  MemoryContextReset>   7.69      0.09     0.01  1000002     0.00
0.00 ExecScan>   7.69      0.10     0.01  1000000     0.00     0.00  ExecStoreTuple>   7.69      0.11     0.01   841135
   0.00     0.00  LWLockRelease>   7.69      0.12     0.01   168383     0.00     0.00  ReadBuffer_common>   7.69
0.13    0.01   168383     0.00     0.00  UnpinBuffer>   0.00      0.13     0.00  3000004     0.00     0.00
InstrStartNode...
!>   0.00      0.13     0.00  1000001     0.00     0.00  ExecResult
!>   0.00      0.13     0.00  1000000     0.00     0.00  ExecProject





regards,

-- 
Kyotaro Horiguchi
NTT Open Source Software Center