Thread

8.2beta1 (w32): server process crash (tsvector)

Thomas H. <me@alternize.com> — 2006-10-17T04:14:32Z

the following query will crash the server process:

INSERT INTO news.news
SELECT * FROM news.news2;

news.news is empty;
news.news2 contains 600 records. both have the same structure (see end of mail)

when the tsvector column & trigger is dumped from the two tables everything works as expected.

regards,
thomas


full log:

2006-10-17 05:56:18 LOG:  database system was shut down at 2006-10-17 05:56:17 W. Europe Daylight Time
2006-10-17 05:56:18 LOG:  Windows fopen("recovery.conf","r") failed: code 2, errno 2
2006-10-17 05:56:18 LOG:  Windows fopen("pg_xlog/00000001.history","r") failed: code 2, errno 2
2006-10-17 05:56:18 LOG:  Windows fopen("backup_label","r") failed: code 2, errno 2
2006-10-17 05:56:18 LOG:  checkpoint record is at 0/A0E16030
2006-10-17 05:56:18 LOG:  redo record is at 0/A0E16030; undo record is at 0/0; shutdown TRUE
2006-10-17 05:56:18 LOG:  next transaction ID: 0/6899; next OID: 5998391
2006-10-17 05:56:18 LOG:  next MultiXactId: 1; next MultiXactOffset: 0
2006-10-17 05:56:18 LOG:  database system is ready
2006-10-17 05:56:18 LOG:  transaction ID wrap limit is 2147484172, limited by database "postgres"
2006-10-17 06:04:07 LOG:  server process (PID 1728) exited with exit code -1073741819
2006-10-17 06:04:07 LOG:  terminating any other active server processes
2006-10-17 06:04:07 WARNING:  terminating connection because of crash of another server process
2006-10-17 06:04:07 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.
2006-10-17 06:04:07 HINT:  In a moment you should be able to reconnect to the database and repeat your command.
2006-10-17 06:04:07 LOG:  all server processes terminated; reinitializing
2006-10-17 06:04:08 LOG:  database system was interrupted at 2006-10-17 06:04:01 W. Europe Daylight Time
2006-10-17 06:04:08 LOG:  Windows fopen("recovery.conf","r") failed: code 2, errno 2
2006-10-17 06:04:08 LOG:  Windows fopen("pg_xlog/00000001.history","r") failed: code 2, errno 2
2006-10-17 06:04:08 LOG:  Windows fopen("backup_label","r") failed: code 2, errno 2
2006-10-17 06:04:08 LOG:  checkpoint record is at 0/A19FC5E8
2006-10-17 06:04:08 LOG:  redo record is at 0/A19FC5E8; undo record is at 0/0; shutdown FALSE
2006-10-17 06:04:08 LOG:  next transaction ID: 0/7089; next OID: 6014775
2006-10-17 06:04:08 LOG:  next MultiXactId: 1; next MultiXactOffset: 0
2006-10-17 06:04:08 LOG:  database system was not properly shut down; automatic recovery in progress
2006-10-17 06:04:08 LOG:  redo starts at 0/A19FC638
2006-10-17 06:04:08 LOG:  unexpected pageaddr 0/9B2CC000 in log file 0, segment 162, offset 2932736
2006-10-17 06:04:08 LOG:  redo done at 0/A22CBF88
2006-10-17 06:04:08 LOG:  database system is ready
2006-10-17 06:04:08 LOG:  Windows fopen("global/pg_fsm.cache","rb") failed: code 2, errno 2
2006-10-17 06:04:08 LOG:  transaction ID wrap limit is 2147484172, limited by database "postgres"
2006-10-17 06:04:08 LOG:  Windows fopen("global/pgstat.stat","rb") failed: code 2, errno 2



-- Table: news.news

-- DROP TABLE news.news;

CREATE TABLE news.news
(
  id integer NOT NULL DEFAULT nextval('news_id_seq'::regclass),
  "show" boolean NOT NULL DEFAULT false,
  date_news timestamp without time zone(-4) NOT NULL DEFAULT now(),
  date_added timestamp without time zone(-4) NOT NULL DEFAULT now(),
  headline character varying(100) NOT NULL DEFAULT ''::character varying,
  editor character varying(50) NOT NULL DEFAULT ''::character varying,
  text_raw text NOT NULL DEFAULT ''::text,
  text_formated text NOT NULL DEFAULT ''::text,
  text_summary character varying(400) NOT NULL DEFAULT ''::character varying,
  image_large character varying(100) NOT NULL DEFAULT ''::character varying,
  image_small character varying(100) NOT NULL DEFAULT ''::character varying,
  image_height integer NOT NULL DEFAULT 0,
  image_caption character varying(100) NOT NULL DEFAULT ''::character varying,
  link1_url character varying(255) NOT NULL DEFAULT ''::character varying,
  link1_title character varying(70) NOT NULL DEFAULT ''::character varying,
  link2_url character varying(255) NOT NULL DEFAULT ''::character varying,
  link2_title character varying(70) NOT NULL DEFAULT ''::character varying,
  "comment" character varying(400) NOT NULL DEFAULT ''::character varying, -- interner kommentar
  forum_count integer NOT NULL DEFAULT 0,
  forum_id integer NOT NULL DEFAULT 0,
  source_title character varying(70) NOT NULL DEFAULT ''::character varying,
  source_url character varying(255) NOT NULL DEFAULT ''::character varying,
  idxfti tsvector,
  text_content text DEFAULT ''::text,
  text_lead character varying(120) NOT NULL DEFAULT ''::character varying,
  CONSTRAINT news_pkey PRIMARY KEY (id)
) 
WITHOUT OIDS;
ALTER TABLE news.news OWNER TO db_outnow;
COMMENT ON COLUMN news.news."comment" IS 'interner kommentar';


-- Index: news.news_date_idx

-- DROP INDEX news.news_date_idx;

CREATE INDEX news_date_idx
  ON news.news
  USING btree
  (date_news);

-- Index: news.news_id_idx

-- DROP INDEX news.news_id_idx;

CREATE INDEX news_id_idx
  ON news.news
  USING btree
  (id);



-- Trigger: news_ts_update on news.news

-- DROP TRIGGER news_ts_update ON news.news;

CREATE TRIGGER news_ts_update
  BEFORE INSERT OR UPDATE
  ON news.news
  FOR EACH ROW
  EXECUTE PROCEDURE tsearch2('idxfti', 'headline', 'text_content');

Re: 8.2beta1 (w32): server process crash (tsvector)

Tom Lane <tgl@sss.pgh.pa.us> — 2006-10-17T14:33:13Z

<me@alternize.com> writes:
> the following query will crash the server process:
> INSERT INTO news.news
> SELECT * FROM news.news2;

This is undoubtedly data-dependent.  Can you supply some sample data
that makes it happen?

			regards, tom lane

Re: 8.2beta1 (w32): server process crash (tsvector)

Thomas H. <me@alternize.com> — 2006-10-17T20:19:03Z

>> the following query will crash the server process:
>> INSERT INTO news.news
>> SELECT * FROM news.news2;
>
> This is undoubtedly data-dependent.  Can you supply some sample data
> that makes it happen?

it's not only happening with INSERTS, but also updates. as thats easier to
test, here's how i can reproduce the error:

1. create new database (encoding: UTF8) with tsearch2 on 8.2b1 win32 (system
locale: de_CH.1252)
2. insert the data from the zip file 
[http://alternize.com/pgsql/tsearch2test.zip] (be sure to also update 
pg_ts_cf /
pg_ts_cfgmap as we have WIN1252 locale)
3. execute UPDATE test SET idxFTI = to_tsvector('default', "sometext"); or
similar queries
4. hopefully see the process crashing as i do ;-)


2006-10-17 17:23:44 LOG:  server process (PID 4584) exited with exit
code -1073741819
2006-10-17 17:23:44 LOG:  terminating any other active server processes
2006-10-17 17:23:44 WARNING:  terminating connection because of crash of
another server process
2006-10-17 17:23:44 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.
{snipp}
2006-10-17 17:23:44 LOG:  all server processes terminated; reinitializing
2006-10-17 17:23:44 LOG:  database system was interrupted at 2006-10-17
17:23:41 W. Europe Daylight Time
2006-10-17 17:23:44 LOG:  Windows fopen("recovery.conf","r") failed: code 2,
errno 2
2006-10-17 17:23:44 LOG:  Windows fopen("pg_xlog/00000001.history","r")
failed: code 2, errno 2
2006-10-17 17:23:44 LOG:  Windows fopen("backup_label","r") failed: code 2,
errno 2
2006-10-17 17:23:44 LOG:  checkpoint record is at 0/E2ECA728
2006-10-17 17:23:44 LOG:  redo record is at 0/E2ECA728; undo record is at
0/0; shutdown FALSE
2006-10-17 17:23:44 LOG:  next transaction ID: 0/514299; next OID: 6276957
2006-10-17 17:23:44 LOG:  next MultiXactId: 1; next MultiXactOffset: 0
2006-10-17 17:23:44 LOG:  database system was not properly shut down;
automatic recovery in progress
2006-10-17 17:23:44 LOG:  redo starts at 0/E2ECA778
2006-10-17 17:23:44 LOG:  unexpected pageaddr 0/DB0CC000 in log file 0,
segment 227, offset 835584
2006-10-17 17:23:44 LOG:  redo done at 0/E30CBE78
2006-10-17 17:23:45 LOG:  database system is ready
2006-10-17 17:23:45 LOG:  Windows fopen("global/pg_fsm.cache","rb") failed:
code 2, errno 2
2006-10-17 17:23:45 LOG:  transaction ID wrap limit is 2147484172, limited
by database "postgres"
2006-10-17 17:23:45 LOG:  Windows fopen("global/pgstat.stat","rb") failed:
code 2, errno 2


i've also tried to update each record on its own in a for-loop. here the
crash happens as well, sometimes after 10 updates, sometimes after 100
updates, sometimes even after 1 update. but eventually every record can be
updated. so i do not think its entierly content-related...

for what its worth, here's the output of pg_controldata:

pg_control version number:            822
Catalog version number:               200609181
Database system identifier:           4986650172201464825
Database cluster state:               in production
pg_control last modified:             17.10.2006 17:44:29
Current log file ID:                  0
Next log file segment:                230
Latest checkpoint location:           0/E4E0F978
Prior checkpoint location:            0/E46BF420
Latest checkpoint's REDO location:    0/E4E03098
Latest checkpoint's UNDO location:    0/0
Latest checkpoint's TimeLineID:       1
Latest checkpoint's NextXID:          0/531333
Latest checkpoint's NextOID:          6285149
Latest checkpoint's NextMultiXactId:  1
Latest checkpoint's NextMultiOffset:  0
Time of latest checkpoint:            17.10.2006 17:43:45
Minimum recovery ending location:     0/0
Maximum data alignment:               8
Database block size:                  8192
Blocks per segment of large relation: 131072
WAL block size:                       8192
Bytes per WAL segment:                16777216
Maximum length of identifiers:        64
Maximum columns in an index:          32
Date/time type storage:               floating-point numbers
Maximum length of locale name:        128
LC_COLLATE:                           German_Switzerland.1252
LC_CTYPE:                             German_Switzerland.1252

let me know if more information / data is needed.

on a sidenote: are those fopen() errors debug-code-leftovers or something
one should worry about? i can't find those files on the file system.

- thomas

Re: 8.2beta1 (w32): server process crash (tsvector)

Magnus Hagander <mha@sollentuna.net> — 2006-10-18T12:06:07Z

[offline ATM, can't look at the main issue, just wanted to get a comment
in about fopen(). Unless beaten to it, I'll try to look at the other
part later.]


> on a sidenote: are those fopen() errors debug-code-leftovers 
> or something one should worry about? i can't find those files 
> on the file system.

No. It's debugging output for a problem we had earlier, and will be
removed before release.

//Magnus

Re: 8.2beta1 (w32): server process crash (tsvector)

Thomas H. <me@alternize.com> — 2006-10-19T03:31:53Z

> No. It's debugging output for a problem we had earlier, and will be
> removed before release.

thanks for clarifying. wasn't sure whether the comment in the release notes 
really was applying to these "file not found" error messages.

> Unless beaten to it, I'll try to look at the other part later

in case more information / data is needed please let me know.
if helpfull (i.e. bug not reproducable with my test data in the previous 
mail), full pgsql access could be set up as well.

thanks in advance,
thomas

Re: 8.2beta1 (w32): server process crash (tsvector)

Thomas H. <me@alternize.com> — 2006-10-25T18:22:00Z

just a small update: this problem is also present in beta 2.
not a big problem for the moment, as we currently have disabled fulltext 
search capabilities on the website.

regards,
thomas

----- Original Message ----- 
From: <me@alternize.com>
To: "Tom Lane" <tgl@sss.pgh.pa.us>
Cc: <pgsql-bugs@postgresql.org>
Sent: Tuesday, October 17, 2006 10:19 PM
Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)


