BUG #4635: postgres.exe crash when RAISE NOTICE during debugging of PL/pgSQL function in PgAdminIII

From: "Robert Walker" <r(dot)walker(at)mtcworldwide(dot)com>
To: pgsql-bugs(at)postgresql(dot)org
Subject: BUG #4635: postgres.exe crash when RAISE NOTICE during debugging of PL/pgSQL function in PgAdminIII
Date: 2009-02-02 18:24:28
Message-ID: 200902021824.n12IOS68081800@wwwmaster.postgresql.org
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs


The following bug has been logged online:

Bug reference: 4635
Logged by: Robert Walker
Email address: r(dot)walker(at)mtcworldwide(dot)com
PostgreSQL version: 8.3.5
Operating system: WinXP SP2 32-bit
Description: postgres.exe crash when RAISE NOTICE during debugging of
PL/pgSQL function in PgAdminIII
Details:

Hello, I seem to have stumbled upon a bug that is consistently reproducible
on my machine. I'm running PostgreSQL 8.3.5 on WinXP SP2 32bit. I apologize
if this might be a duplicate bug report, as I couldn't find anything in the
TODO that seemed to match this. This is my first Postgres bug report. I also
tried posted this to the bug email list, until I noticed that it mentioned I
have to be a subscriber in order to use that list, so I have reposted the
bug here.

I have a function that basically loops through a query and uses the results
from that query to do an individual insert into another table, and if there
is a unique violation, it simply raises a notice and continues on. When
trying to debug the function within PgAdminIII 1.8.4, when stepping through
to the point of the RAISE NOTICE statement, it displays the following and
then Windows informs me that postgres.exe has crashed:

NOTICE: Unique constraint violation for work shift history.
WARNING: terminating connection because of crash of another server process
DETAIL: The postmaster has commanded this server process to roll back the
current transaction and exit, because another server process exited
abnormally and possibly corrupted shared memory.
HINT: In a moment you should be able to reconnect to the database and
repeat your command.

This is what shows in the logs in the CSV format. The pertinent line seems
to be, "server process (PID 3824) was terminated by exception 0xC0000005".

2009-02-02 11:24:27.906 CST 4880 49872b77.1310 2 2009-02-02 11:20:55 CST
0 LOG 0 server process (PID 3824) was terminated by exception 0xC0000005
See C include file "ntstatus.h" for a description of the hexadecimal value.

2009-02-02 11:24:27.906 CST 4880 49872b77.1310 3 2009-02-02 11:20:55 CST
0 LOG 0 terminating any other active server processes
2009-02-02 11:24:27.906 CST postgres ed3 2104 127.0.0.1:1911 49872bac.838 2
idle 2009-02-02 11:21:48 CST Feb-00 0 WARNING 57P02 terminating connection
because of crash of another server process The postmaster has commanded this
server process to roll back the current transaction and exit, because
another server process exited abnormally and possibly corrupted shared
memory. In a moment you should be able to reconnect to the database and
repeat your command.
2009-02-02 11:24:27.906 CST postgres postgres 6100 127.0.0.1:1910
49872baa.17d4 2 idle 2009-02-02 11:21:46 CST Jan-00 0 WARNING 57P02
terminating connection because of crash of another server process The
postmaster has commanded this server process to roll back the current
transaction and exit, because another server process exited abnormally and
possibly corrupted shared memory. In a moment you should be able to
reconnect to the database and repeat your command.
2009-02-02 11:24:27.937 CST 4880 49872b77.1310 4 2009-02-02 11:20:55 CST
0 LOG 0 all server processes terminated; reinitializing
2009-02-02 11:24:28.936 CST 4880 49872b77.1310 5 2009-02-02 11:20:55 CST
0 FATAL XX000 pre-existing shared memory block is still in use Check if
there are any old server processes still running, and terminate them.


Here are the table definitions and function definitions (please excuse their
crudeness/bugginess, this was all in the middle of the process of learning
Postgres and making some proof-of-concepts for a database, hence the use of
the debugger). There would of course need to be a user login created called
'ebatt' in addition to the schema:

CREATE SCHEMA ebatt
AUTHORIZATION ebatt;

CREATE TABLE ebatt.work_shifts
(
site_id uuid NOT NULL,
work_shift_label text NOT NULL,
start_day_id smallint NOT NULL,
start_time time without time zone NOT NULL,
end_day_id smallint NOT NULL,
end_time time without time zone NOT NULL,
description text,
CONSTRAINT work_shifts_pkey PRIMARY KEY (start_day_id, start_time,
end_day_id, end_time, site_id),
CONSTRAINT work_shifts_work_shift_label_key UNIQUE (work_shift_label,
site_id)
)
WITH (OIDS=FALSE);
ALTER TABLE ebatt.work_shifts OWNER TO ebatt;


