dblink: could not send query: another command is already in progress

Hi all

I try to use dblink to create a asynchronous logging facility. I have
the following code

-- open the dblink if it does not yet exist
V_DBLINK_CONNECTION_NAME :=
GET_PROPERTY_VALUE_STRING(
I_PROPERTY_NAME => 'DBLINK_CONNECTION_NAME'
);
select dblink_get_connections() into V_DBLINK_CONNECTION_NAMES;
if (
V_DBLINK_CONNECTION_NAMES is null
or V_DBLINK_CONNECTION_NAME != any(V_DBLINK_CONNECTION_NAMES)
) then
V_DBLINK_CONNECT_STRING :=
GET_PROPERTY_VALUE_STRING(
I_PROPERTY_NAME => 'DBLINK_CONNECT_STRING'
);
-- better to use dblink_connect_u with password file?
perform dblink_connect(
V_DBLINK_CONNECTION_NAME,
V_DBLINK_CONNECT_STRING
);
end if;

-- send query asynchronously
-- Use literal (%L) as it returns the value null as the
unquoted
-- string NULL.
V_QUERY := format(
$s$select true $s$ || C_LB ||
$s$ from %I( $s$ || C_LB ||
$s$ I_FUNCTION => %L, $s$ || C_LB ||
$s$ I_MESSAGE => %L, $s$ || C_LB ||
$s$ I_LEVEL => %L, $s$ || C_LB ||
$s$ I_PRESENT_USER => %L, $s$ || C_LB ||
$s$ I_SESSION_USER => %L, $s$ || C_LB ||
$s$ I_TRANSACTION_TIMESTAMP => $s$ ||
$s$ %L::timestamp, $s$ || C_LB ||
$s$ I_TRANSACTION_ID => $s$ ||
$s$ %L::bigint, $s$ || C_LB ||
$s$ I_SERVER_PID => $s$ ||
$s$ %L::bigint, $s$ || C_LB ||
$s$ I_REMOTE_ADDRESS => $s$ ||
$s$ %L::inet, $s$ || C_LB ||
$s$ I_REMOTE_PORT => $s$ ||
$s$ %L::bigint $s$ || C_LB ||
$s$ ); $s$ || C_LB ||
$s$commit $s$,
'WRITE_MESSAGE_TO_TABLE',
C_CALLER_FUNCTION,
I_MESSAGE,
I_LEVEL,
C_PRESENT_USER,
C_SESSION_USER,
C_TRANSACTION_TIMESTAMP,
C_TRANSACTION_ID,
C_SERVER_PID,
C_REMOTE_ADDRESS,
C_REMOTE_PORT
);
-- send query when connection is ready
V_WAIT_FOR :=
GET_PROPERTY_VALUE_INTERVAL(
I_PROPERTY_NAME => 'BUSY_WAIT_INTERVAL'
); -- to avoid continuous re-querying, already queried here
-- surprisingly, dblink_is_busy does not return boolean,
but 0 for
-- false
while dblink_is_busy(V_DBLINK_CONNECTION_NAME) != 0 loop
perform pg_sleep_for(V_WAIT_FOR);
end loop;
perform dblink_send_query(
V_DBLINK_CONNECTION_NAME,
V_QUERY
);
raise notice 'Connection busy: %', dblink_is_busy(V_DBLINK_CONNECTION_NAME);
raise notice 'Last error: %',
dblink_error_message(V_DBLINK_CONNECTION_NAME);
raise notice 'Cancel query: %',
dblink_cancel_query(V_DBLINK_CONNECTION_NAME);
-- ??? commit needed?
raise notice 'Connection busy: %', dblink_is_busy(V_DBLINK_CONNECTION_NAME);
while dblink_is_busy(V_DBLINK_CONNECTION_NAME) != 0 loop
perform pg_sleep_for(V_WAIT_FOR);
raise notice 'Waited for commit for % seconds', V_WAIT_FOR;
raise notice 'Connection busy: %', dblink_is_busy(V_DBLINK_CONNECTION_NAME);
end loop;
perform dblink_send_query(
V_DBLINK_CONNECTION_NAME,
'commit'
);

I get the following output.
psql:testing/test.pg_sql:41: NOTICE: Connection busy: 1

psql:testing/test.pg_sql:41: NOTICE: Last error: OK

psql:testing/test.pg_sql:41: NOTICE: Cancel query: OK

psql:testing/test.pg_sql:41: NOTICE: Connection busy: 0

psql:testing/test.pg_sql:41: NOTICE: could not send query: another
command is already in progress

I did all the raise notice and dblink querying and cancelling to get
some information on what is going on but I am no wiser than before as
without that the connection was not busy either. But it was still
blocking I had the second call even though the commit did not seem to
work and I was trying to send it for good. Btw, there is no entry in the
logging table which is being done when the same function is called
without using dblink.

Maybe I am wrong but I tried the solution with dblink_connect
dblink_send_query instead of simply dblink believing that dblink
function would open and close a connection at every call. I wanted to
avoid this overhead.

Has anyone an idea?

--
SIP/iptel.org: thiemo.kellner
Öffentlicher PGP-Schlüssel:
http://pgp.mit.edu/pks/lookup?op=get&search=0xCA167FB0E717AFFC