>>> the following query will crash the server process:
>>> INSERT INTO news.news
>>> SELECT * FROM news.news2;
>>
>> This is undoubtedly data-dependent.  Can you supply some sample data
>> that makes it happen?
>
> it's not only happening with INSERTS, but also updates. as thats easier to
> test, here's how i can reproduce the error:
>
> 1. create new database (encoding: UTF8) with tsearch2 on 8.2b1 win32 
> (system
> locale: de_CH.1252)
> 2. insert the data from the zip file 
> [http://alternize.com/pgsql/tsearch2test.zip] (be sure to also update 
> pg_ts_cf /
> pg_ts_cfgmap as we have WIN1252 locale)
> 3. execute UPDATE test SET idxFTI = to_tsvector('default', "sometext"); or
> similar queries
> 4. hopefully see the process crashing as i do ;-)
>
>
> 2006-10-17 17:23:44 LOG:  server process (PID 4584) exited with exit
> code -1073741819
> 2006-10-17 17:23:44 LOG:  terminating any other active server processes
> 2006-10-17 17:23:44 WARNING:  terminating connection because of crash of
> another server process
> 2006-10-17 17:23:44 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.
> {snipp}
> 2006-10-17 17:23:44 LOG:  all server processes terminated; reinitializing
> 2006-10-17 17:23:44 LOG:  database system was interrupted at 2006-10-17
> 17:23:41 W. Europe Daylight Time
> 2006-10-17 17:23:44 LOG:  Windows fopen("recovery.conf","r") failed: code 
> 2,
> errno 2
> 2006-10-17 17:23:44 LOG:  Windows fopen("pg_xlog/00000001.history","r")
> failed: code 2, errno 2
> 2006-10-17 17:23:44 LOG:  Windows fopen("backup_label","r") failed: code 
> 2,
> errno 2
> 2006-10-17 17:23:44 LOG:  checkpoint record is at 0/E2ECA728
> 2006-10-17 17:23:44 LOG:  redo record is at 0/E2ECA728; undo record is at
> 0/0; shutdown FALSE
> 2006-10-17 17:23:44 LOG:  next transaction ID: 0/514299; next OID: 6276957
> 2006-10-17 17:23:44 LOG:  next MultiXactId: 1; next MultiXactOffset: 0
> 2006-10-17 17:23:44 LOG:  database system was not properly shut down;
> automatic recovery in progress
> 2006-10-17 17:23:44 LOG:  redo starts at 0/E2ECA778
> 2006-10-17 17:23:44 LOG:  unexpected pageaddr 0/DB0CC000 in log file 0,
> segment 227, offset 835584
> 2006-10-17 17:23:44 LOG:  redo done at 0/E30CBE78
> 2006-10-17 17:23:45 LOG:  database system is ready
> 2006-10-17 17:23:45 LOG:  Windows fopen("global/pg_fsm.cache","rb") 
> failed:
> code 2, errno 2
> 2006-10-17 17:23:45 LOG:  transaction ID wrap limit is 2147484172, limited
> by database "postgres"
> 2006-10-17 17:23:45 LOG:  Windows fopen("global/pgstat.stat","rb") failed:
> code 2, errno 2
>
>
> i've also tried to update each record on its own in a for-loop. here the
> crash happens as well, sometimes after 10 updates, sometimes after 100
> updates, sometimes even after 1 update. but eventually every record can be
> updated. so i do not think its entierly content-related...
>
> for what its worth, here's the output of pg_controldata:
>
> pg_control version number:            822
> Catalog version number:               200609181
> Database system identifier:           4986650172201464825
> Database cluster state:               in production
> pg_control last modified:             17.10.2006 17:44:29
> Current log file ID:                  0
> Next log file segment:                230
> Latest checkpoint location:           0/E4E0F978
> Prior checkpoint location:            0/E46BF420
> Latest checkpoint's REDO location:    0/E4E03098
> Latest checkpoint's UNDO location:    0/0
> Latest checkpoint's TimeLineID:       1
> Latest checkpoint's NextXID:          0/531333
> Latest checkpoint's NextOID:          6285149
> Latest checkpoint's NextMultiXactId:  1
> Latest checkpoint's NextMultiOffset:  0
> Time of latest checkpoint:            17.10.2006 17:43:45
> Minimum recovery ending location:     0/0
> Maximum data alignment:               8
> Database block size:                  8192
> Blocks per segment of large relation: 131072
> WAL block size:                       8192
> Bytes per WAL segment:                16777216
> Maximum length of identifiers:        64
> Maximum columns in an index:          32
> Date/time type storage:               floating-point numbers
> Maximum length of locale name:        128
> LC_COLLATE:                           German_Switzerland.1252
> LC_CTYPE:                             German_Switzerland.1252
>
> let me know if more information / data is needed.
>
> on a sidenote: are those fopen() errors debug-code-leftovers or something
> one should worry about? i can't find those files on the file system.
>
> - thomas
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 4: Have you searched our list archives?
>
>               http://archives.postgresql.org
>

Re: 8.2beta1 (w32): server process crash (tsvector)

Thomas H. <me@alternize.com> — 2006-11-12T14:06:05Z

this bug (please see below) is unfortunately still present in beta3 (win32 
build). test case still crashes the child process and lets postmaster kill & 
reload everything.

it is not GiST-related, i've just validated the same problem using GIN.

this breaks tsearch2 functionality on our win32 system as no 
tsvector-indexing of new/existing rows is possible (crash after ~10 
processed rows). searching already indexed rows works fine.

best regards,
thomas

----- Original Message ----- 
From: <me@alternize.com>
To: "Tom Lane" <tgl@sss.pgh.pa.us>
Cc: <pgsql-bugs@postgresql.org>
Sent: Tuesday, October 17, 2006 9:19 PM
Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)


>>> the following query will crash the server process:
>>> INSERT INTO news.news
>>> SELECT * FROM news.news2;
>>
>> This is undoubtedly data-dependent.  Can you supply some sample data
>> that makes it happen?
>
> it's not only happening with INSERTS, but also updates. as thats easier to
> test, here's how i can reproduce the error:
>
> 1. create new database (encoding: UTF8) with tsearch2 on 8.2b1 win32 
> (system
> locale: de_CH.1252)
> 2. insert the data from the zip file 
> [http://alternize.com/pgsql/tsearch2test.zip] (be sure to also update 
> pg_ts_cf /
> pg_ts_cfgmap as we have WIN1252 locale)
> 3. execute UPDATE test SET idxFTI = to_tsvector('default', "sometext"); or
> similar queries
> 4. hopefully see the process crashing as i do ;-)
>
>
> 2006-10-17 17:23:44 LOG:  server process (PID 4584) exited with exit
> code -1073741819
> 2006-10-17 17:23:44 LOG:  terminating any other active server processes
> 2006-10-17 17:23:44 WARNING:  terminating connection because of crash of
> another server process
> 2006-10-17 17:23:44 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.
> {snipp}
> 2006-10-17 17:23:44 LOG:  all server processes terminated; reinitializing
> 2006-10-17 17:23:44 LOG:  database system was interrupted at 2006-10-17
> 17:23:41 W. Europe Daylight Time
> 2006-10-17 17:23:44 LOG:  Windows fopen("recovery.conf","r") failed: code 
> 2,
> errno 2
> 2006-10-17 17:23:44 LOG:  Windows fopen("pg_xlog/00000001.history","r")
> failed: code 2, errno 2
> 2006-10-17 17:23:44 LOG:  Windows fopen("backup_label","r") failed: code 
> 2,
> errno 2
> 2006-10-17 17:23:44 LOG:  checkpoint record is at 0/E2ECA728
> 2006-10-17 17:23:44 LOG:  redo record is at 0/E2ECA728; undo record is at
> 0/0; shutdown FALSE
> 2006-10-17 17:23:44 LOG:  next transaction ID: 0/514299; next OID: 6276957
> 2006-10-17 17:23:44 LOG:  next MultiXactId: 1; next MultiXactOffset: 0
> 2006-10-17 17:23:44 LOG:  database system was not properly shut down;
> automatic recovery in progress
> 2006-10-17 17:23:44 LOG:  redo starts at 0/E2ECA778
> 2006-10-17 17:23:44 LOG:  unexpected pageaddr 0/DB0CC000 in log file 0,
> segment 227, offset 835584
> 2006-10-17 17:23:44 LOG:  redo done at 0/E30CBE78
> 2006-10-17 17:23:45 LOG:  database system is ready
> 2006-10-17 17:23:45 LOG:  Windows fopen("global/pg_fsm.cache","rb") 
> failed:
> code 2, errno 2
> 2006-10-17 17:23:45 LOG:  transaction ID wrap limit is 2147484172, limited
> by database "postgres"
> 2006-10-17 17:23:45 LOG:  Windows fopen("global/pgstat.stat","rb") failed:
> code 2, errno 2
>
>
> i've also tried to update each record on its own in a for-loop. here the
> crash happens as well, sometimes after 10 updates, sometimes after 100
> updates, sometimes even after 1 update. but eventually every record can be
> updated. so i do not think its entierly content-related...
>
> for what its worth, here's the output of pg_controldata:
>
> pg_control version number:            822
> Catalog version number:               200609181
> Database system identifier:           4986650172201464825
> Database cluster state:               in production
> pg_control last modified:             17.10.2006 17:44:29
> Current log file ID:                  0
> Next log file segment:                230
> Latest checkpoint location:           0/E4E0F978
> Prior checkpoint location:            0/E46BF420
> Latest checkpoint's REDO location:    0/E4E03098
> Latest checkpoint's UNDO location:    0/0
> Latest checkpoint's TimeLineID:       1
> Latest checkpoint's NextXID:          0/531333
> Latest checkpoint's NextOID:          6285149
> Latest checkpoint's NextMultiXactId:  1
> Latest checkpoint's NextMultiOffset:  0
> Time of latest checkpoint:            17.10.2006 17:43:45
> Minimum recovery ending location:     0/0
> Maximum data alignment:               8
> Database block size:                  8192
> Blocks per segment of large relation: 131072
> WAL block size:                       8192
> Bytes per WAL segment:                16777216
> Maximum length of identifiers:        64
> Maximum columns in an index:          32
> Date/time type storage:               floating-point numbers
> Maximum length of locale name:        128
> LC_COLLATE:                           German_Switzerland.1252
> LC_CTYPE:                             German_Switzerland.1252
>
> let me know if more information / data is needed.
>
> on a sidenote: are those fopen() errors debug-code-leftovers or something
> one should worry about? i can't find those files on the file system.
>
> - thomas
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 4: Have you searched our list archives?
>
>               http://archives.postgresql.org
>

Re: 8.2beta1 (w32): server process crash (tsvector)

Magnus Hagander <mha@sollentuna.net> — 2006-11-12T16:05:42Z

Ok, I've run this test on an assert enabled build (my msvc build,
actually, so I could get a debugger on it if needed). It then outputs:

WARNING:  detected write past chunk end in ExprContext 02C6D0F8
WARNING:  detected write past chunk end in ExprContext 02C6AEA0
WARNING:  detected write past chunk end in ExprContext 02C6B200
WARNING:  detected write past chunk end in ExprContext 02C44630
WARNING:  detected write past chunk end in ExprContext 02C4C118
WARNING:  problem in alloc set ExprContext: bogus aset link in block
02C435A8, c
hunk 02C44520
WARNING:  detected write past chunk end in ExprContext 02C66440
WARNING:  detected write past chunk end in ExprContext 02C3B9D0
WARNING:  detected write past chunk end in ExprContext 02C3BDE8
WARNING:  detected write past chunk end in ExprContext 02C4E7E0
WARNING:  detected write past chunk end in ExprContext 02C47508
WARNING:  problem in alloc set ExprContext: bogus aset link in block
02C435A8, c
hunk 02C47528
WARNING:  detected write past chunk end in ExprContext 02C43800
WARNING:  detected write past chunk end in ExprContext 02C66C90
WARNING:  detected write past chunk end in ExprContext 02C68270
WARNING:  detected write past chunk end in ExprContext 02C4F5D8
WARNING:  problem in alloc set ExprContext: bogus aset link in block
02C4E6F8, c
hunk 02C4F5F8
WARNING:  detected write past chunk end in ExprContext 02C7B680
WARNING:  detected write past chunk end in ExprContext 02C45190
WARNING:  detected write past chunk end in ExprContext 02C46AC8
WARNING:  detected write past chunk end in ExprContext 02C3C538
WARNING:  detected write past chunk end in ExprContext 02C67B90
WARNING:  detected write past chunk end in ExprContext 02C438F0
WARNING:  problem in alloc set ExprContext: bad single-chunk 02C43FB8 in
block 0
2C435A8
WARNING:  problem in alloc set ExprContext: bogus aset link in block
02C435A8, c
hunk 02C43FB8
server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request. 




The actual crash happens on line 1142 of AllocSetCheck. Full callstack
is:
>	postgres.exe!AllocSetCheck(MemoryContextData *
context=0x02c455b8)  Line 1142 + 0x11 bytes	C
 	postgres.exe!AllocSetReset(MemoryContextData *
context=0x02c455b8)  Line 409 + 0x9 bytes	C
 	postgres.exe!MemoryContextReset(MemoryContextData *
context=0x02c455b8)  Line 129 + 0xf bytes	C
 	postgres.exe!ExecScan(ScanState * node=0x02c227d0,
TupleTableSlot * (ScanState *)* accessMtd=0x00530b70)  Line 91 + 0xc
bytes	C
 	postgres.exe!ExecSeqScan(ScanState * node=0x02c227d0)  Line 130
+ 0xe bytes	C
 	postgres.exe!ExecProcNode(PlanState * node=0x02c227d0)  Line 349
+ 0x9 bytes	C
 	postgres.exe!ExecutePlan(EState * estate=0x02c223e8, PlanState *
planstate=0x02c227d0, CmdType operation=CMD_UPDATE, long numberTuples=0,
ScanDirection direction=ForwardScanDirection, _DestReceiver *
dest=0x02bf8d30)  Line 1081 + 0x9 bytes	C
 	postgres.exe!ExecutorRun(QueryDesc * queryDesc=0x02c44078,
ScanDirection direction=ForwardScanDirection, long count=0)  Line 246 +
0x20 bytes	C
 	postgres.exe!ProcessQuery(Query * parsetree=0x02bddab0, Plan *
plan=0x02bf7e28, ParamListInfoData * params=0x00000000, _DestReceiver *
dest=0x02bf8d30, char * completionTag=0x00d4fb24)  Line 157 + 0xd bytes
C
 	postgres.exe!PortalRunMulti(PortalData * portal=0x02c48138,
_DestReceiver * dest=0x02bf8d30, _DestReceiver * altdest=0x02bf8d30,
char * completionTag=0x00d4fb24)  Line 1148 + 0x1c bytes	C
 	postgres.exe!PortalRun(PortalData * portal=0x02c48138, long
count=2147483647, _DestReceiver * dest=0x02bf8d30, _DestReceiver *
altdest=0x02bf8d30, char * completionTag=0x00d4fb24)  Line 700 + 0x15
bytes	C
 	postgres.exe!exec_simple_query(const char *
query_string=0x02bdd4c8)  Line 943 + 0x23 bytes	C
 	postgres.exe!PostgresMain(int argc=4, char * * argv=0x02ba2478,
const char * username=0x025e7af8)  Line 3414 + 0xc bytes	C
 	postgres.exe!BackendRun(Port * port=0x00d4fd2c)  Line 2853 +
0x17 bytes	C
 	postgres.exe!SubPostmasterMain(int argc=3, char * *
argv=0x025e5b30)  Line 3288 + 0xc bytes	C
 	postgres.exe!main(int argc=3, char * * argv=0x025e5b30)  Line
165 + 0xd bytes	C




Can someone point me towards what next to check? :-)

Oh, and per Thomas, this does NOT appear to happen in C locale, but
happens in both de_CH and en_US. ANd I've tested in Swedish_Sweden,
which also crashes.

Note that this appears not to be index related at all, because during
this test there is only a standard btree index on "someint", and nothing
on the tsvector column.

//Magnus