CREATE TABLE ebatt.work_shift_history
(
site_id uuid NOT NULL,
start_day_id smallint NOT NULL,
start_time time without time zone NOT NULL,
end_day_id smallint NOT NULL,
end_time time without time zone NOT NULL,
notes text,
start_timestamp timestamp with time zone NOT NULL,
end_timestamp timestamp with time zone NOT NULL,
CONSTRAINT work_shift_history_pkey PRIMARY KEY (start_timestamp,
end_timestamp, site_id),
CONSTRAINT work_shift_history_start_day_id_fkey FOREIGN KEY (start_day_id,
start_time, end_day_id, end_time, site_id)
REFERENCES ebatt.work_shifts (start_day_id, start_time, end_day_id,
end_time, site_id) MATCH SIMPLE
ON UPDATE CASCADE ON DELETE NO ACTION
)
WITH (OIDS=FALSE);
ALTER TABLE ebatt.work_shift_history OWNER TO ebatt;

CREATE OR REPLACE FUNCTION ebatt.populate_work_shift_history(from_timestamp
timestamp with time zone)
RETURNS integer AS
$BODY$
DECLARE
-- This will be the record variable we will use for looping:
ws RECORD;

start_ts TIMESTAMP := NULL;
end_ts TIMESTAMP := NULL;

rows_affected INTEGER := 0;
total_rows_affected BIGINT := 0;

-- Use the intuitive enumeration for days of the week instead
-- of the ISO 8601 version:
from_timestamp_dow DOUBLE PRECISION := EXTRACT(DOW FROM
from_timestamp);

-- These use the ISO 8601 logic (instead of the intuitive
behavior):
current_week DOUBLE PRECISION := EXTRACT('WEEK' FROM
CURRENT_TIMESTAMP);
current_year DOUBLE PRECISION := EXTRACT('YEAR' FROM
CURRENT_TIMESTAMP);
BEGIN

