On 12/01/2015 06:51 AM, Peter J. Holzer wrote:
A rather weird observation from the log files of our server (9.5 beta1):
2015-12-01 09:23:37 CET [26265]: [42-1] user=fragner,db=wds,pid=26265 WARNING: Use of uninitialized value $success in concatenation (.) or string at /usr/local/share/perl/5.20.2/WDS/Macrobond/Utils.pm line 36.
2015-12-01 09:23:37 CET [26265]: [43-1] user=fragner,db=wds,pid=26265 CONTEXT: PL/Perl function "mb_timeseriesdata_zmq"
[lots of other stuff from different connections]
2015-12-01 09:24:45 CET [26265]: [44-1] user=fragner,db=wds,pid=26265 ERROR: impossible result '' (payload=) at /usr/local/share/perl/5.20.2/WDS/Macrobond/Utils.pm line 36.
WDS::Macrobond::Utils::decode_result("") called at line 30
main::__ANON__("gen_wqehur") called at -e line 0
eval {...} called at -e line 0
Two messages from the same line of the same plperlu stored procedure, 68
seconds apart. So what is this line 36?
confess "impossible result '$success' (payload=$payload)";
What? The first message clearly comes from interpolating $success
(which is undef at that point) into the argument. The second from
confess itself. What could cause a plperlu procedure to freeze for 68
seconds between the call to confess and its output?
Is it possible that only the writing of the log entry is delayed?
Another weird thing: $success is undef because a ØMQ rpc call[1] timed
And the call is?
out (after 60 seconds, which is also a mystery, because ØMQ doesn't seem
to have a default timeout of 60 seconds, and I don't set one). But at
Network timeout?
09:24:45 (i.e. the time of the error message) the answer for that RPC
call arrived. So it kind of looks like confess waited for the message to
arrive (which makes no sense at all) or maybe that confess waited for
something which also blocked the sending of the request (because
according to the server logs, the RPC request only arrived there at
09:24:45 and was answered within 1 second), but that doesn't make any
So if the request timed out how did you get a reply, a second request?
sense either. (Just noticed that 60 + 68 == 128, which is also a round
number).
This looks a question for a ØMQ list.
Another thought, have you tried the code outside Postgres to see if works?
hp
[1] ØMQ is an IPC framework: See http://zeromq.org/ We use it to make
RPC calls from stored procedures to a server process.
--
Adrian Klaver
adrian.klaver@xxxxxxxxxxx
--
Sent via pgsql-general mailing list (pgsql-general@xxxxxxxxxxxxxx)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general