> -----Original Message-----
> From: pgsql-bugs-owner@postgresql.org 
> [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of Thomas H.
> Sent: den 12 november 2006 15:06
> To: pgsql-bugs@postgresql.org
> Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> 
> this bug (please see below) is unfortunately still present in 
> beta3 (win32 build). test case still crashes the child 
> process and lets postmaster kill & reload everything.
> 
> it is not GiST-related, i've just validated the same problem 
> using GIN.
> 
> this breaks tsearch2 functionality on our win32 system as no 
> tsvector-indexing of new/existing rows is possible (crash 
> after ~10 processed rows). searching already indexed rows works fine.
> 
> best regards,
> thomas
> 
> ----- Original Message -----
> From: <me@alternize.com>
> To: "Tom Lane" <tgl@sss.pgh.pa.us>
> Cc: <pgsql-bugs@postgresql.org>
> Sent: Tuesday, October 17, 2006 9:19 PM
> Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> 
> 
> >>> the following query will crash the server process:
> >>> INSERT INTO news.news
> >>> SELECT * FROM news.news2;
> >>
> >> This is undoubtedly data-dependent.  Can you supply some 
> sample data
> >> that makes it happen?
> >
> > it's not only happening with INSERTS, but also updates. as 
> thats easier to
> > test, here's how i can reproduce the error:
> >
> > 1. create new database (encoding: UTF8) with tsearch2 on 
> 8.2b1 win32 
> > (system
> > locale: de_CH.1252)
> > 2. insert the data from the zip file 
> > [http://alternize.com/pgsql/tsearch2test.zip] (be sure to 
> also update 
> > pg_ts_cf /
> > pg_ts_cfgmap as we have WIN1252 locale)
> > 3. execute UPDATE test SET idxFTI = to_tsvector('default', 
> "sometext"); or
> > similar queries
> > 4. hopefully see the process crashing as i do ;-)
> >
> >
> > 2006-10-17 17:23:44 LOG:  server process (PID 4584) exited with exit
> > code -1073741819
> > 2006-10-17 17:23:44 LOG:  terminating any other active 
> server processes
> > 2006-10-17 17:23:44 WARNING:  terminating connection 
> because of crash of
> > another server process
> > 2006-10-17 17:23:44 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.
> > {snipp}
> > 2006-10-17 17:23:44 LOG:  all server processes terminated; 
> reinitializing
> > 2006-10-17 17:23:44 LOG:  database system was interrupted 
> at 2006-10-17
> > 17:23:41 W. Europe Daylight Time
> > 2006-10-17 17:23:44 LOG:  Windows 
> fopen("recovery.conf","r") failed: code 
> > 2,
> > errno 2
> > 2006-10-17 17:23:44 LOG:  Windows 
> fopen("pg_xlog/00000001.history","r")
> > failed: code 2, errno 2
> > 2006-10-17 17:23:44 LOG:  Windows fopen("backup_label","r") 
> failed: code 
> > 2,
> > errno 2
> > 2006-10-17 17:23:44 LOG:  checkpoint record is at 0/E2ECA728
> > 2006-10-17 17:23:44 LOG:  redo record is at 0/E2ECA728; 
> undo record is at
> > 0/0; shutdown FALSE
> > 2006-10-17 17:23:44 LOG:  next transaction ID: 0/514299; 
> next OID: 6276957
> > 2006-10-17 17:23:44 LOG:  next MultiXactId: 1; next 
> MultiXactOffset: 0
> > 2006-10-17 17:23:44 LOG:  database system was not properly 
> shut down;
> > automatic recovery in progress
> > 2006-10-17 17:23:44 LOG:  redo starts at 0/E2ECA778
> > 2006-10-17 17:23:44 LOG:  unexpected pageaddr 0/DB0CC000 in 
> log file 0,
> > segment 227, offset 835584
> > 2006-10-17 17:23:44 LOG:  redo done at 0/E30CBE78
> > 2006-10-17 17:23:45 LOG:  database system is ready
> > 2006-10-17 17:23:45 LOG:  Windows fopen("global/pg_fsm.cache","rb") 
> > failed:
> > code 2, errno 2
> > 2006-10-17 17:23:45 LOG:  transaction ID wrap limit is 
> 2147484172, limited
> > by database "postgres"
> > 2006-10-17 17:23:45 LOG:  Windows 
> fopen("global/pgstat.stat","rb") failed:
> > code 2, errno 2
> >
> >
> > i've also tried to update each record on its own in a 
> for-loop. here the
> > crash happens as well, sometimes after 10 updates, 
> sometimes after 100
> > updates, sometimes even after 1 update. but eventually 
> every record can be
> > updated. so i do not think its entierly content-related...
> >
> > for what its worth, here's the output of pg_controldata:
> >
> > pg_control version number:            822
> > Catalog version number:               200609181
> > Database system identifier:           4986650172201464825
> > Database cluster state:               in production
> > pg_control last modified:             17.10.2006 17:44:29
> > Current log file ID:                  0
> > Next log file segment:                230
> > Latest checkpoint location:           0/E4E0F978
> > Prior checkpoint location:            0/E46BF420
> > Latest checkpoint's REDO location:    0/E4E03098
> > Latest checkpoint's UNDO location:    0/0
> > Latest checkpoint's TimeLineID:       1
> > Latest checkpoint's NextXID:          0/531333
> > Latest checkpoint's NextOID:          6285149
> > Latest checkpoint's NextMultiXactId:  1
> > Latest checkpoint's NextMultiOffset:  0
> > Time of latest checkpoint:            17.10.2006 17:43:45
> > Minimum recovery ending location:     0/0
> > Maximum data alignment:               8
> > Database block size:                  8192
> > Blocks per segment of large relation: 131072
> > WAL block size:                       8192
> > Bytes per WAL segment:                16777216
> > Maximum length of identifiers:        64
> > Maximum columns in an index:          32
> > Date/time type storage:               floating-point numbers
> > Maximum length of locale name:        128
> > LC_COLLATE:                           German_Switzerland.1252
> > LC_CTYPE:                             German_Switzerland.1252
> >
> > let me know if more information / data is needed.
> >
> > on a sidenote: are those fopen() errors 
> debug-code-leftovers or something
> > one should worry about? i can't find those files on the file system.
> >
> > - thomas
> >
> >
> > ---------------------------(end of 
> broadcast)---------------------------
> > TIP 4: Have you searched our list archives?
> >
> >               http://archives.postgresql.org
> > 
> 
> 
> 
> ---------------------------(end of 
> broadcast)---------------------------
> TIP 6: explain analyze is your friend
>

Re: 8.2beta1 (w32): server process crash (tsvector)

imad <immaad@gmail.com> — 2006-11-12T16:20:11Z

yeah... i dont think it will be related to index anyway.
it looks to me that some extra bytes are written to the allocated
memory when locale is set to en-US etc. The warning

"WARNING:  detected write past chunk end in ExprContext 02C6D0F8"

is generated when you write bytes on a location more than its allocated size,
and this thing will eventualy lead to a server crash.

Now, I would suggest try to minimize the script and look for the action
with leads to this warning. Then a debug would be easy on the execution
path and I guess, there won't be any problem in parsing and planning.

Can you send me the knotty script BTW?


--Imad
www.EnterpriseDB.com

On 11/12/06, Magnus Hagander <mha@sollentuna.net> wrote:
> Ok, I've run this test on an assert enabled build (my msvc build,
> actually, so I could get a debugger on it if needed). It then outputs:
>
> WARNING:  detected write past chunk end in ExprContext 02C6D0F8
> WARNING:  detected write past chunk end in ExprContext 02C6AEA0
> WARNING:  detected write past chunk end in ExprContext 02C6B200
> WARNING:  detected write past chunk end in ExprContext 02C44630
> WARNING:  detected write past chunk end in ExprContext 02C4C118
> WARNING:  problem in alloc set ExprContext: bogus aset link in block
> 02C435A8, c
> hunk 02C44520
> WARNING:  detected write past chunk end in ExprContext 02C66440
> WARNING:  detected write past chunk end in ExprContext 02C3B9D0
> WARNING:  detected write past chunk end in ExprContext 02C3BDE8
> WARNING:  detected write past chunk end in ExprContext 02C4E7E0
> WARNING:  detected write past chunk end in ExprContext 02C47508
> WARNING:  problem in alloc set ExprContext: bogus aset link in block
> 02C435A8, c
> hunk 02C47528
> WARNING:  detected write past chunk end in ExprContext 02C43800
> WARNING:  detected write past chunk end in ExprContext 02C66C90
> WARNING:  detected write past chunk end in ExprContext 02C68270
> WARNING:  detected write past chunk end in ExprContext 02C4F5D8
> WARNING:  problem in alloc set ExprContext: bogus aset link in block
> 02C4E6F8, c
> hunk 02C4F5F8
> WARNING:  detected write past chunk end in ExprContext 02C7B680
> WARNING:  detected write past chunk end in ExprContext 02C45190
> WARNING:  detected write past chunk end in ExprContext 02C46AC8
> WARNING:  detected write past chunk end in ExprContext 02C3C538
> WARNING:  detected write past chunk end in ExprContext 02C67B90
> WARNING:  detected write past chunk end in ExprContext 02C438F0
> WARNING:  problem in alloc set ExprContext: bad single-chunk 02C43FB8 in
> block 0
> 2C435A8
> WARNING:  problem in alloc set ExprContext: bogus aset link in block
> 02C435A8, c
> hunk 02C43FB8
> server closed the connection unexpectedly
>         This probably means the server terminated abnormally
>         before or while processing the request.
>
>
>
>
> The actual crash happens on line 1142 of AllocSetCheck. Full callstack
> is:
> >       postgres.exe!AllocSetCheck(MemoryContextData *
> context=0x02c455b8)  Line 1142 + 0x11 bytes     C
>         postgres.exe!AllocSetReset(MemoryContextData *
> context=0x02c455b8)  Line 409 + 0x9 bytes       C
>         postgres.exe!MemoryContextReset(MemoryContextData *
> context=0x02c455b8)  Line 129 + 0xf bytes       C
>         postgres.exe!ExecScan(ScanState * node=0x02c227d0,
> TupleTableSlot * (ScanState *)* accessMtd=0x00530b70)  Line 91 + 0xc
> bytes   C
>         postgres.exe!ExecSeqScan(ScanState * node=0x02c227d0)  Line 130
> + 0xe bytes     C
>         postgres.exe!ExecProcNode(PlanState * node=0x02c227d0)  Line 349
> + 0x9 bytes     C
>         postgres.exe!ExecutePlan(EState * estate=0x02c223e8, PlanState *
> planstate=0x02c227d0, CmdType operation=CMD_UPDATE, long numberTuples=0,
> ScanDirection direction=ForwardScanDirection, _DestReceiver *
> dest=0x02bf8d30)  Line 1081 + 0x9 bytes C
>         postgres.exe!ExecutorRun(QueryDesc * queryDesc=0x02c44078,
> ScanDirection direction=ForwardScanDirection, long count=0)  Line 246 +
> 0x20 bytes      C
>         postgres.exe!ProcessQuery(Query * parsetree=0x02bddab0, Plan *
> plan=0x02bf7e28, ParamListInfoData * params=0x00000000, _DestReceiver *
> dest=0x02bf8d30, char * completionTag=0x00d4fb24)  Line 157 + 0xd bytes
> C
>         postgres.exe!PortalRunMulti(PortalData * portal=0x02c48138,
> _DestReceiver * dest=0x02bf8d30, _DestReceiver * altdest=0x02bf8d30,
> char * completionTag=0x00d4fb24)  Line 1148 + 0x1c bytes        C
>         postgres.exe!PortalRun(PortalData * portal=0x02c48138, long
> count=2147483647, _DestReceiver * dest=0x02bf8d30, _DestReceiver *
> altdest=0x02bf8d30, char * completionTag=0x00d4fb24)  Line 700 + 0x15
> bytes   C
>         postgres.exe!exec_simple_query(const char *
> query_string=0x02bdd4c8)  Line 943 + 0x23 bytes C
>         postgres.exe!PostgresMain(int argc=4, char * * argv=0x02ba2478,
> const char * username=0x025e7af8)  Line 3414 + 0xc bytes        C
>         postgres.exe!BackendRun(Port * port=0x00d4fd2c)  Line 2853 +
> 0x17 bytes      C
>         postgres.exe!SubPostmasterMain(int argc=3, char * *
> argv=0x025e5b30)  Line 3288 + 0xc bytes C
>         postgres.exe!main(int argc=3, char * * argv=0x025e5b30)  Line
> 165 + 0xd bytes C
>
>
>
>
> Can someone point me towards what next to check? :-)
>
> Oh, and per Thomas, this does NOT appear to happen in C locale, but
> happens in both de_CH and en_US. ANd I've tested in Swedish_Sweden,
> which also crashes.
>
> Note that this appears not to be index related at all, because during
> this test there is only a standard btree index on "someint", and nothing
> on the tsvector column.
>
> //Magnus
>
>
> > -----Original Message-----
> > From: pgsql-bugs-owner@postgresql.org
> > [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of Thomas H.
> > Sent: den 12 november 2006 15:06
> > To: pgsql-bugs@postgresql.org
> > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> >
> > this bug (please see below) is unfortunately still present in
> > beta3 (win32 build). test case still crashes the child
> > process and lets postmaster kill & reload everything.
> >
> > it is not GiST-related, i've just validated the same problem
> > using GIN.
> >
> > this breaks tsearch2 functionality on our win32 system as no
> > tsvector-indexing of new/existing rows is possible (crash
> > after ~10 processed rows). searching already indexed rows works fine.
> >
> > best regards,
> > thomas
> >
> > ----- Original Message -----
> > From: <me@alternize.com>
> > To: "Tom Lane" <tgl@sss.pgh.pa.us>
> > Cc: <pgsql-bugs@postgresql.org>
> > Sent: Tuesday, October 17, 2006 9:19 PM
> > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> >
> >
> > >>> the following query will crash the server process:
> > >>> INSERT INTO news.news
> > >>> SELECT * FROM news.news2;
> > >>
> > >> This is undoubtedly data-dependent.  Can you supply some
> > sample data
> > >> that makes it happen?
> > >
> > > it's not only happening with INSERTS, but also updates. as
> > thats easier to
> > > test, here's how i can reproduce the error:
> > >
> > > 1. create new database (encoding: UTF8) with tsearch2 on
> > 8.2b1 win32
> > > (system
> > > locale: de_CH.1252)
> > > 2. insert the data from the zip file
> > > [http://alternize.com/pgsql/tsearch2test.zip] (be sure to
> > also update
> > > pg_ts_cf /
> > > pg_ts_cfgmap as we have WIN1252 locale)
> > > 3. execute UPDATE test SET idxFTI = to_tsvector('default',
> > "sometext"); or
> > > similar queries
> > > 4. hopefully see the process crashing as i do ;-)
> > >
> > >
> > > 2006-10-17 17:23:44 LOG:  server process (PID 4584) exited with exit
> > > code -1073741819
> > > 2006-10-17 17:23:44 LOG:  terminating any other active
> > server processes
> > > 2006-10-17 17:23:44 WARNING:  terminating connection
> > because of crash of
> > > another server process
> > > 2006-10-17 17:23:44 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.
> > > {snipp}
> > > 2006-10-17 17:23:44 LOG:  all server processes terminated;
> > reinitializing
> > > 2006-10-17 17:23:44 LOG:  database system was interrupted
> > at 2006-10-17
> > > 17:23:41 W. Europe Daylight Time
> > > 2006-10-17 17:23:44 LOG:  Windows
> > fopen("recovery.conf","r") failed: code
> > > 2,
> > > errno 2
> > > 2006-10-17 17:23:44 LOG:  Windows
> > fopen("pg_xlog/00000001.history","r")
> > > failed: code 2, errno 2
> > > 2006-10-17 17:23:44 LOG:  Windows fopen("backup_label","r")
> > failed: code
> > > 2,
> > > errno 2
> > > 2006-10-17 17:23:44 LOG:  checkpoint record is at 0/E2ECA728
> > > 2006-10-17 17:23:44 LOG:  redo record is at 0/E2ECA728;
> > undo record is at
> > > 0/0; shutdown FALSE
> > > 2006-10-17 17:23:44 LOG:  next transaction ID: 0/514299;
> > next OID: 6276957
> > > 2006-10-17 17:23:44 LOG:  next MultiXactId: 1; next
> > MultiXactOffset: 0
> > > 2006-10-17 17:23:44 LOG:  database system was not properly
> > shut down;
> > > automatic recovery in progress
> > > 2006-10-17 17:23:44 LOG:  redo starts at 0/E2ECA778
> > > 2006-10-17 17:23:44 LOG:  unexpected pageaddr 0/DB0CC000 in
> > log file 0,
> > > segment 227, offset 835584
> > > 2006-10-17 17:23:44 LOG:  redo done at 0/E30CBE78
> > > 2006-10-17 17:23:45 LOG:  database system is ready
> > > 2006-10-17 17:23:45 LOG:  Windows fopen("global/pg_fsm.cache","rb")
> > > failed:
> > > code 2, errno 2
> > > 2006-10-17 17:23:45 LOG:  transaction ID wrap limit is
> > 2147484172, limited
> > > by database "postgres"
> > > 2006-10-17 17:23:45 LOG:  Windows
> > fopen("global/pgstat.stat","rb") failed:
> > > code 2, errno 2
> > >
> > >
> > > i've also tried to update each record on its own in a
> > for-loop. here the
> > > crash happens as well, sometimes after 10 updates,
> > sometimes after 100
> > > updates, sometimes even after 1 update. but eventually
> > every record can be
> > > updated. so i do not think its entierly content-related...
> > >
> > > for what its worth, here's the output of pg_controldata:
> > >
> > > pg_control version number:            822
> > > Catalog version number:               200609181
> > > Database system identifier:           4986650172201464825
> > > Database cluster state:               in production
> > > pg_control last modified:             17.10.2006 17:44:29
> > > Current log file ID:                  0
> > > Next log file segment:                230
> > > Latest checkpoint location:           0/E4E0F978
> > > Prior checkpoint location:            0/E46BF420
> > > Latest checkpoint's REDO location:    0/E4E03098
> > > Latest checkpoint's UNDO location:    0/0
> > > Latest checkpoint's TimeLineID:       1
> > > Latest checkpoint's NextXID:          0/531333
> > > Latest checkpoint's NextOID:          6285149
> > > Latest checkpoint's NextMultiXactId:  1
> > > Latest checkpoint's NextMultiOffset:  0
> > > Time of latest checkpoint:            17.10.2006 17:43:45
> > > Minimum recovery ending location:     0/0
> > > Maximum data alignment:               8
> > > Database block size:                  8192
> > > Blocks per segment of large relation: 131072
> > > WAL block size:                       8192
> > > Bytes per WAL segment:                16777216
> > > Maximum length of identifiers:        64
> > > Maximum columns in an index:          32
> > > Date/time type storage:               floating-point numbers
> > > Maximum length of locale name:        128
> > > LC_COLLATE:                           German_Switzerland.1252
> > > LC_CTYPE:                             German_Switzerland.1252
> > >
> > > let me know if more information / data is needed.
> > >
> > > on a sidenote: are those fopen() errors
> > debug-code-leftovers or something
> > > one should worry about? i can't find those files on the file system.
> > >
> > > - thomas
> > >
> > >
> > > ---------------------------(end of
> > broadcast)---------------------------
> > > TIP 4: Have you searched our list archives?
> > >
> > >               http://archives.postgresql.org
> > >
> >
> >
> >
> > ---------------------------(end of
> > broadcast)---------------------------
> > TIP 6: explain analyze is your friend
> >
>
> ---------------------------(end of broadcast)---------------------------
> TIP 3: Have you checked our extensive FAQ?
>
>                http://www.postgresql.org/docs/faq
>

