Subject: Measuring the execution time of functions within functions...
From: Mario Splivalo <mario.splivalo@mobart.hr>
Reply-To: mario.splivalo@mobart.hr
To: pgsql-performance@postgresql.org
Content-Type: text/plain
Organization: Mob-Art
Date: Mon, 03 Apr 2006 11:42:19 +0200
Message-Id: <1144057339.20123.18.camel@localhost.localdomain>
Mime-Version: 1.0
Content-Transfer-Encoding: 7bit

I have asked this before, but haven't noticed any response, so if there
were any, I appologize for asking this again...

I have a function that is called by middle-tier (java trough JDBC), and
in postgres log I can see only the execution time of that function. I
have no idea how long are functions insde taking time to execute.

Since the function is written in plpgsql I tried to calculate the
durations by using now() function, but realized that within the
transaction now() always retunrs the same value.

The good thing is that those RAISE NOTICE calls from within my function
are logged as they're encountered, so, with carefully placed RAISE
NOTICE calls I could see how much time are the -inside- functions
taking.

For instance:

CREATE FUNCTION test_outer() RETURNS void
AS
$$BODY$$BEGIN
	RAISE NOTICE 'We start here'
	PERFORM SELECT someInternalFunction1();
	RAISE NOTICE 'InternalFunction1 is done now.';
	PERFORM SELECT someInternalFunction2();
	RAISE NOTICE 'InternalFunction2 is done now.';
	-- ... more code here
END$$BODY$$
LANGUAGE 'plpgsql'

Is there any other, maybe more convinient way to measure the 'inside'
function performance? I also have a problem if the outer function is
written in SQL, like this, for instance:

CREATE FUNCTION getSomeData(param1, param2, param3)
RETURN SETOF someType
AS
$$BODY$$SELECT
	*
FROM
	someTable
	JOIN someOtherFunction($1, $2, $3) ON someTable.col =
someOtherFunction.col
WHERE
	someCondition
$$BODY$$
LANGUAGE 'sql'.

Thank you in advance,

	Mario
-- 
Mario Splivalo
Mob-Art
mario.splivalo@mobart.hr

"I can do it quick, I can do it cheap, I can do it well. Pick any two."