Function Scan costs - Mailing list pgsql-novice

I'm calling functions via libpq. I've noticed that in the EXPLAIN analysis the time for the Function Scan is high relative to that of the actual query. In the example below (if I'm reading it correctly), the query seems to take just 0.022 ms whereas the time allocated to "Function Scan is 0.483ms. Is this to do with parsing original query and substituting params? Could somebody please explain? Thanks.
 
CONTEXT:  SQL statement "SELECT        n.node_type, r.rel_type, n.c_state, n.sort_key, n.d_state, n.node_id,
                              r.s_t_n, r.t_s_n, n.permissions, n.audit,
                              r.state, r.permissions, r.control,
                              r.prime_key, r.prime_key_len, r.sec_key, r.sec_key_len,
                              r.up_prime_key, r.up_prime_key_len, r.up_sec_key, r.up_sec_key_len
                FROM relationship r, node n
                WHERE r.rel_id = in_rel_id
                AND n.node_id = in_node_id
                AND n.d_state = 1"
        PL/pgSQL function "sp_select_by_node_rel" line 6 at SQL statement
LOG:  duration: 0.497 ms  plan:
        Query Text: select * from sp_select_by_node_rel($1,$2)
        Function Scan on public.sp_select_by_node_rel  (cost=0.25..0.26 rows=1 width=296) (actual time=0.482..0.483 rows=1 loo
ps=1)
          Output: tn_type, rel_type, tn_c_state, tn_sort, tn_d_state, tn_create_order, stn_guid, tsn_guid, tn_gen_perms, tn_au
dit, rel_state, sp_perms, rel_control, prime_key, prime_key_len, sec_key, sec_key_len, u_prime_key, u_prime_key_len, u_sec_key
, u_sec_key_len

          Function Call: sp_select_by_node_rel(82677::bigint, 71346::bigint)
          Buffers: shared hit=6
LOG:  duration: 0.030 ms  plan:
        Query Text: SELECT        n.node_type, r.rel_type, n.c_state, n.sort_key, n.d_state, n.node_id,
                              r.s_t_n, r.t_s_n, n.permissions, n.audit,
                              r.state, r.permissions, r.control,
                              r.prime_key, r.prime_key_len, r.sec_key, r.sec_key_len,
                              r.up_prime_key, r.up_prime_key_len, r.up_sec_key, r.up_sec_key_len
                FROM relationship r, node n
                WHERE r.rel_id = in_rel_id
                AND n.node_id = in_node_id
                AND n.d_state = 1
        Nested Loop  (cost=0.00..12.55 rows=1 width=130) (actual time=0.022..0.022 rows=1 loops=1)
          Output: n.node_type, r.rel_type, n.c_state, n.sort_key, n.d_state, n.node_id, r.s_t_n, r.t_s_n, n.permissions, n.aud
it, r.state, r.permissions, r.control, r.prime_key, r.prime_key_len, r.sec_key, r.sec_key_len, r.up_prime_key, r.up_prime_key_
len, r.up_sec_key, r.up_sec_key_len
          Buffers: shared hit=6
          ->  Index Scan using pk_relationship on public.relationship r  (cost=0.00..6.27 rows=1 width=81) (actual time=0.011.
.0.011 rows=1 loops=1)
                Output: r.rel_id, r.rel_type, r.s_t_n, r.t_s_n, r.state, r.control, r.sort_key, r.prime_key, r.prime_key_len,
r.sec_key, r.sec_key_len, r.up_sort_key, r.up_prime_key, r.up_prime_key_len, r.up_sec_key, r.up_sec_key_len, r.permissions, r.
created, r.t_s_n_type
                Index Cond: (r.rel_id = $1)
                Buffers: shared hit=3
          ->  Index Scan using pk_node on public.node n  (cost=0.00..6.27 rows=1 width=49) (actual time=0.008..0.008 rows=1 lo
ops=1)
                Output: n.node_id, n.node_type, n.c_state, n.d_state, n.sort_key, n.permissions, n.audit, n.pkg_id, n.created
                Index Cond: (n.node_id = $2)
                Filter: (n.d_state = 1)
                Buffers: shared hit=3