Re: 8.2beta1 (w32): server process crash (tsvector)

Thomas H. <me@alternize.com> — 2006-11-12T16:27:58Z

here are the steps to reproduce:

--------
1. intall win32 beta3 as new instance using UTF8 / en_US and tsearch2 
module, everything else default
2. create new db with encoding UTF8, standard template
3. load data from http://alternize.com/pgsql/tsearch2test.zip (updated dump 
so it only includes the test table/data)
4. issue query: UPDATE test SET idxFTI = to_tsvector('default', sometext);
5. watch the process die... *sniff*
-------

(steps 1 & 2 can probably be skipped, but i wanted to have a clean test env)

best regards,
thomas



----- Original Message ----- 
From: "imad" <immaad@gmail.com>
To: "Magnus Hagander" <mha@sollentuna.net>
Cc: "Thomas H." <me@alternize.com>; <pgsql-bugs@postgresql.org>; "Tom Lane" 
<tgl@sss.pgh.pa.us>
Sent: Sunday, November 12, 2006 5:20 PM
Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)


> yeah... i dont think it will be related to index anyway.
> it looks to me that some extra bytes are written to the allocated
> memory when locale is set to en-US etc. The warning
>
> "WARNING:  detected write past chunk end in ExprContext 02C6D0F8"
>
> is generated when you write bytes on a location more than its allocated 
> size,
> and this thing will eventualy lead to a server crash.
>
> Now, I would suggest try to minimize the script and look for the action
> with leads to this warning. Then a debug would be easy on the execution
> path and I guess, there won't be any problem in parsing and planning.
>
> Can you send me the knotty script BTW?
>
>
> --Imad
> www.EnterpriseDB.com
>
> On 11/12/06, Magnus Hagander <mha@sollentuna.net> wrote:
>> Ok, I've run this test on an assert enabled build (my msvc build,
>> actually, so I could get a debugger on it if needed). It then outputs:
>>
>> WARNING:  detected write past chunk end in ExprContext 02C6D0F8
>> WARNING:  detected write past chunk end in ExprContext 02C6AEA0
>> WARNING:  detected write past chunk end in ExprContext 02C6B200
>> WARNING:  detected write past chunk end in ExprContext 02C44630
>> WARNING:  detected write past chunk end in ExprContext 02C4C118
>> WARNING:  problem in alloc set ExprContext: bogus aset link in block
>> 02C435A8, c
>> hunk 02C44520
>> WARNING:  detected write past chunk end in ExprContext 02C66440
>> WARNING:  detected write past chunk end in ExprContext 02C3B9D0
>> WARNING:  detected write past chunk end in ExprContext 02C3BDE8
>> WARNING:  detected write past chunk end in ExprContext 02C4E7E0
>> WARNING:  detected write past chunk end in ExprContext 02C47508
>> WARNING:  problem in alloc set ExprContext: bogus aset link in block
>> 02C435A8, c
>> hunk 02C47528
>> WARNING:  detected write past chunk end in ExprContext 02C43800
>> WARNING:  detected write past chunk end in ExprContext 02C66C90
>> WARNING:  detected write past chunk end in ExprContext 02C68270
>> WARNING:  detected write past chunk end in ExprContext 02C4F5D8
>> WARNING:  problem in alloc set ExprContext: bogus aset link in block
>> 02C4E6F8, c
>> hunk 02C4F5F8
>> WARNING:  detected write past chunk end in ExprContext 02C7B680
>> WARNING:  detected write past chunk end in ExprContext 02C45190
>> WARNING:  detected write past chunk end in ExprContext 02C46AC8
>> WARNING:  detected write past chunk end in ExprContext 02C3C538
>> WARNING:  detected write past chunk end in ExprContext 02C67B90
>> WARNING:  detected write past chunk end in ExprContext 02C438F0
>> WARNING:  problem in alloc set ExprContext: bad single-chunk 02C43FB8 in
>> block 0
>> 2C435A8
>> WARNING:  problem in alloc set ExprContext: bogus aset link in block
>> 02C435A8, c
>> hunk 02C43FB8
>> server closed the connection unexpectedly
>>         This probably means the server terminated abnormally
>>         before or while processing the request.
>>
>>
>>
>>
>> The actual crash happens on line 1142 of AllocSetCheck. Full callstack
>> is:
>> >       postgres.exe!AllocSetCheck(MemoryContextData *
>> context=0x02c455b8)  Line 1142 + 0x11 bytes     C
>>         postgres.exe!AllocSetReset(MemoryContextData *
>> context=0x02c455b8)  Line 409 + 0x9 bytes       C
>>         postgres.exe!MemoryContextReset(MemoryContextData *
>> context=0x02c455b8)  Line 129 + 0xf bytes       C
>>         postgres.exe!ExecScan(ScanState * node=0x02c227d0,
>> TupleTableSlot * (ScanState *)* accessMtd=0x00530b70)  Line 91 + 0xc
>> bytes   C
>>         postgres.exe!ExecSeqScan(ScanState * node=0x02c227d0)  Line 130
>> + 0xe bytes     C
>>         postgres.exe!ExecProcNode(PlanState * node=0x02c227d0)  Line 349
>> + 0x9 bytes     C
>>         postgres.exe!ExecutePlan(EState * estate=0x02c223e8, PlanState *
>> planstate=0x02c227d0, CmdType operation=CMD_UPDATE, long numberTuples=0,
>> ScanDirection direction=ForwardScanDirection, _DestReceiver *
>> dest=0x02bf8d30)  Line 1081 + 0x9 bytes C
>>         postgres.exe!ExecutorRun(QueryDesc * queryDesc=0x02c44078,
>> ScanDirection direction=ForwardScanDirection, long count=0)  Line 246 +
>> 0x20 bytes      C
>>         postgres.exe!ProcessQuery(Query * parsetree=0x02bddab0, Plan *
>> plan=0x02bf7e28, ParamListInfoData * params=0x00000000, _DestReceiver *
>> dest=0x02bf8d30, char * completionTag=0x00d4fb24)  Line 157 + 0xd bytes
>> C
>>         postgres.exe!PortalRunMulti(PortalData * portal=0x02c48138,
>> _DestReceiver * dest=0x02bf8d30, _DestReceiver * altdest=0x02bf8d30,
>> char * completionTag=0x00d4fb24)  Line 1148 + 0x1c bytes        C
>>         postgres.exe!PortalRun(PortalData * portal=0x02c48138, long
>> count=2147483647, _DestReceiver * dest=0x02bf8d30, _DestReceiver *
>> altdest=0x02bf8d30, char * completionTag=0x00d4fb24)  Line 700 + 0x15
>> bytes   C
>>         postgres.exe!exec_simple_query(const char *
>> query_string=0x02bdd4c8)  Line 943 + 0x23 bytes C
>>         postgres.exe!PostgresMain(int argc=4, char * * argv=0x02ba2478,
>> const char * username=0x025e7af8)  Line 3414 + 0xc bytes        C
>>         postgres.exe!BackendRun(Port * port=0x00d4fd2c)  Line 2853 +
>> 0x17 bytes      C
>>         postgres.exe!SubPostmasterMain(int argc=3, char * *
>> argv=0x025e5b30)  Line 3288 + 0xc bytes C
>>         postgres.exe!main(int argc=3, char * * argv=0x025e5b30)  Line
>> 165 + 0xd bytes C
>>
>>
>>
>>
>> Can someone point me towards what next to check? :-)
>>
>> Oh, and per Thomas, this does NOT appear to happen in C locale, but
>> happens in both de_CH and en_US. ANd I've tested in Swedish_Sweden,
>> which also crashes.
>>
>> Note that this appears not to be index related at all, because during
>> this test there is only a standard btree index on "someint", and nothing
>> on the tsvector column.
>>
>> //Magnus
>>
>>
>> > -----Original Message-----
>> > From: pgsql-bugs-owner@postgresql.org
>> > [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of Thomas H.
>> > Sent: den 12 november 2006 15:06
>> > To: pgsql-bugs@postgresql.org
>> > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
>> >
>> > this bug (please see below) is unfortunately still present in
>> > beta3 (win32 build). test case still crashes the child
>> > process and lets postmaster kill & reload everything.
>> >
>> > it is not GiST-related, i've just validated the same problem
>> > using GIN.
>> >
>> > this breaks tsearch2 functionality on our win32 system as no
>> > tsvector-indexing of new/existing rows is possible (crash
>> > after ~10 processed rows). searching already indexed rows works fine.
>> >
>> > best regards,
>> > thomas
>> >
>> > ----- Original Message -----
>> > From: <me@alternize.com>
>> > To: "Tom Lane" <tgl@sss.pgh.pa.us>
>> > Cc: <pgsql-bugs@postgresql.org>
>> > Sent: Tuesday, October 17, 2006 9:19 PM
>> > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
>> >
>> >
>> > >>> the following query will crash the server process:
>> > >>> INSERT INTO news.news
>> > >>> SELECT * FROM news.news2;
>> > >>
>> > >> This is undoubtedly data-dependent.  Can you supply some
>> > sample data
>> > >> that makes it happen?
>> > >
>> > > it's not only happening with INSERTS, but also updates. as
>> > thats easier to
>> > > test, here's how i can reproduce the error:
>> > >
>> > > 1. create new database (encoding: UTF8) with tsearch2 on
>> > 8.2b1 win32
>> > > (system
>> > > locale: de_CH.1252)
>> > > 2. insert the data from the zip file
>> > > [http://alternize.com/pgsql/tsearch2test.zip] (be sure to
>> > also update
>> > > pg_ts_cf /
>> > > pg_ts_cfgmap as we have WIN1252 locale)
>> > > 3. execute UPDATE test SET idxFTI = to_tsvector('default',
>> > "sometext"); or
>> > > similar queries
>> > > 4. hopefully see the process crashing as i do ;-)
>> > >
>> > >
>> > > 2006-10-17 17:23:44 LOG:  server process (PID 4584) exited with exit
>> > > code -1073741819
>> > > 2006-10-17 17:23:44 LOG:  terminating any other active
>> > server processes
>> > > 2006-10-17 17:23:44 WARNING:  terminating connection
>> > because of crash of
>> > > another server process
>> > > 2006-10-17 17:23:44 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.
>> > > {snipp}
>> > > 2006-10-17 17:23:44 LOG:  all server processes terminated;
>> > reinitializing
>> > > 2006-10-17 17:23:44 LOG:  database system was interrupted
>> > at 2006-10-17
>> > > 17:23:41 W. Europe Daylight Time
>> > > 2006-10-17 17:23:44 LOG:  Windows
>> > fopen("recovery.conf","r") failed: code
>> > > 2,
>> > > errno 2
>> > > 2006-10-17 17:23:44 LOG:  Windows
>> > fopen("pg_xlog/00000001.history","r")
>> > > failed: code 2, errno 2
>> > > 2006-10-17 17:23:44 LOG:  Windows fopen("backup_label","r")
>> > failed: code
>> > > 2,
>> > > errno 2
>> > > 2006-10-17 17:23:44 LOG:  checkpoint record is at 0/E2ECA728
>> > > 2006-10-17 17:23:44 LOG:  redo record is at 0/E2ECA728;
>> > undo record is at
>> > > 0/0; shutdown FALSE
>> > > 2006-10-17 17:23:44 LOG:  next transaction ID: 0/514299;
>> > next OID: 6276957
>> > > 2006-10-17 17:23:44 LOG:  next MultiXactId: 1; next
>> > MultiXactOffset: 0
>> > > 2006-10-17 17:23:44 LOG:  database system was not properly
>> > shut down;
>> > > automatic recovery in progress
>> > > 2006-10-17 17:23:44 LOG:  redo starts at 0/E2ECA778
>> > > 2006-10-17 17:23:44 LOG:  unexpected pageaddr 0/DB0CC000 in
>> > log file 0,
>> > > segment 227, offset 835584
>> > > 2006-10-17 17:23:44 LOG:  redo done at 0/E30CBE78
>> > > 2006-10-17 17:23:45 LOG:  database system is ready
>> > > 2006-10-17 17:23:45 LOG:  Windows fopen("global/pg_fsm.cache","rb")
>> > > failed:
>> > > code 2, errno 2
>> > > 2006-10-17 17:23:45 LOG:  transaction ID wrap limit is
>> > 2147484172, limited
>> > > by database "postgres"
>> > > 2006-10-17 17:23:45 LOG:  Windows
>> > fopen("global/pgstat.stat","rb") failed:
>> > > code 2, errno 2
>> > >
>> > >
>> > > i've also tried to update each record on its own in a
>> > for-loop. here the
>> > > crash happens as well, sometimes after 10 updates,
>> > sometimes after 100
>> > > updates, sometimes even after 1 update. but eventually
>> > every record can be
>> > > updated. so i do not think its entierly content-related...
>> > >
>> > > for what its worth, here's the output of pg_controldata:
>> > >
>> > > pg_control version number:            822
>> > > Catalog version number:               200609181
>> > > Database system identifier:           4986650172201464825
>> > > Database cluster state:               in production
>> > > pg_control last modified:             17.10.2006 17:44:29
>> > > Current log file ID:                  0
>> > > Next log file segment:                230
>> > > Latest checkpoint location:           0/E4E0F978
>> > > Prior checkpoint location:            0/E46BF420
>> > > Latest checkpoint's REDO location:    0/E4E03098
>> > > Latest checkpoint's UNDO location:    0/0
>> > > Latest checkpoint's TimeLineID:       1
>> > > Latest checkpoint's NextXID:          0/531333
>> > > Latest checkpoint's NextOID:          6285149
>> > > Latest checkpoint's NextMultiXactId:  1
>> > > Latest checkpoint's NextMultiOffset:  0
>> > > Time of latest checkpoint:            17.10.2006 17:43:45
>> > > Minimum recovery ending location:     0/0
>> > > Maximum data alignment:               8
>> > > Database block size:                  8192
>> > > Blocks per segment of large relation: 131072
>> > > WAL block size:                       8192
>> > > Bytes per WAL segment:                16777216
>> > > Maximum length of identifiers:        64
>> > > Maximum columns in an index:          32
>> > > Date/time type storage:               floating-point numbers
>> > > Maximum length of locale name:        128
>> > > LC_COLLATE:                           German_Switzerland.1252
>> > > LC_CTYPE:                             German_Switzerland.1252
>> > >
>> > > let me know if more information / data is needed.
>> > >
>> > > on a sidenote: are those fopen() errors
>> > debug-code-leftovers or something
>> > > one should worry about? i can't find those files on the file system.
>> > >
>> > > - thomas
>> > >
>> > >
>> > > ---------------------------(end of
>> > broadcast)---------------------------
>> > > TIP 4: Have you searched our list archives?
>> > >
>> > >               http://archives.postgresql.org
>> > >
>> >
>> >
>> >
>> > ---------------------------(end of
>> > broadcast)---------------------------
>> > TIP 6: explain analyze is your friend
>> >
>>
>> ---------------------------(end of broadcast)---------------------------
>> TIP 3: Have you checked our extensive FAQ?
>>
>>                http://www.postgresql.org/docs/faq
>>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 2: Don't 'kill -9' the postmaster
>

