/
Performance Tuning Functions

Performance Tuning Functions

Owned by Paul McCullough (Unlicensed)
Last updated: Jun 13, 2017 by Samuel Valdez

We had a problem with performance on a function that calls lots of other funcitons.
Here is how we found which function was causing the problem.

First, add this line to your poastgres.conf file

  • track_functions = pl

Then, run your function.
Finally, analyze the results as show below.

Script started on Thu 21 Jul 2011 04:34:23 PM PDT
bash-3.2$ exitscreen[2Ppsql
psql (9.0.4)
Type "help" for help.

postgres=# \qselect * from pg_stat_user_functions;

postgres=# \c eas_prod [K
You are now connected to database "eas_prod".
eas_prod=# \c eas_prod q[Kselect * from pg_stat_user_functions;
 funcid | schemaname |             funcname             | calls  | total_time | self_time 
--------+------------+----------------------------------+--------+------------+-----------
 763121 | avs        | process_address_parcel_link      | 190570 |     150040 |    102882
 404372 | avs        | delete_addresses                 |      1 |        322 |       322
 404371 | avs        | init_streets_nearest             |      1 |     343549 |    343549
 404369 | avs        | init_avs_addresses               |      1 |     592559 |    592442
 404370 | avs        | init_parcel_points               |      1 |      22349 |     22349
 404183 | public     | _sfmad_address_base_history      | 152567 |   16930941 |  16930941
 404185 | public     | _sfmad_addresses_history         | 178206 |      26794 |     26794
 404187 | public     | _sfmad_address_x_parcels_history | 195119 |      47157 |     47157
 404299 | public     | _eas_is_date                     |   9177 |        116 |       116
 404305 | public     | _eas_insert_base_address         | 152567 |   17038590 |     84753
 404306 | public     | _eas_insert_unit_address         |  25639 |       9126 |      5227
 404308 | public     | _eas_find_equiv_unit_address     |  26801 |       2072 |      2072
 404373 | avs        | find_address_base                | 191515 |      81506 |     81506
 404374 | avs        | find_nearest_street              | 306329 |      53249 |     53249
 404375 | avs        | find_nearest_street_fancy        | 153396 |     120053 |     66804
 404376 | avs        | process_address_base             | 191515 |   17762263 |    522113
 404377 | avs        | process_address_unit             | 190686 |      25695 |     14496
 404379 | avs        | cascade_retire                   |      1 |        220 |       220
 404380 | avs        | load                             |     20 |   18007181 |     68961
(19 rows)

eas_prod=# select * from pg_stat_user_functions;

eas_prod=# [Kselect func[K[K[K[Ksceh[K[Khemaname, funcname, ( calls[K[K[K[K[Ktotal_time/calls) as avg_tot_time, (self_time/calls as avg>[K_self_time)[K[K[K[K[K[K[K[K[K[K[K[K[K[K[K[K[K[K) as avg_self_time;[K from pg_stat_user_functions;
 schemaname |             funcname             | avg_tot_time | avg_self_time 
------------+----------------------------------+--------------+---------------
 avs        | process_address_parcel_link      |            0 |             0
 avs        | delete_addresses                 |          322 |           322
 avs        | init_streets_nearest             |       343549 |        343549
 avs        | init_avs_addresses               |       592559 |        592442
 avs        | init_parcel_points               |        22349 |         22349
 public     | _sfmad_address_base_history      |          110 |           110
 public     | _sfmad_addresses_history         |            0 |             0
 public     | _sfmad_address_x_parcels_history |            0 |             0
 public     | _eas_is_date                     |            0 |             0
 public     | _eas_insert_base_address         |          111 |             0
 public     | _eas_insert_unit_address         |            0 |             0
 public     | _eas_find_equiv_unit_address     |            0 |             0
 avs        | find_address_base                |            0 |             0
 avs        | find_nearest_street              |            0 |             0
 avs        | find_nearest_street_fancy        |            0 |             0
 avs        | process_address_base             |           92 |             2
 avs        | process_address_unit             |            0 |             0
 avs        | cascade_retire                   |          220 |           220
 avs        | load                             |       900359 |          3448
(19 rows)

eas_prod=# select schemaname, funcname, ( total_time/calls) as avg_tot_time, (self_time/calls) as avg_self_time from pg_stat_user_functions;
eas_prod=# select schemaname, funcname, ( total_time/calls) as avg_tot_time, (self_time/calls[1@:[1@:[1@n[1@u[1@m[1@e[1@r[1@i[1@c[1@:[1@:[1@n[1@u[1@m[1@er) as avg_tot_time, (self_time/calls::numeric) as avg_self_time from pg_stat_user_functions; M
eas_prod=# select schemaname, funcname, ( total_time/calls::numeri) as avg_tot_time, (self_time/calls::numeric) as avg_self_time from pg_stat_user_functions;
;M
eas_prod=# select schemaname, funcname, ( total_time/calls::numeric) as avg_tot_time, (self_time/calls::numeric) as avg_self_time from pg_stat_user_functions;M
eas_prod=# select schemaname, funcname, ( total_time/calls::numeric

 schemaname |             funcname             |      avg_tot_time      |     avg_self_time      
------------+----------------------------------+------------------------+------------------------
 avs        | process_address_parcel_link      | 0.78732224379493099648 | 0.53986461667628692869
 avs        | delete_addresses                 |   322.0000000000000000 |   322.0000000000000000
 avs        | init_streets_nearest             |    343549.000000000000 |    343549.000000000000
 avs        | init_avs_addresses               |    592559.000000000000 |    592442.000000000000
 avs        | init_parcel_points               |     22349.000000000000 |     22349.000000000000
 public     | _sfmad_address_base_history      |   110.9738082285159963 |   110.9738082285159963
 public     | _sfmad_addresses_history         | 0.15035408459872282639 | 0.15035408459872282639
 public     | _sfmad_address_x_parcels_history | 0.24168328045961695171 | 0.24168328045961695171
 public     | _eas_is_date                     | 0.01264029639315680506 | 0.01264029639315680506
 public     | _eas_insert_base_address         |   111.6793933157235837 | 0.55551331546140384225
 public     | _eas_insert_unit_address         | 0.35594211942743476735 | 0.20386910565934708842
 public     | _eas_find_equiv_unit_address     | 0.07731054811387634790 | 0.07731054811387634790
 avs        | find_address_base                | 0.42558546327963867060 | 0.42558546327963867060
 avs        | find_nearest_street              | 0.17382944481260344270 | 0.17382944481260344270
 avs        | find_nearest_street_fancy        | 0.78263448851339017967 | 0.43550027380114214191
 avs        | process_address_base             |    92.7460668877111453 |     2.7262250998616296
 avs        | process_address_unit             | 0.13475032251974450143 | 0.07602026367955696800
 avs        | cascade_retire                   |   220.0000000000000000 |   220.0000000000000000
 avs        | load                             |    900359.050000000000 |  3448.0500000000000000
(19 rows)

eas_prod=# select schemaname, funcname, ( total_time/calls::numeric) as avg_tot_time, (self_time/calls::numeric) as avg_self_time from pg_stat_user_functions
s;
M
eas_prod=# select schemaname, funcname, ( total_time/calls::numeric) as avg_tot_time, (self_time/calls::numeric) as avg_self_time from pg_stat_user_functio (self_time/calls::numeric) as avg_self_time from pg_stat_user_functions;[KM
eas_prod=# select schemaname, funcname, ( total_time/calls::numeric) as avg_tot_time (self_time/calls::numeric) as avg_self_time from pg_stat_user_functions; 
[KM
eas_prod=# select schemaname, funcname, ( total_time/calls::numeric) as avg_tot_tim[1P

[KM
eas_prod=# select schemaname, funcname, ( total_time/calls::numeric) as avg_tot_ti[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1P[1@1[1@0[1@0[1@0[1@:[1@:[1@n[1@u[1@m[1@e[1@r[1@i[1@c[1@)
eas_prod=# select schemaname, funcname, ( total_time/1000::numeric) [1@ [1@a[1@s
eas_prod=# select schemaname, funcname, ( total_time/1000::numeric) as [1@ [1@t[1@o[1@t[1@a[1@l[1@_[1@s[1@,
 schemaname |             funcname             |        total_s         |     avg_self_time      
------------+----------------------------------+------------------------+------------------------
 avs        | process_address_parcel_link      |   150.0400000000000000 | 0.53986461667628692869
 avs        | delete_addresses                 | 0.32200000000000000000 |   322.0000000000000000
 avs        | init_streets_nearest             |   343.5490000000000000 |    343549.000000000000
 avs        | init_avs_addresses               |   592.5590000000000000 |    592442.000000000000
 avs        | init_parcel_points               |    22.3490000000000000 |     22349.000000000000
 public     | _sfmad_address_base_history      |     16930.941000000000 |   110.9738082285159963
 public     | _sfmad_addresses_history         |    26.7940000000000000 | 0.15035408459872282639
 public     | _sfmad_address_x_parcels_history |    47.1570000000000000 | 0.24168328045961695171
 public     | _eas_is_date                     | 0.11600000000000000000 | 0.01264029639315680506
 public     | _eas_insert_base_address         |     17038.590000000000 | 0.55551331546140384225
 public     | _eas_insert_unit_address         |     9.1260000000000000 | 0.20386910565934708842
 public     | _eas_find_equiv_unit_address     |     2.0720000000000000 | 0.07731054811387634790
 avs        | find_address_base                |    81.5060000000000000 | 0.42558546327963867060
 avs        | find_nearest_street              |    53.2490000000000000 | 0.17382944481260344270
 avs        | find_nearest_street_fancy        |   120.0530000000000000 | 0.43550027380114214191
 avs        | process_address_base             |     17762.263000000000 |     2.7262250998616296
 avs        | process_address_unit             |    25.6950000000000000 | 0.07602026367955696800
 avs        | cascade_retire                   | 0.22000000000000000000 |   220.0000000000000000
 avs        | load                             |     18007.181000000000 |  3448.0500000000000000
(19 rows)

eas_prod=# select schemaname, funcname, ( total_time/1000::numeric) as total_s, (self_time/calls::numeric) as avg_self_time from pg_stat_user_functions;[1P[1@6
eas_prod=# select schemaname, funcname, ( total_time/6000[1@0
eas_prod=# select schemaname, funcname, ( total_time/600
eas_prod=# select schemaname, funcname, ( total_time/6000
eas_prod=# select schemaname, funcname, ( total_time/60000
eas_prod=# select schemaname, funcname, ( total_time/60000:
eas_prod=# select schemaname, funcname, ( total_time/60000::
eas_prod=# select schemaname, funcname, ( total_time/60000::n
eas_prod=# select schemaname, funcname, ( total_time/60000::nu
eas_prod=# select schemaname, funcname, ( total_time/60000::num
eas_prod=# select schemaname, funcname, ( total_time/60000::nume
eas_prod=# select schemaname, funcname, ( total_time/60000::numer
eas_prod=# select schemaname, funcname, ( total_time/60000::numeri
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric)
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) 
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) a
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) as
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) as 
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) as t
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) as to
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) as tot
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) as tota
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) as total
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) as total_
eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) as total_s[1P[1@m
 schemaname |             funcname             |        total_m         |     avg_self_time      
------------+----------------------------------+------------------------+------------------------
 avs        | process_address_parcel_link      |     2.5006666666666667 | 0.53986461667628692869
 avs        | delete_addresses                 | 0.00536666666666666667 |   322.0000000000000000
 avs        | init_streets_nearest             |     5.7258166666666667 |    343549.000000000000
 avs        | init_avs_addresses               |     9.8759833333333333 |    592442.000000000000
 avs        | init_parcel_points               | 0.37248333333333333333 |     22349.000000000000
 public     | _sfmad_address_base_history      |   282.1823500000000000 |   110.9738082285159963
 public     | _sfmad_addresses_history         | 0.44656666666666666667 | 0.15035408459872282639
 public     | _sfmad_address_x_parcels_history | 0.78595000000000000000 | 0.24168328045961695171
 public     | _eas_is_date                     | 0.00193333333333333333 | 0.01264029639315680506
 public     | _eas_insert_base_address         |   283.9765000000000000 | 0.55551331546140384225
 public     | _eas_insert_unit_address         | 0.15210000000000000000 | 0.20386910565934708842
 public     | _eas_find_equiv_unit_address     | 0.03453333333333333333 | 0.07731054811387634790
 avs        | find_address_base                |     1.3584333333333333 | 0.42558546327963867060
 avs        | find_nearest_street              | 0.88748333333333333333 | 0.17382944481260344270
 avs        | find_nearest_street_fancy        |     2.0008833333333333 | 0.43550027380114214191
 avs        | process_address_base             |   296.0377166666666667 |     2.7262250998616296
 avs        | process_address_unit             | 0.42825000000000000000 | 0.07602026367955696800
 avs        | cascade_retire                   | 0.00366666666666666667 |   220.0000000000000000
 avs        | load                             |   300.1196833333333333 |  3448.0500000000000000
(19 rows)

eas_prod=# select schemaname, funcname, ( total_time/60000::numeric) as total_m, (self_time/calls::numeric) as avg_self_time from pg_stat_user_functions;
eas_prod=# select schemaname, funcname, ( total[1P[1P[1P[1P[1P[1@s[1@e[1@l[1@f
 schemaname |             funcname             |        total_m         |     avg_self_time      
------------+----------------------------------+------------------------+------------------------
 avs        | process_address_parcel_link      |     1.7147000000000000 | 0.53986461667628692869
 avs        | delete_addresses                 | 0.00536666666666666667 |   322.0000000000000000
 avs        | init_streets_nearest             |     5.7258166666666667 |    343549.000000000000
 avs        | init_avs_addresses               |     9.8740333333333333 |    592442.000000000000
 avs        | init_parcel_points               | 0.37248333333333333333 |     22349.000000000000
 public     | _sfmad_address_base_history      |   282.1823500000000000 |   110.9738082285159963
 public     | _sfmad_addresses_history         | 0.44656666666666666667 | 0.15035408459872282639
 public     | _sfmad_address_x_parcels_history | 0.78595000000000000000 | 0.24168328045961695171
 public     | _eas_is_date                     | 0.00193333333333333333 | 0.01264029639315680506
 public     | _eas_insert_base_address         |     1.4125500000000000 | 0.55551331546140384225
 public     | _eas_insert_unit_address         | 0.08711666666666666667 | 0.20386910565934708842
 public     | _eas_find_equiv_unit_address     | 0.03453333333333333333 | 0.07731054811387634790
 avs        | find_address_base                |     1.3584333333333333 | 0.42558546327963867060
 avs        | find_nearest_street              | 0.88748333333333333333 | 0.17382944481260344270
 avs        | find_nearest_street_fancy        | 1.11340000000000000000 | 0.43550027380114214191
 avs        | process_address_base             |     8.7018833333333333 |     2.7262250998616296
 avs        | process_address_unit             | 0.24160000000000000000 | 0.07602026367955696800
 avs        | cascade_retire                   | 0.00366666666666666667 |   220.0000000000000000
 avs        | load                             | 1.14935000000000000000 |  3448.0500000000000000
(19 rows)

eas_prod=# select null is not distinct from numm[K[Kll;
 ?column? 
----------
 t
(1 row)

eas_prod=# select null is not distinct from null;[1P[1P[1P[1P[1@1
 ?column? 
----------
 f
(1 row)

eas_prod=# \q
bash-3.2$ exit
exit

Script done on Thu 21 Jul 2011 05:01:33 PM PDT

Related content