-- The strategy here could be that we would use a loop of INSERT
-- statements instead of a single INSERT statement so that if
-- an attempt to add an entry to the work shift history violates
-- a unique constraint such as a primary key, we can just allow
-- that one transaction to fail but continue on to populate the
-- rest of the entries for the history. That way we are
-- "filling in the gaps" if there is missing history rather than
-- just populating only one full week at a time. Of course, that
-- means we have to do error handling.
FOR ws IN
-- Get the abstract work shift definitions:
SELECT
site_id,
start_day_id,
start_time,
end_day_id,
end_time
FROM ebatt.work_shifts
ORDER BY
start_day_id ASC,
start_time ASC,
end_day_id ASC,
end_time ASC,
site_id ASC
LOOP
-- Using the abstract work shift definitions, populate the
-- work shift history with real timestamps:
BEGIN
-- Calculate the start/end timestamps:
IF from_timestamp_dow = ws.start_day_id::DOUBLE PRECISION
THEN
-- If we just used the next_day function, it would give
us
-- the next date for that day of the week. So, in order
to
-- get the date for the same day, we subtract 1 day and
-- then ask for the next day:
start_ts := ebatt.next_day((from_timestamp - '1
DAY'::INTERVAL)::DATE, ws.start_day_id::DOUBLE PRECISION)::TIMESTAMP +
ws.start_time;
ELSE
-- Because the from_timestamp isn't the same day as the
-- for the start_day_id, we can just go ahead and use
-- the next_day function normally to get the date:
start_ts := ebatt.next_day(from_timestamp::DATE,
ws.start_day_id::DOUBLE PRECISION)::TIMESTAMP + ws.start_time;
END IF;

IF from_timestamp_dow = ws.end_day_id::DOUBLE PRECISION
THEN
end_ts := ebatt.next_day((from_timestamp - '1
DAY'::INTERVAL)::DATE, ws.end_day_id::DOUBLE PRECISION)::TIMESTAMP +
ws.end_time;
ELSE
end_ts := ebatt.next_day(from_timestamp::DATE,
ws.end_day_id::DOUBLE PRECISION)::TIMESTAMP + ws.end_time;
END IF;

-- Create the row for the work shift history:
INSERT INTO ebatt.work_shift_history (
site_id,
start_day_id,
start_time,
end_day_id,
end_time,
start_timestamp,
end_timestamp
)
VALUES (
ws.site_id,
ws.start_day_id,
ws.start_time,
ws.end_day_id,
ws.end_time,
start_ts,
end_ts
);
EXCEPTION
-- If we create a duplicate, let it fail but log it and
just
-- continue on with the rest:
-- (Does PostgreSQL automatically roll-back? If so, this
might
-- not work because we are trying to let it fail
semi-silently...)
WHEN unique_violation THEN
RAISE NOTICE 'Unique constraint violation for work shift
history.';
END;

-- The built-in variables FOUND and ROW_COUNT will help us
determine
-- how many rows were affected by the INSERT:
-- (Note that ROW_COUNT only returns the value from a single
-- INSERT. If we want to tally more than one insert, the
strategy
-- would be to count the ROW_COUNT for a loop of inserts and
add
-- them up to a final total.)
GET DIAGNOSTICS rows_affected := ROW_COUNT;
IF FOUND THEN
total_rows_affected := total_rows_affected + rows_affected;
END IF;

END LOOP;

RETURN total_rows_affected;
END;
$BODY$
LANGUAGE 'plpgsql' VOLATILE STRICT
COST 100;
ALTER FUNCTION ebatt.populate_work_shift_history(timestamp with time zone)
OWNER TO ebatt;

CREATE OR REPLACE FUNCTION ebatt.next_day(given_date date, dow_id double
precision)
RETURNS date AS
$BODY$
DECLARE
-- As we cycle through dates, one of the values must end up being
-- the date we were looking for:
test_date DATE := NULL;
BEGIN

---------------------------------------------------------------------------
-- PURPOSE:

---------------------------------------------------------------------------
-- This function is designed to function similarly to Oracle's
next_day()
-- function. Given a date and the numeric ID for a day of the week,
return
-- the next date that falls on that day of the week.

---------------------------------------------------------------------------

-- NOTE: For the dow_id, it ranges from 0 to 6 where 0 is Sunday and
6 is
-- Saturday.

-- For any given weekday, within 7 days you should hit that same
day
-- of the week again. Loop through the dates of each of those days
-- that follow the given_date. When we hit the same day of the
week,
-- return the date for that day:
FOR i IN 1..7 LOOP
test_date := (given_date::TIMESTAMP + (i::TEXT || '
day')::INTERVAL)::DATE;

IF EXTRACT(DOW FROM test_date) = dow_id THEN
RETURN test_date;
END IF;
END LOOP;

-- If we get here, we couldn't figure out what the date should be:
RETURN NULL;
END;
$BODY$
LANGUAGE 'plpgsql' IMMUTABLE STRICT
COST 100;
ALTER FUNCTION ebatt.next_day(date, double precision) OWNER TO ebatt;


This was the data in the work_shifts table:

"c0549e0a-f144-11dd-affa-837a3056ea58";"shift 1";1;"07:00:00";1;"17:00:00"
"c0549e0a-f144-11dd-affa-837a3056ea58";"shift 2";2;"07:00:00";3;"07:00:00"
"c0549e0a-f144-11dd-affa-837a3056ea58";"shift 3";5;"12:00:00";6;"07:00:00"
"c0549e0a-f144-11dd-affa-837a3056ea58";"shift 4";6;"12:00:00";6;"15:00:00"


This was the data in the work_shift_history table:

"c0549e0a-f144-11dd-affa-837a3056ea58";6;"12:00:00";6;"15:00:00";"";"2009-01
-31 12:00:00-06";"2009-01-31 15:00:00-06"
"c0549e0a-f144-11dd-affa-837a3056ea58";1;"07:00:00";1;"17:00:00";"";"2009-02
-02 07:00:00-06";"2009-02-02 17:00:00-06"
"c0549e0a-f144-11dd-affa-837a3056ea58";2;"07:00:00";3;"07:00:00";"";"2009-02
-03 07:00:00-06";"2009-02-04 07:00:00-06"
"c0549e0a-f144-11dd-affa-837a3056ea58";5;"12:00:00";6;"07:00:00";"";"2009-02
-06 12:00:00-06";"2009-01-31 07:00:00-06"
"c0549e0a-f144-11dd-affa-837a3056ea58";5;"12:00:00";6;"07:00:00";"";"2009-02
-06 12:00:00-06";"2009-02-07 07:00:00-06"
"c0549e0a-f144-11dd-affa-837a3056ea58";6;"12:00:00";6;"15:00:00";"";"2009-02
-07 12:00:00-06";"2009-02-07 15:00:00-06"

When trying to run the populate_work_shift_history function, the idea was
that it would take information from the work_shifts table and use that to
populate the work_shift_history table with real timestamps. If there were
duplicate rows for any reason, the loop is intended to simply log the raised
notice that there was a unique violation and continue on through the loop to
add any remaining rows. When running the debugger, I used '2009/1/31 00:00'
as the initial value, and once it stepped through to the point of the RAISE
statement (triggered by the unique constraint violation), it would show the
message in PgAdminIII and then postgres.exe would crash every time I went
through these steps. I would then have to restart the server each time.

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Tom Lane 2009-02-02 19:30:46 Re: BUG #4629: PL/pgSQL issue
Previous Message Michael Meskes 2009-02-02 16:17:22 Re: BUG #4625: ECPG: Memory allocation for binary data is wrong