Re: 8.2beta1 (w32): server process crash (tsvector)

Tom Lane <tgl@sss.pgh.pa.us> — 2006-11-12T17:41:08Z

"Thomas H." <me@alternize.com> writes:
> here are the steps to reproduce:
> --------
> 1. intall win32 beta3 as new instance using UTF8 / en_US and tsearch2 
> module, everything else default
> 2. create new db with encoding UTF8, standard template
> 3. load data from http://alternize.com/pgsql/tsearch2test.zip (updated dump 
> so it only includes the test table/data)
> 4. issue query: UPDATE test SET idxFTI = to_tsvector('default', sometext);
> 5. watch the process die... *sniff*
> -------

Did you do anything to install tsearch2 into this fresh database beyond
"\i tsearch2.sql"?

I couldn't reproduce it on a Linux x86 machine, so it seems specific to
the Windows port.

			regards, tom lane

Re: 8.2beta1 (w32): server process crash (tsvector)

Thomas H. <me@alternize.com> — 2006-11-12T17:50:36Z

> Did you do anything to install tsearch2 into this fresh database beyond
> "\i tsearch2.sql"?

no, i used the win32 setup and selected to install tsearch2 contrib 
module... so i didn't even had to run "\i tsearch2.sql". installation logs 
are available if helpful.

should i try a manual install of tsearch2.sql to see if that changes 
anything?

- thomas

Re: 8.2beta1 (w32): server process crash (tsvector)

Tom Lane <tgl@sss.pgh.pa.us> — 2006-11-12T17:56:17Z

"Thomas H." <me@alternize.com> writes:
> no, i used the win32 setup and selected to install tsearch2 contrib 
> module... so i didn't even had to run "\i tsearch2.sql". installation logs 
> are available if helpful.

Hm, I wonder whether the windows installer changes tsearch2's
configuration at all.

			regards, tom lane

Re: 8.2beta1 (w32): server process crash (tsvector)

Thomas H. <me@alternize.com> — 2006-11-12T18:17:07Z

it should... at least for <8.2 this worked fine without manually installing 
tsearch2. the tsearch2.sql is run by the installer, the tsearch2 objects are 
present in template1 and thus in the freshly created db. also the function 
and types are there or else the table creation would fail in first place (as 
one of its column is tsvector). of course you have to tweak the config 
afterwards if you want it to run smooth on non-default locales.

just for fun i set up an instance without selecting the tsearch2 option and 
run tsearch2.sql manually. there was no error with this script. the result 
in my test case is unfortunately the same - crashing.

- thomas

----- Original Message ----- 
From: "Tom Lane" <tgl@sss.pgh.pa.us>
To: "Thomas H." <me@alternize.com>
Cc: "imad" <immaad@gmail.com>; "Magnus Hagander" <mha@sollentuna.net>; 
<pgsql-bugs@postgresql.org>
Sent: Sunday, November 12, 2006 6:56 PM
Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)

> "Thomas H." <me@alternize.com> writes:
>> no, i used the win32 setup and selected to install tsearch2 contrib
>> module... so i didn't even had to run "\i tsearch2.sql". installation 
>> logs
>> are available if helpful.
>
> Hm, I wonder whether the windows installer changes tsearch2's
> configuration at all.
>
> regards, tom lane
>

Re: 8.2beta1 (w32): server process crash (tsvector)

Dave Page <dpage@postgresql.org> — 2006-11-12T19:32:37Z

Tom Lane wrote:
> "Thomas H." <me@alternize.com> writes:
>> no, i used the win32 setup and selected to install tsearch2 contrib 
>> module... so i didn't even had to run "\i tsearch2.sql". installation logs 
>> are available if helpful.
> 
> Hm, I wonder whether the windows installer changes tsearch2's
> configuration at all.

No, it just feeds the sql script into PQexec.

Regards, Dave

Re: 8.2beta1 (w32): server process crash (tsvector)

Magnus Hagander <mha@sollentuna.net> — 2006-11-12T20:34:30Z

> > no, i used the win32 setup and selected to install tsearch2 contrib 
> > module... so i didn't even had to run "\i tsearch2.sql". 
> installation 
> > logs are available if helpful.
> 
> Hm, I wonder whether the windows installer changes tsearch2's 
> configuration at all.

It doesn't. And in my repro, I used the \i method to load tsearch2.sql,
and that also causes the crash.

//Magnus

Re: 8.2beta1 (w32): server process crash (tsvector)

Magnus Hagander <mha@sollentuna.net> — 2006-11-13T09:00:59Z

Did some more tests, and it's even easier to repro this. No need to
update, just
SELECT to_tsvector('default',sometext) from test;

It appears to be data dependent still, though, because just running
SELECT to_tsvector('default','foo bar foo bar foo bar foo bar')
fromgenerate_series(1,1000000) works withuot a hitch.


Also, the "detected write past chunk end" comes from the pfree() in
tsvector.c, function unqiueWORD() line 656. At this point, "ptr->word"
points at the text "temp" followed by a bunch of junk. The callstack
leading up to this is:
 	postgres.exe!AllocSetFree(MemoryContextData *
context=0x02c37bd8, void * pointer=0x02c65ed0)  Line 775	C
 	postgres.exe!pfree(void * pointer=0x02c65ed0)  Line 585 + 0x17
bytes	C
 	tsearch2.dll!uniqueWORD(TSWORD * a=0x02c66e60, int l=517)  Line
656 + 0xc bytes	C
 	tsearch2.dll!makevalue(PRSTEXT * prs=0x00d4f44c)  Line 692 +
0x12 bytes	C
 	tsearch2.dll!to_tsvector(FunctionCallInfoData *
fcinfo=0x00d4f46c)  Line 764 + 0x9 bytes	C
 	postgres.exe!DirectFunctionCall3(unsigned long
(FunctionCallInfoData *)* func=0x02cd1131, unsigned long arg1=16473,
unsigned long arg2=49941724, unsigned long arg3=0)  Line 905 + 0xa bytes
C
 	tsearch2.dll!to_tsvector_name(FunctionCallInfoData *
fcinfo=0x00d4f6b0)  Line 787 + 0x20 bytes	C


Now, the parametsrs to to_tsvector() looks weird - the "text *in =
PG_GETARG_TEXT_P(1)" appears to return a struct with vl_len set t
2139062143, which seems. Eh. Wrong? :) But this does not happen on the
*first* call to to_tsquery() which shows a proper text, but subsequent
calls show what lokos like garbage a couple of times, and then the
WARNING about the write past end fires.

//Magnus 

> -----Original Message-----
> From: pgsql-bugs-owner@postgresql.org 
> [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of Magnus Hagander
> Sent: den 12 november 2006 17:06
> To: Thomas H.; pgsql-bugs@postgresql.org
> Cc: Tom Lane
> Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> 
> Ok, I've run this test on an assert enabled build (my msvc 
> build, actually, so I could get a debugger on it if needed). 
> It then outputs:
> 
> WARNING:  detected write past chunk end in ExprContext 02C6D0F8
> WARNING:  detected write past chunk end in ExprContext 02C6AEA0
> WARNING:  detected write past chunk end in ExprContext 02C6B200
> WARNING:  detected write past chunk end in ExprContext 02C44630
> WARNING:  detected write past chunk end in ExprContext 02C4C118
> WARNING:  problem in alloc set ExprContext: bogus aset link 
> in block 02C435A8, c hunk 02C44520
> WARNING:  detected write past chunk end in ExprContext 02C66440
> WARNING:  detected write past chunk end in ExprContext 02C3B9D0
> WARNING:  detected write past chunk end in ExprContext 02C3BDE8
> WARNING:  detected write past chunk end in ExprContext 02C4E7E0
> WARNING:  detected write past chunk end in ExprContext 02C47508
> WARNING:  problem in alloc set ExprContext: bogus aset link 
> in block 02C435A8, c hunk 02C47528
> WARNING:  detected write past chunk end in ExprContext 02C43800
> WARNING:  detected write past chunk end in ExprContext 02C66C90
> WARNING:  detected write past chunk end in ExprContext 02C68270
> WARNING:  detected write past chunk end in ExprContext 02C4F5D8
> WARNING:  problem in alloc set ExprContext: bogus aset link 
> in block 02C4E6F8, c hunk 02C4F5F8
> WARNING:  detected write past chunk end in ExprContext 02C7B680
> WARNING:  detected write past chunk end in ExprContext 02C45190
> WARNING:  detected write past chunk end in ExprContext 02C46AC8
> WARNING:  detected write past chunk end in ExprContext 02C3C538
> WARNING:  detected write past chunk end in ExprContext 02C67B90
> WARNING:  detected write past chunk end in ExprContext 02C438F0
> WARNING:  problem in alloc set ExprContext: bad single-chunk 
> 02C43FB8 in block 0
> 2C435A8
> WARNING:  problem in alloc set ExprContext: bogus aset link 
> in block 02C435A8, c hunk 02C43FB8 server closed the 
> connection unexpectedly
>         This probably means the server terminated abnormally
>         before or while processing the request. 
> 
> 
> 
> 
> The actual crash happens on line 1142 of AllocSetCheck. Full callstack
> is:
> >	postgres.exe!AllocSetCheck(MemoryContextData *
> context=0x02c455b8)  Line 1142 + 0x11 bytes	C
>  	postgres.exe!AllocSetReset(MemoryContextData *
> context=0x02c455b8)  Line 409 + 0x9 bytes	C
>  	postgres.exe!MemoryContextReset(MemoryContextData *
> context=0x02c455b8)  Line 129 + 0xf bytes	C
>  	postgres.exe!ExecScan(ScanState * node=0x02c227d0, 
> TupleTableSlot * (ScanState *)* accessMtd=0x00530b70)  Line 91 + 0xc
> bytes	C
>  	postgres.exe!ExecSeqScan(ScanState * node=0x02c227d0)  Line 130
> + 0xe bytes	C
>  	postgres.exe!ExecProcNode(PlanState * node=0x02c227d0)  Line 349
> + 0x9 bytes	C
>  	postgres.exe!ExecutePlan(EState * estate=0x02c223e8, 
> PlanState * planstate=0x02c227d0, CmdType 
> operation=CMD_UPDATE, long numberTuples=0, ScanDirection 
> direction=ForwardScanDirection, _DestReceiver *
> dest=0x02bf8d30)  Line 1081 + 0x9 bytes	C
>  	postgres.exe!ExecutorRun(QueryDesc * 
> queryDesc=0x02c44078, ScanDirection 
> direction=ForwardScanDirection, long count=0)  Line 246 +
> 0x20 bytes	C
>  	postgres.exe!ProcessQuery(Query * parsetree=0x02bddab0, 
> Plan * plan=0x02bf7e28, ParamListInfoData * 
> params=0x00000000, _DestReceiver * dest=0x02bf8d30, char * 
> completionTag=0x00d4fb24)  Line 157 + 0xd bytes C
>  	postgres.exe!PortalRunMulti(PortalData * 
> portal=0x02c48138, _DestReceiver * dest=0x02bf8d30, 
> _DestReceiver * altdest=0x02bf8d30,
> char * completionTag=0x00d4fb24)  Line 1148 + 0x1c bytes	C
>  	postgres.exe!PortalRun(PortalData * portal=0x02c48138, 
> long count=2147483647, _DestReceiver * dest=0x02bf8d30, 
> _DestReceiver * altdest=0x02bf8d30, char * 
> completionTag=0x00d4fb24)  Line 700 + 0x15
> bytes	C
>  	postgres.exe!exec_simple_query(const char *
> query_string=0x02bdd4c8)  Line 943 + 0x23 bytes	C
>  	postgres.exe!PostgresMain(int argc=4, char * * argv=0x02ba2478,
> const char * username=0x025e7af8)  Line 3414 + 0xc bytes	C
>  	postgres.exe!BackendRun(Port * port=0x00d4fd2c)  Line 2853 +
> 0x17 bytes	C
>  	postgres.exe!SubPostmasterMain(int argc=3, char * *
> argv=0x025e5b30)  Line 3288 + 0xc bytes	C
>  	postgres.exe!main(int argc=3, char * * argv=0x025e5b30)  Line
> 165 + 0xd bytes	C
> 
> 
> 
> 
> Can someone point me towards what next to check? :-)
> 
> Oh, and per Thomas, this does NOT appear to happen in C 
> locale, but happens in both de_CH and en_US. ANd I've tested 
> in Swedish_Sweden, which also crashes.
> 
> Note that this appears not to be index related at all, 
> because during this test there is only a standard btree index 
> on "someint", and nothing on the tsvector column.
> 
> //Magnus
> 
> 
> > -----Original Message-----
> > From: pgsql-bugs-owner@postgresql.org 
> > [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of Thomas H.
> > Sent: den 12 november 2006 15:06
> > To: pgsql-bugs@postgresql.org
> > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> > 
> > this bug (please see below) is unfortunately still present in
> > beta3 (win32 build). test case still crashes the child process and 
> > lets postmaster kill & reload everything.
> > 
> > it is not GiST-related, i've just validated the same problem using 
> > GIN.
> > 
> > this breaks tsearch2 functionality on our win32 system as no 
> > tsvector-indexing of new/existing rows is possible (crash after ~10 
> > processed rows). searching already indexed rows works fine.
> > 
> > best regards,
> > thomas
> > 
> > ----- Original Message -----
> > From: <me@alternize.com>
> > To: "Tom Lane" <tgl@sss.pgh.pa.us>
> > Cc: <pgsql-bugs@postgresql.org>
> > Sent: Tuesday, October 17, 2006 9:19 PM
> > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> > 
> > 
> > >>> the following query will crash the server process:
> > >>> INSERT INTO news.news
> > >>> SELECT * FROM news.news2;
> > >>
> > >> This is undoubtedly data-dependent.  Can you supply some
> > sample data
> > >> that makes it happen?
> > >
> > > it's not only happening with INSERTS, but also updates. as
> > thats easier to
> > > test, here's how i can reproduce the error:
> > >
> > > 1. create new database (encoding: UTF8) with tsearch2 on
> > 8.2b1 win32
> > > (system
> > > locale: de_CH.1252)
> > > 2. insert the data from the zip file 
> > > [http://alternize.com/pgsql/tsearch2test.zip] (be sure to
> > also update
> > > pg_ts_cf /
> > > pg_ts_cfgmap as we have WIN1252 locale) 3. execute UPDATE 
> test SET 
> > > idxFTI = to_tsvector('default',
> > "sometext"); or
> > > similar queries
> > > 4. hopefully see the process crashing as i do ;-)
> > >
> > >
> > > 2006-10-17 17:23:44 LOG:  server process (PID 4584) 
> exited with exit 
> > > code -1073741819
> > > 2006-10-17 17:23:44 LOG:  terminating any other active
> > server processes
> > > 2006-10-17 17:23:44 WARNING:  terminating connection
> > because of crash of
> > > another server process
> > > 2006-10-17 17:23:44 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.
> > > {snipp}
> > > 2006-10-17 17:23:44 LOG:  all server processes terminated;
> > reinitializing
> > > 2006-10-17 17:23:44 LOG:  database system was interrupted
> > at 2006-10-17
> > > 17:23:41 W. Europe Daylight Time
> > > 2006-10-17 17:23:44 LOG:  Windows
> > fopen("recovery.conf","r") failed: code
> > > 2,
> > > errno 2
> > > 2006-10-17 17:23:44 LOG:  Windows
> > fopen("pg_xlog/00000001.history","r")
> > > failed: code 2, errno 2
> > > 2006-10-17 17:23:44 LOG:  Windows fopen("backup_label","r")
> > failed: code
> > > 2,
> > > errno 2
> > > 2006-10-17 17:23:44 LOG:  checkpoint record is at 0/E2ECA728
> > > 2006-10-17 17:23:44 LOG:  redo record is at 0/E2ECA728;
> > undo record is at
> > > 0/0; shutdown FALSE
> > > 2006-10-17 17:23:44 LOG:  next transaction ID: 0/514299;
> > next OID: 6276957
> > > 2006-10-17 17:23:44 LOG:  next MultiXactId: 1; next
> > MultiXactOffset: 0
> > > 2006-10-17 17:23:44 LOG:  database system was not properly
> > shut down;
> > > automatic recovery in progress
> > > 2006-10-17 17:23:44 LOG:  redo starts at 0/E2ECA778
> > > 2006-10-17 17:23:44 LOG:  unexpected pageaddr 0/DB0CC000 in
> > log file 0,
> > > segment 227, offset 835584
> > > 2006-10-17 17:23:44 LOG:  redo done at 0/E30CBE78
> > > 2006-10-17 17:23:45 LOG:  database system is ready
> > > 2006-10-17 17:23:45 LOG:  Windows 
> fopen("global/pg_fsm.cache","rb")
> > > failed:
> > > code 2, errno 2
> > > 2006-10-17 17:23:45 LOG:  transaction ID wrap limit is
> > 2147484172, limited
> > > by database "postgres"
> > > 2006-10-17 17:23:45 LOG:  Windows
> > fopen("global/pgstat.stat","rb") failed:
> > > code 2, errno 2
> > >
> > >
> > > i've also tried to update each record on its own in a
> > for-loop. here the
> > > crash happens as well, sometimes after 10 updates,
> > sometimes after 100
> > > updates, sometimes even after 1 update. but eventually
> > every record can be
> > > updated. so i do not think its entierly content-related...
> > >
> > > for what its worth, here's the output of pg_controldata:
> > >
> > > pg_control version number:            822
> > > Catalog version number:               200609181
> > > Database system identifier:           4986650172201464825
> > > Database cluster state:               in production
> > > pg_control last modified:             17.10.2006 17:44:29
> > > Current log file ID:                  0
> > > Next log file segment:                230
> > > Latest checkpoint location:           0/E4E0F978
> > > Prior checkpoint location:            0/E46BF420
> > > Latest checkpoint's REDO location:    0/E4E03098
> > > Latest checkpoint's UNDO location:    0/0
> > > Latest checkpoint's TimeLineID:       1
> > > Latest checkpoint's NextXID:          0/531333
> > > Latest checkpoint's NextOID:          6285149
> > > Latest checkpoint's NextMultiXactId:  1 Latest checkpoint's 
> > > NextMultiOffset:  0
> > > Time of latest checkpoint:            17.10.2006 17:43:45
> > > Minimum recovery ending location:     0/0
> > > Maximum data alignment:               8
> > > Database block size:                  8192
> > > Blocks per segment of large relation: 131072
> > > WAL block size:                       8192
> > > Bytes per WAL segment:                16777216
> > > Maximum length of identifiers:        64
> > > Maximum columns in an index:          32
> > > Date/time type storage:               floating-point numbers
> > > Maximum length of locale name:        128
> > > LC_COLLATE:                           German_Switzerland.1252
> > > LC_CTYPE:                             German_Switzerland.1252
> > >
> > > let me know if more information / data is needed.
> > >
> > > on a sidenote: are those fopen() errors
> > debug-code-leftovers or something
> > > one should worry about? i can't find those files on the 
> file system.
> > >
> > > - thomas
> > >
> > >
> > > ---------------------------(end of
> > broadcast)---------------------------
> > > TIP 4: Have you searched our list archives?
> > >
> > >               http://archives.postgresql.org
> > > 
> > 
> > 
> > 
> > ---------------------------(end of
> > broadcast)---------------------------
> > TIP 6: explain analyze is your friend
> > 
> 
> ---------------------------(end of 
> broadcast)---------------------------
> TIP 3: Have you checked our extensive FAQ?
> 
>                http://www.postgresql.org/docs/faq
>

Re: 8.2beta1 (w32): server process crash (tsvector)

Magnus Hagander <mha@sollentuna.net> — 2006-11-13T09:36:19Z

Did yet some more stuff, mainly in line of shotgun-debugging :-)

If I add a "return NULL" right before:
				res = (TSLexeme *)
DatumGetPointer(FunctionCall4(
	
&(dict->lexize_info),
	
PointerGetDatum(dict->dictionary),
	
PointerGetDatum(curVal->lemm),
	
Int32GetDatum(curVal->lenlemm),
	
PointerGetDatum(&ld->dictState)
	
));
in LexizeExec(), I get no crash and NULL values for all tsvectors.
If I add it right *after* that line, I get a crash. But I don't get the
warnings about overwriting.

Not entirely sure how much that helps. Don't have time to dig in more
right htis minute, but I'd definitly appreciate some pointers into what
to look at next.

//Magnus

> -----Original Message-----
> From: pgsql-bugs-owner@postgresql.org 
> [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of Magnus Hagander
> Sent: den 13 november 2006 10:01
> To: Thomas H.; pgsql-bugs@postgresql.org
> Cc: Tom Lane
> Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> 
> Did some more tests, and it's even easier to repro this. No 
> need to update, just SELECT to_tsvector('default',sometext) from test;
> 
> It appears to be data dependent still, though, because just 
> running SELECT to_tsvector('default','foo bar foo bar foo bar 
> foo bar')
> fromgenerate_series(1,1000000) works withuot a hitch.
> 
> 
> Also, the "detected write past chunk end" comes from the 
> pfree() in tsvector.c, function unqiueWORD() line 656. At 
> this point, "ptr->word"
> points at the text "temp" followed by a bunch of junk. The 
> callstack leading up to this is:
>  	postgres.exe!AllocSetFree(MemoryContextData *
> context=0x02c37bd8, void * pointer=0x02c65ed0)  Line 775	C
>  	postgres.exe!pfree(void * pointer=0x02c65ed0)  Line 585 + 0x17
> bytes	C
>  	tsearch2.dll!uniqueWORD(TSWORD * a=0x02c66e60, int l=517)  Line
> 656 + 0xc bytes	C
>  	tsearch2.dll!makevalue(PRSTEXT * prs=0x00d4f44c)  Line 692 +
> 0x12 bytes	C
>  	tsearch2.dll!to_tsvector(FunctionCallInfoData *
> fcinfo=0x00d4f46c)  Line 764 + 0x9 bytes	C
>  	postgres.exe!DirectFunctionCall3(unsigned long 
> (FunctionCallInfoData *)* func=0x02cd1131, unsigned long 
> arg1=16473, unsigned long arg2=49941724, unsigned long 
> arg3=0)  Line 905 + 0xa bytes C
>  	tsearch2.dll!to_tsvector_name(FunctionCallInfoData *
> fcinfo=0x00d4f6b0)  Line 787 + 0x20 bytes	C
> 
> 
> Now, the parametsrs to to_tsvector() looks weird - the "text 
> *in = PG_GETARG_TEXT_P(1)" appears to return a struct with 
> vl_len set t 2139062143, which seems. Eh. Wrong? :) But this 
> does not happen on the
> *first* call to to_tsquery() which shows a proper text, but 
> subsequent calls show what lokos like garbage a couple of 
> times, and then the WARNING about the write past end fires.
> 
> //Magnus 
> 
> > -----Original Message-----
> > From: pgsql-bugs-owner@postgresql.org 
> > [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of 
> Magnus Hagander
> > Sent: den 12 november 2006 17:06
> > To: Thomas H.; pgsql-bugs@postgresql.org
> > Cc: Tom Lane
> > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> > 
> > Ok, I've run this test on an assert enabled build (my msvc build, 
> > actually, so I could get a debugger on it if needed).
> > It then outputs:
> > 
> > WARNING:  detected write past chunk end in ExprContext 02C6D0F8
> > WARNING:  detected write past chunk end in ExprContext 02C6AEA0
> > WARNING:  detected write past chunk end in ExprContext 02C6B200
> > WARNING:  detected write past chunk end in ExprContext 02C44630
> > WARNING:  detected write past chunk end in ExprContext 02C4C118
> > WARNING:  problem in alloc set ExprContext: bogus aset link 
> in block 
> > 02C435A8, c hunk 02C44520
> > WARNING:  detected write past chunk end in ExprContext 02C66440
> > WARNING:  detected write past chunk end in ExprContext 02C3B9D0
> > WARNING:  detected write past chunk end in ExprContext 02C3BDE8
> > WARNING:  detected write past chunk end in ExprContext 02C4E7E0
> > WARNING:  detected write past chunk end in ExprContext 02C47508
> > WARNING:  problem in alloc set ExprContext: bogus aset link 
> in block 
> > 02C435A8, c hunk 02C47528
> > WARNING:  detected write past chunk end in ExprContext 02C43800
> > WARNING:  detected write past chunk end in ExprContext 02C66C90
> > WARNING:  detected write past chunk end in ExprContext 02C68270
> > WARNING:  detected write past chunk end in ExprContext 02C4F5D8
> > WARNING:  problem in alloc set ExprContext: bogus aset link 
> in block 
> > 02C4E6F8, c hunk 02C4F5F8
> > WARNING:  detected write past chunk end in ExprContext 02C7B680
> > WARNING:  detected write past chunk end in ExprContext 02C45190
> > WARNING:  detected write past chunk end in ExprContext 02C46AC8
> > WARNING:  detected write past chunk end in ExprContext 02C3C538
> > WARNING:  detected write past chunk end in ExprContext 02C67B90
> > WARNING:  detected write past chunk end in ExprContext 02C438F0
> > WARNING:  problem in alloc set ExprContext: bad single-chunk
> > 02C43FB8 in block 0
> > 2C435A8
> > WARNING:  problem in alloc set ExprContext: bogus aset link 
> in block 
> > 02C435A8, c hunk 02C43FB8 server closed the connection unexpectedly
> >         This probably means the server terminated abnormally
> >         before or while processing the request. 
> > 
> > 
> > 
> > 
> > The actual crash happens on line 1142 of AllocSetCheck. 
> Full callstack
> > is:
> > >	postgres.exe!AllocSetCheck(MemoryContextData *
> > context=0x02c455b8)  Line 1142 + 0x11 bytes	C
> >  	postgres.exe!AllocSetReset(MemoryContextData *
> > context=0x02c455b8)  Line 409 + 0x9 bytes	C
> >  	postgres.exe!MemoryContextReset(MemoryContextData *
> > context=0x02c455b8)  Line 129 + 0xf bytes	C
> >  	postgres.exe!ExecScan(ScanState * node=0x02c227d0, 
> TupleTableSlot * 
> > (ScanState *)* accessMtd=0x00530b70)  Line 91 + 0xc
> > bytes	C
> >  	postgres.exe!ExecSeqScan(ScanState * node=0x02c227d0)  Line 130
> > + 0xe bytes	C
> >  	postgres.exe!ExecProcNode(PlanState * node=0x02c227d0)  Line 349
> > + 0x9 bytes	C
> >  	postgres.exe!ExecutePlan(EState * estate=0x02c223e8, 
> PlanState * 
> > planstate=0x02c227d0, CmdType operation=CMD_UPDATE, long 
> > numberTuples=0, ScanDirection direction=ForwardScanDirection, 
> > _DestReceiver *
> > dest=0x02bf8d30)  Line 1081 + 0x9 bytes	C
> >  	postgres.exe!ExecutorRun(QueryDesc * queryDesc=0x02c44078, 
> > ScanDirection direction=ForwardScanDirection, long count=0) 
>  Line 246 
> > +
> > 0x20 bytes	C
> >  	postgres.exe!ProcessQuery(Query * parsetree=0x02bddab0, Plan * 
> > plan=0x02bf7e28, ParamListInfoData * params=0x00000000, 
> _DestReceiver 
> > * dest=0x02bf8d30, char *
> > completionTag=0x00d4fb24)  Line 157 + 0xd bytes C
> >  	postgres.exe!PortalRunMulti(PortalData * portal=0x02c48138, 
> > _DestReceiver * dest=0x02bf8d30, _DestReceiver * altdest=0x02bf8d30,
> > char * completionTag=0x00d4fb24)  Line 1148 + 0x1c bytes	C
> >  	postgres.exe!PortalRun(PortalData * portal=0x02c48138, long 
> > count=2147483647, _DestReceiver * dest=0x02bf8d30, _DestReceiver * 
> > altdest=0x02bf8d30, char *
> > completionTag=0x00d4fb24)  Line 700 + 0x15
> > bytes	C
> >  	postgres.exe!exec_simple_query(const char *
> > query_string=0x02bdd4c8)  Line 943 + 0x23 bytes	C
> >  	postgres.exe!PostgresMain(int argc=4, char * * argv=0x02ba2478,
> > const char * username=0x025e7af8)  Line 3414 + 0xc bytes	C
> >  	postgres.exe!BackendRun(Port * port=0x00d4fd2c)  Line 2853 +
> > 0x17 bytes	C
> >  	postgres.exe!SubPostmasterMain(int argc=3, char * *
> > argv=0x025e5b30)  Line 3288 + 0xc bytes	C
> >  	postgres.exe!main(int argc=3, char * * argv=0x025e5b30)  Line
> > 165 + 0xd bytes	C
> > 
> > 
> > 
> > 
> > Can someone point me towards what next to check? :-)
> > 
> > Oh, and per Thomas, this does NOT appear to happen in C locale, but 
> > happens in both de_CH and en_US. ANd I've tested in Swedish_Sweden, 
> > which also crashes.
> > 
> > Note that this appears not to be index related at all, 
> because during 
> > this test there is only a standard btree index on "someint", and 
> > nothing on the tsvector column.
> > 
> > //Magnus
> > 
> > 
> > > -----Original Message-----
> > > From: pgsql-bugs-owner@postgresql.org 
> > > [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of Thomas H.
> > > Sent: den 12 november 2006 15:06
> > > To: pgsql-bugs@postgresql.org
> > > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash 
> (tsvector)
> > > 
> > > this bug (please see below) is unfortunately still present in
> > > beta3 (win32 build). test case still crashes the child 
> process and 
> > > lets postmaster kill & reload everything.
> > > 
> > > it is not GiST-related, i've just validated the same 
> problem using 
> > > GIN.
> > > 
> > > this breaks tsearch2 functionality on our win32 system as no 
> > > tsvector-indexing of new/existing rows is possible (crash 
> after ~10 
> > > processed rows). searching already indexed rows works fine.
> > > 
> > > best regards,
> > > thomas
> > > 
> > > ----- Original Message -----
> > > From: <me@alternize.com>
> > > To: "Tom Lane" <tgl@sss.pgh.pa.us>
> > > Cc: <pgsql-bugs@postgresql.org>
> > > Sent: Tuesday, October 17, 2006 9:19 PM
> > > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash 
> (tsvector)
> > > 
> > > 
> > > >>> the following query will crash the server process:
> > > >>> INSERT INTO news.news
> > > >>> SELECT * FROM news.news2;
> > > >>
> > > >> This is undoubtedly data-dependent.  Can you supply some
> > > sample data
> > > >> that makes it happen?
> > > >
> > > > it's not only happening with INSERTS, but also updates. as
> > > thats easier to
> > > > test, here's how i can reproduce the error:
> > > >
> > > > 1. create new database (encoding: UTF8) with tsearch2 on
> > > 8.2b1 win32
> > > > (system
> > > > locale: de_CH.1252)
> > > > 2. insert the data from the zip file 
> > > > [http://alternize.com/pgsql/tsearch2test.zip] (be sure to
> > > also update
> > > > pg_ts_cf /
> > > > pg_ts_cfgmap as we have WIN1252 locale) 3. execute UPDATE
> > test SET
> > > > idxFTI = to_tsvector('default',
> > > "sometext"); or
> > > > similar queries
> > > > 4. hopefully see the process crashing as i do ;-)
> > > >
> > > >
> > > > 2006-10-17 17:23:44 LOG:  server process (PID 4584)
> > exited with exit
> > > > code -1073741819
> > > > 2006-10-17 17:23:44 LOG:  terminating any other active
> > > server processes
> > > > 2006-10-17 17:23:44 WARNING:  terminating connection
> > > because of crash of
> > > > another server process
> > > > 2006-10-17 17:23:44 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.
> > > > {snipp}
> > > > 2006-10-17 17:23:44 LOG:  all server processes terminated;
> > > reinitializing
> > > > 2006-10-17 17:23:44 LOG:  database system was interrupted
> > > at 2006-10-17
> > > > 17:23:41 W. Europe Daylight Time
> > > > 2006-10-17 17:23:44 LOG:  Windows
> > > fopen("recovery.conf","r") failed: code
> > > > 2,
> > > > errno 2
> > > > 2006-10-17 17:23:44 LOG:  Windows
> > > fopen("pg_xlog/00000001.history","r")
> > > > failed: code 2, errno 2
> > > > 2006-10-17 17:23:44 LOG:  Windows fopen("backup_label","r")
> > > failed: code
> > > > 2,
> > > > errno 2
> > > > 2006-10-17 17:23:44 LOG:  checkpoint record is at 0/E2ECA728
> > > > 2006-10-17 17:23:44 LOG:  redo record is at 0/E2ECA728;
> > > undo record is at
> > > > 0/0; shutdown FALSE
> > > > 2006-10-17 17:23:44 LOG:  next transaction ID: 0/514299;
> > > next OID: 6276957
> > > > 2006-10-17 17:23:44 LOG:  next MultiXactId: 1; next
> > > MultiXactOffset: 0
> > > > 2006-10-17 17:23:44 LOG:  database system was not properly
> > > shut down;
> > > > automatic recovery in progress
> > > > 2006-10-17 17:23:44 LOG:  redo starts at 0/E2ECA778
> > > > 2006-10-17 17:23:44 LOG:  unexpected pageaddr 0/DB0CC000 in
> > > log file 0,
> > > > segment 227, offset 835584
> > > > 2006-10-17 17:23:44 LOG:  redo done at 0/E30CBE78
> > > > 2006-10-17 17:23:45 LOG:  database system is ready
> > > > 2006-10-17 17:23:45 LOG:  Windows
> > fopen("global/pg_fsm.cache","rb")
> > > > failed:
> > > > code 2, errno 2
> > > > 2006-10-17 17:23:45 LOG:  transaction ID wrap limit is
> > > 2147484172, limited
> > > > by database "postgres"
> > > > 2006-10-17 17:23:45 LOG:  Windows
> > > fopen("global/pgstat.stat","rb") failed:
> > > > code 2, errno 2
> > > >
> > > >
> > > > i've also tried to update each record on its own in a
> > > for-loop. here the
> > > > crash happens as well, sometimes after 10 updates,
> > > sometimes after 100
> > > > updates, sometimes even after 1 update. but eventually
> > > every record can be
> > > > updated. so i do not think its entierly content-related...
> > > >
> > > > for what its worth, here's the output of pg_controldata:
> > > >
> > > > pg_control version number:            822
> > > > Catalog version number:               200609181
> > > > Database system identifier:           4986650172201464825
> > > > Database cluster state:               in production
> > > > pg_control last modified:             17.10.2006 17:44:29
> > > > Current log file ID:                  0
> > > > Next log file segment:                230
> > > > Latest checkpoint location:           0/E4E0F978
> > > > Prior checkpoint location:            0/E46BF420
> > > > Latest checkpoint's REDO location:    0/E4E03098
> > > > Latest checkpoint's UNDO location:    0/0
> > > > Latest checkpoint's TimeLineID:       1
> > > > Latest checkpoint's NextXID:          0/531333
> > > > Latest checkpoint's NextOID:          6285149
> > > > Latest checkpoint's NextMultiXactId:  1 Latest checkpoint's
> > > > NextMultiOffset:  0
> > > > Time of latest checkpoint:            17.10.2006 17:43:45
> > > > Minimum recovery ending location:     0/0
> > > > Maximum data alignment:               8
> > > > Database block size:                  8192
> > > > Blocks per segment of large relation: 131072
> > > > WAL block size:                       8192
> > > > Bytes per WAL segment:                16777216
> > > > Maximum length of identifiers:        64
> > > > Maximum columns in an index:          32
> > > > Date/time type storage:               floating-point numbers
> > > > Maximum length of locale name:        128
> > > > LC_COLLATE:                           German_Switzerland.1252
> > > > LC_CTYPE:                             German_Switzerland.1252
> > > >
> > > > let me know if more information / data is needed.
> > > >
> > > > on a sidenote: are those fopen() errors
> > > debug-code-leftovers or something
> > > > one should worry about? i can't find those files on the
> > file system.
> > > >
> > > > - thomas
> > > >
> > > >
> > > > ---------------------------(end of
> > > broadcast)---------------------------
> > > > TIP 4: Have you searched our list archives?
> > > >
> > > >               http://archives.postgresql.org
> > > > 
> > > 
> > > 
> > > 
> > > ---------------------------(end of
> > > broadcast)---------------------------
> > > TIP 6: explain analyze is your friend
> > > 
> > 
> > ---------------------------(end of
> > broadcast)---------------------------
> > TIP 3: Have you checked our extensive FAQ?
> > 
> >                http://www.postgresql.org/docs/faq
> > 
> 
> ---------------------------(end of 
> broadcast)---------------------------
> TIP 2: Don't 'kill -9' the postmaster
>

Re: 8.2beta1 (w32): server process crash (tsvector)

Magnus Hagander <mha@sollentuna.net> — 2006-11-16T14:49:20Z

Just wanted to let you know that working with Teodor I beleive we have
now found the cause for this bug, and I have a workaround that passes
your tests. I'm unsure if it's safe on != win32, so I'm deferring to
Teodor to come up with the final fix.

It's also possible that I spotted another problem with taht code that
might require slightly more code than a one-liner to fix. We'll know in
a while when Teodor has analyzed it completely.

//Magnus

> -----Original Message-----
> From: pgsql-bugs-owner@postgresql.org 
> [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of Magnus Hagander
> Sent: den 13 november 2006 10:36
> To: Thomas H.; pgsql-bugs@postgresql.org
> Cc: Tom Lane
> Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> 
> Did yet some more stuff, mainly in line of shotgun-debugging :-)
> 
> If I add a "return NULL" right before:
> 				res = (TSLexeme *)
> DatumGetPointer(FunctionCall4(
> 	
> &(dict->lexize_info),
> 	
> PointerGetDatum(dict->dictionary),
> 	
> PointerGetDatum(curVal->lemm),
> 	
> Int32GetDatum(curVal->lenlemm),
> 	
> PointerGetDatum(&ld->dictState)
> 	
> ));
> in LexizeExec(), I get no crash and NULL values for all tsvectors.
> If I add it right *after* that line, I get a crash. But I 
> don't get the warnings about overwriting.
> 
> Not entirely sure how much that helps. Don't have time to dig 
> in more right htis minute, but I'd definitly appreciate some 
> pointers into what to look at next.
> 
> //Magnus
> 
> > -----Original Message-----
> > From: pgsql-bugs-owner@postgresql.org 
> > [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of 
> Magnus Hagander
> > Sent: den 13 november 2006 10:01
> > To: Thomas H.; pgsql-bugs@postgresql.org
> > Cc: Tom Lane
> > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash (tsvector)
> > 
> > Did some more tests, and it's even easier to repro this. No need to 
> > update, just SELECT to_tsvector('default',sometext) from test;
> > 
> > It appears to be data dependent still, though, because just running 
> > SELECT to_tsvector('default','foo bar foo bar foo bar foo bar')
> > fromgenerate_series(1,1000000) works withuot a hitch.
> > 
> > 
> > Also, the "detected write past chunk end" comes from the 
> > pfree() in tsvector.c, function unqiueWORD() line 656. At 
> > this point, "ptr->word"
> > points at the text "temp" followed by a bunch of junk. The 
> > callstack leading up to this is:
> >  	postgres.exe!AllocSetFree(MemoryContextData *
> > context=0x02c37bd8, void * pointer=0x02c65ed0)  Line 775	C
> >  	postgres.exe!pfree(void * pointer=0x02c65ed0)  Line 585 + 0x17
> > bytes	C
> >  	tsearch2.dll!uniqueWORD(TSWORD * a=0x02c66e60, int l=517)  Line
> > 656 + 0xc bytes	C
> >  	tsearch2.dll!makevalue(PRSTEXT * prs=0x00d4f44c)  Line 692 +
> > 0x12 bytes	C
> >  	tsearch2.dll!to_tsvector(FunctionCallInfoData *
> > fcinfo=0x00d4f46c)  Line 764 + 0x9 bytes	C
> >  	postgres.exe!DirectFunctionCall3(unsigned long 
> > (FunctionCallInfoData *)* func=0x02cd1131, unsigned long 
> > arg1=16473, unsigned long arg2=49941724, unsigned long 
> > arg3=0)  Line 905 + 0xa bytes C
> >  	tsearch2.dll!to_tsvector_name(FunctionCallInfoData *
> > fcinfo=0x00d4f6b0)  Line 787 + 0x20 bytes	C
> > 
> > 
> > Now, the parametsrs to to_tsvector() looks weird - the "text 
> > *in = PG_GETARG_TEXT_P(1)" appears to return a struct with 
> > vl_len set t 2139062143, which seems. Eh. Wrong? :) But this 
> > does not happen on the
> > *first* call to to_tsquery() which shows a proper text, but 
> > subsequent calls show what lokos like garbage a couple of 
> > times, and then the WARNING about the write past end fires.
> > 
> > //Magnus 
> > 
> > > -----Original Message-----
> > > From: pgsql-bugs-owner@postgresql.org 
> > > [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of 
> > Magnus Hagander
> > > Sent: den 12 november 2006 17:06
> > > To: Thomas H.; pgsql-bugs@postgresql.org
> > > Cc: Tom Lane
> > > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash 
> (tsvector)
> > > 
> > > Ok, I've run this test on an assert enabled build (my msvc build, 
> > > actually, so I could get a debugger on it if needed).
> > > It then outputs:
> > > 
> > > WARNING:  detected write past chunk end in ExprContext 02C6D0F8
> > > WARNING:  detected write past chunk end in ExprContext 02C6AEA0
> > > WARNING:  detected write past chunk end in ExprContext 02C6B200
> > > WARNING:  detected write past chunk end in ExprContext 02C44630
> > > WARNING:  detected write past chunk end in ExprContext 02C4C118
> > > WARNING:  problem in alloc set ExprContext: bogus aset link 
> > in block 
> > > 02C435A8, c hunk 02C44520
> > > WARNING:  detected write past chunk end in ExprContext 02C66440
> > > WARNING:  detected write past chunk end in ExprContext 02C3B9D0
> > > WARNING:  detected write past chunk end in ExprContext 02C3BDE8
> > > WARNING:  detected write past chunk end in ExprContext 02C4E7E0
> > > WARNING:  detected write past chunk end in ExprContext 02C47508
> > > WARNING:  problem in alloc set ExprContext: bogus aset link 
> > in block 
> > > 02C435A8, c hunk 02C47528
> > > WARNING:  detected write past chunk end in ExprContext 02C43800
> > > WARNING:  detected write past chunk end in ExprContext 02C66C90
> > > WARNING:  detected write past chunk end in ExprContext 02C68270
> > > WARNING:  detected write past chunk end in ExprContext 02C4F5D8
> > > WARNING:  problem in alloc set ExprContext: bogus aset link 
> > in block 
> > > 02C4E6F8, c hunk 02C4F5F8
> > > WARNING:  detected write past chunk end in ExprContext 02C7B680
> > > WARNING:  detected write past chunk end in ExprContext 02C45190
> > > WARNING:  detected write past chunk end in ExprContext 02C46AC8
> > > WARNING:  detected write past chunk end in ExprContext 02C3C538
> > > WARNING:  detected write past chunk end in ExprContext 02C67B90
> > > WARNING:  detected write past chunk end in ExprContext 02C438F0
> > > WARNING:  problem in alloc set ExprContext: bad single-chunk
> > > 02C43FB8 in block 0
> > > 2C435A8
> > > WARNING:  problem in alloc set ExprContext: bogus aset link 
> > in block 
> > > 02C435A8, c hunk 02C43FB8 server closed the connection 
> unexpectedly
> > >         This probably means the server terminated abnormally
> > >         before or while processing the request. 
> > > 
> > > 
> > > 
> > > 
> > > The actual crash happens on line 1142 of AllocSetCheck. 
> > Full callstack
> > > is:
> > > >	postgres.exe!AllocSetCheck(MemoryContextData *
> > > context=0x02c455b8)  Line 1142 + 0x11 bytes	C
> > >  	postgres.exe!AllocSetReset(MemoryContextData *
> > > context=0x02c455b8)  Line 409 + 0x9 bytes	C
> > >  	postgres.exe!MemoryContextReset(MemoryContextData *
> > > context=0x02c455b8)  Line 129 + 0xf bytes	C
> > >  	postgres.exe!ExecScan(ScanState * node=0x02c227d0, 
> > TupleTableSlot * 
> > > (ScanState *)* accessMtd=0x00530b70)  Line 91 + 0xc
> > > bytes	C
> > >  	postgres.exe!ExecSeqScan(ScanState * node=0x02c227d0)  Line 130
> > > + 0xe bytes	C
> > >  	postgres.exe!ExecProcNode(PlanState * node=0x02c227d0)  Line 349
> > > + 0x9 bytes	C
> > >  	postgres.exe!ExecutePlan(EState * estate=0x02c223e8, 
> > PlanState * 
> > > planstate=0x02c227d0, CmdType operation=CMD_UPDATE, long 
> > > numberTuples=0, ScanDirection direction=ForwardScanDirection, 
> > > _DestReceiver *
> > > dest=0x02bf8d30)  Line 1081 + 0x9 bytes	C
> > >  	postgres.exe!ExecutorRun(QueryDesc * queryDesc=0x02c44078, 
> > > ScanDirection direction=ForwardScanDirection, long count=0) 
> >  Line 246 
> > > +
> > > 0x20 bytes	C
> > >  	postgres.exe!ProcessQuery(Query * parsetree=0x02bddab0, Plan * 
> > > plan=0x02bf7e28, ParamListInfoData * params=0x00000000, 
> > _DestReceiver 
> > > * dest=0x02bf8d30, char *
> > > completionTag=0x00d4fb24)  Line 157 + 0xd bytes C
> > >  	postgres.exe!PortalRunMulti(PortalData * portal=0x02c48138, 
> > > _DestReceiver * dest=0x02bf8d30, _DestReceiver * 
> altdest=0x02bf8d30,
> > > char * completionTag=0x00d4fb24)  Line 1148 + 0x1c bytes	C
> > >  	postgres.exe!PortalRun(PortalData * portal=0x02c48138, long 
> > > count=2147483647, _DestReceiver * dest=0x02bf8d30, 
> _DestReceiver * 
> > > altdest=0x02bf8d30, char *
> > > completionTag=0x00d4fb24)  Line 700 + 0x15
> > > bytes	C
> > >  	postgres.exe!exec_simple_query(const char *
> > > query_string=0x02bdd4c8)  Line 943 + 0x23 bytes	C
> > >  	postgres.exe!PostgresMain(int argc=4, char * * argv=0x02ba2478,
> > > const char * username=0x025e7af8)  Line 3414 + 0xc bytes	C
> > >  	postgres.exe!BackendRun(Port * port=0x00d4fd2c)  Line 2853 +
> > > 0x17 bytes	C
> > >  	postgres.exe!SubPostmasterMain(int argc=3, char * *
> > > argv=0x025e5b30)  Line 3288 + 0xc bytes	C
> > >  	postgres.exe!main(int argc=3, char * * argv=0x025e5b30)  Line
> > > 165 + 0xd bytes	C
> > > 
> > > 
> > > 
> > > 
> > > Can someone point me towards what next to check? :-)
> > > 
> > > Oh, and per Thomas, this does NOT appear to happen in C 
> locale, but 
> > > happens in both de_CH and en_US. ANd I've tested in 
> Swedish_Sweden, 
> > > which also crashes.
> > > 
> > > Note that this appears not to be index related at all, 
> > because during 
> > > this test there is only a standard btree index on "someint", and 
> > > nothing on the tsvector column.
> > > 
> > > //Magnus
> > > 
> > > 
> > > > -----Original Message-----
> > > > From: pgsql-bugs-owner@postgresql.org 
> > > > [mailto:pgsql-bugs-owner@postgresql.org] On Behalf Of Thomas H.
> > > > Sent: den 12 november 2006 15:06
> > > > To: pgsql-bugs@postgresql.org
> > > > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash 
> > (tsvector)
> > > > 
> > > > this bug (please see below) is unfortunately still present in
> > > > beta3 (win32 build). test case still crashes the child 
> > process and 
> > > > lets postmaster kill & reload everything.
> > > > 
> > > > it is not GiST-related, i've just validated the same 
> > problem using 
> > > > GIN.
> > > > 
> > > > this breaks tsearch2 functionality on our win32 system as no 
> > > > tsvector-indexing of new/existing rows is possible (crash 
> > after ~10 
> > > > processed rows). searching already indexed rows works fine.
> > > > 
> > > > best regards,
> > > > thomas
> > > > 
> > > > ----- Original Message -----
> > > > From: <me@alternize.com>
> > > > To: "Tom Lane" <tgl@sss.pgh.pa.us>
> > > > Cc: <pgsql-bugs@postgresql.org>
> > > > Sent: Tuesday, October 17, 2006 9:19 PM
> > > > Subject: Re: [BUGS] 8.2beta1 (w32): server process crash 
> > (tsvector)
> > > > 
> > > > 
> > > > >>> the following query will crash the server process:
> > > > >>> INSERT INTO news.news
> > > > >>> SELECT * FROM news.news2;
> > > > >>
> > > > >> This is undoubtedly data-dependent.  Can you supply some
> > > > sample data
> > > > >> that makes it happen?
> > > > >
> > > > > it's not only happening with INSERTS, but also updates. as
> > > > thats easier to
> > > > > test, here's how i can reproduce the error:
> > > > >
> > > > > 1. create new database (encoding: UTF8) with tsearch2 on
> > > > 8.2b1 win32
> > > > > (system
> > > > > locale: de_CH.1252)
> > > > > 2. insert the data from the zip file 
> > > > > [http://alternize.com/pgsql/tsearch2test.zip] (be sure to
> > > > also update
> > > > > pg_ts_cf /
> > > > > pg_ts_cfgmap as we have WIN1252 locale) 3. execute UPDATE
> > > test SET
> > > > > idxFTI = to_tsvector('default',
> > > > "sometext"); or
> > > > > similar queries
> > > > > 4. hopefully see the process crashing as i do ;-)
> > > > >
> > > > >
> > > > > 2006-10-17 17:23:44 LOG:  server process (PID 4584)
> > > exited with exit
> > > > > code -1073741819
> > > > > 2006-10-17 17:23:44 LOG:  terminating any other active
> > > > server processes
> > > > > 2006-10-17 17:23:44 WARNING:  terminating connection
> > > > because of crash of
> > > > > another server process
> > > > > 2006-10-17 17:23:44 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.
> > > > > {snipp}
> > > > > 2006-10-17 17:23:44 LOG:  all server processes terminated;
> > > > reinitializing
> > > > > 2006-10-17 17:23:44 LOG:  database system was interrupted
> > > > at 2006-10-17
> > > > > 17:23:41 W. Europe Daylight Time
> > > > > 2006-10-17 17:23:44 LOG:  Windows
> > > > fopen("recovery.conf","r") failed: code
> > > > > 2,
> > > > > errno 2
> > > > > 2006-10-17 17:23:44 LOG:  Windows
> > > > fopen("pg_xlog/00000001.history","r")
> > > > > failed: code 2, errno 2
> > > > > 2006-10-17 17:23:44 LOG:  Windows fopen("backup_label","r")
> > > > failed: code
> > > > > 2,
> > > > > errno 2
> > > > > 2006-10-17 17:23:44 LOG:  checkpoint record is at 0/E2ECA728
> > > > > 2006-10-17 17:23:44 LOG:  redo record is at 0/E2ECA728;
> > > > undo record is at
> > > > > 0/0; shutdown FALSE
> > > > > 2006-10-17 17:23:44 LOG:  next transaction ID: 0/514299;
> > > > next OID: 6276957
> > > > > 2006-10-17 17:23:44 LOG:  next MultiXactId: 1; next
> > > > MultiXactOffset: 0
> > > > > 2006-10-17 17:23:44 LOG:  database system was not properly
> > > > shut down;
> > > > > automatic recovery in progress
> > > > > 2006-10-17 17:23:44 LOG:  redo starts at 0/E2ECA778
> > > > > 2006-10-17 17:23:44 LOG:  unexpected pageaddr 0/DB0CC000 in
> > > > log file 0,
> > > > > segment 227, offset 835584
> > > > > 2006-10-17 17:23:44 LOG:  redo done at 0/E30CBE78
> > > > > 2006-10-17 17:23:45 LOG:  database system is ready
> > > > > 2006-10-17 17:23:45 LOG:  Windows
> > > fopen("global/pg_fsm.cache","rb")
> > > > > failed:
> > > > > code 2, errno 2
> > > > > 2006-10-17 17:23:45 LOG:  transaction ID wrap limit is
> > > > 2147484172, limited
> > > > > by database "postgres"
> > > > > 2006-10-17 17:23:45 LOG:  Windows
> > > > fopen("global/pgstat.stat","rb") failed:
> > > > > code 2, errno 2
> > > > >
> > > > >
> > > > > i've also tried to update each record on its own in a
> > > > for-loop. here the
> > > > > crash happens as well, sometimes after 10 updates,
> > > > sometimes after 100
> > > > > updates, sometimes even after 1 update. but eventually
> > > > every record can be
> > > > > updated. so i do not think its entierly content-related...
> > > > >
> > > > > for what its worth, here's the output of pg_controldata:
> > > > >
> > > > > pg_control version number:            822
> > > > > Catalog version number:               200609181
> > > > > Database system identifier:           4986650172201464825
> > > > > Database cluster state:               in production
> > > > > pg_control last modified:             17.10.2006 17:44:29
> > > > > Current log file ID:                  0
> > > > > Next log file segment:                230
> > > > > Latest checkpoint location:           0/E4E0F978
> > > > > Prior checkpoint location:            0/E46BF420
> > > > > Latest checkpoint's REDO location:    0/E4E03098
> > > > > Latest checkpoint's UNDO location:    0/0
> > > > > Latest checkpoint's TimeLineID:       1
> > > > > Latest checkpoint's NextXID:          0/531333
> > > > > Latest checkpoint's NextOID:          6285149
> > > > > Latest checkpoint's NextMultiXactId:  1 Latest checkpoint's
> > > > > NextMultiOffset:  0
> > > > > Time of latest checkpoint:            17.10.2006 17:43:45
> > > > > Minimum recovery ending location:     0/0
> > > > > Maximum data alignment:               8
> > > > > Database block size:                  8192
> > > > > Blocks per segment of large relation: 131072
> > > > > WAL block size:                       8192
> > > > > Bytes per WAL segment:                16777216
> > > > > Maximum length of identifiers:        64
> > > > > Maximum columns in an index:          32
> > > > > Date/time type storage:               floating-point numbers
> > > > > Maximum length of locale name:        128
> > > > > LC_COLLATE:                           German_Switzerland.1252
> > > > > LC_CTYPE:                             German_Switzerland.1252
> > > > >
> > > > > let me know if more information / data is needed.
> > > > >
> > > > > on a sidenote: are those fopen() errors
> > > > debug-code-leftovers or something
> > > > > one should worry about? i can't find those files on the
> > > file system.
> > > > >
> > > > > - thomas
> > > > >
> > > > >
> > > > > ---------------------------(end of
> > > > broadcast)---------------------------
> > > > > TIP 4: Have you searched our list archives?
> > > > >
> > > > >               http://archives.postgresql.org
> > > > > 
> > > > 
> > > > 
> > > > 
> > > > ---------------------------(end of
> > > > broadcast)---------------------------
> > > > TIP 6: explain analyze is your friend
> > > > 
> > > 
> > > ---------------------------(end of
> > > broadcast)---------------------------
> > > TIP 3: Have you checked our extensive FAQ?
> > > 
> > >                http://www.postgresql.org/docs/faq
> > > 
> > 
> > ---------------------------(end of 
> > broadcast)---------------------------
> > TIP 2: Don't 'kill -9' the postmaster
> > 
> 
> ---------------------------(end of 
> broadcast)---------------------------
> TIP 7: You can help support the PostgreSQL project by donating at
> 
>                 http://www.postgresql.org/about/donate
>