Обсуждение: Can't Figure Out Where Rows Are Going
Hello,
I am running 8.1.3, built from source, on RHEL4/x64.
I have a Web application that uses this database to sell products. We have
an order table and an order lines table with a one to many relationship
between them.
For the past few months I have had a strange problem where sometimes (about
2% of orders), the line item rows disappear. By disappear I mean that they
are committed to the database and then when I go to look at the order later,
there are no line items. The row in the 'order' table still exists, it is
just the line(s) that vanish.
As I started looking into this problem I assumed that it was a bug in my Web
application. I did some extensive testing and logging to no avail. I turned
up the logging on my Web app and I can see the INSERTs but I never saw any
DELETE statements though I can't find the child row(s) in the DB.
I've been perplexed for quite some time so a few days ago I turned on the
following PG logging:
log_statement = 'mod'
Today, I found an order that has this problem. Grepping my serverlog, I see
the following:
The line item is inserted:
serverlog:LOG: statement: INSERT INTO order_lines ("order_description",
"order_id", "updated_at", "band_name", "order_item", "product_id",
"line_source", "order_quantity", "extended_price", "unit_price",
"catalog_number", "created_at") VALUES('FW "Not My Pres" Trucker Hat',
16899, '2006-05-06 14:43:38', NULL, 'Baseball Cap ', 165, 'Merch', 1, NULL,
7.0, 94, '2006-05-06 14:43:38')
Then, I do a SELECT:
fw_production=# SELECT COUNT(*) FROM order_lines WHERE order_id = 16899;
count
-------
0
There was about 3 hours between when the line was inserted and when I went
to look for it. There is no DELETE in the serverlog for this row.
I can't figure out where this row went and why it disappeared! Is it getting
deleted some other way that wouldn't be logged? Am I missing something
rudimentary?
Any help is appreciated.
Hunter
Just to be sure....
Any error msg in log?
Maybe you can run this query in psql and see if it return any error msg
Best regards
Rodrigo
HH wrote:
> Hello,
>
> I am running 8.1.3, built from source, on RHEL4/x64.
>
> I have a Web application that uses this database to sell products. We have
> an order table and an order lines table with a one to many relationship
> between them.
>
> For the past few months I have had a strange problem where sometimes (about
> 2% of orders), the line item rows disappear. By disappear I mean that they
> are committed to the database and then when I go to look at the order later,
> there are no line items. The row in the 'order' table still exists, it is
> just the line(s) that vanish.
>
> As I started looking into this problem I assumed that it was a bug in my Web
> application. I did some extensive testing and logging to no avail. I turned
> up the logging on my Web app and I can see the INSERTs but I never saw any
> DELETE statements though I can't find the child row(s) in the DB.
>
> I've been perplexed for quite some time so a few days ago I turned on the
> following PG logging:
>
> log_statement = 'mod'
>
> Today, I found an order that has this problem. Grepping my serverlog, I see
> the following:
>
> The line item is inserted:
>
> serverlog:LOG: statement: INSERT INTO order_lines ("order_description",
> "order_id", "updated_at", "band_name", "order_item", "product_id",
> "line_source", "order_quantity", "extended_price", "unit_price",
> "catalog_number", "created_at") VALUES('FW "Not My Pres" Trucker Hat',
> 16899, '2006-05-06 14:43:38', NULL, 'Baseball Cap ', 165, 'Merch', 1, NULL,
> 7.0, 94, '2006-05-06 14:43:38')
>
> Then, I do a SELECT:
>
> fw_production=# SELECT COUNT(*) FROM order_lines WHERE order_id = 16899;
> count
> -------
> 0
>
> There was about 3 hours between when the line was inserted and when I went
> to look for it. There is no DELETE in the serverlog for this row.
>
> I can't figure out where this row went and why it disappeared! Is it getting
> deleted some other way that wouldn't be logged? Am I missing something
> rudimentary?
>
> Any help is appreciated.
>
> Hunter
>
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 9: In versions below 8.0, the planner will ignore your desire to
> choose an index scan if your joining column's datatypes do not
> match
>
>
Is there an chance the rows are being inserted in a transaction that
fails and rolls back? Maybe look at all the lines that were inserted
with that order, and try them manually in psql, character for character,
and see if an error pops up for any of the lines?
Terry Fielder
terry@greatgulfhomes.com
Associate Director Software Development and Deployment
Great Gulf Homes / Ashton Woods Homes
Fax: (416) 441-9085
Rodrigo Gonzalez wrote:
> Just to be sure....
>
> Any error msg in log?
>
> Maybe you can run this query in psql and see if it return any error msg
>
> Best regards
>
> Rodrigo
>
> HH wrote:
>> Hello,
>>
>> I am running 8.1.3, built from source, on RHEL4/x64.
>>
>> I have a Web application that uses this database to sell products. We
>> have
>> an order table and an order lines table with a one to many relationship
>> between them.
>>
>> For the past few months I have had a strange problem where sometimes
>> (about
>> 2% of orders), the line item rows disappear. By disappear I mean that
>> they
>> are committed to the database and then when I go to look at the order
>> later,
>> there are no line items. The row in the 'order' table still exists,
>> it is
>> just the line(s) that vanish.
>>
>> As I started looking into this problem I assumed that it was a bug in
>> my Web
>> application. I did some extensive testing and logging to no avail. I
>> turned
>> up the logging on my Web app and I can see the INSERTs but I never
>> saw any
>> DELETE statements though I can't find the child row(s) in the DB.
>>
>> I've been perplexed for quite some time so a few days ago I turned on
>> the
>> following PG logging:
>>
>> log_statement = 'mod'
>>
>> Today, I found an order that has this problem. Grepping my serverlog,
>> I see
>> the following:
>>
>> The line item is inserted:
>>
>> serverlog:LOG: statement: INSERT INTO order_lines ("order_description",
>> "order_id", "updated_at", "band_name", "order_item", "product_id",
>> "line_source", "order_quantity", "extended_price", "unit_price",
>> "catalog_number", "created_at") VALUES('FW "Not My Pres" Trucker Hat',
>> 16899, '2006-05-06 14:43:38', NULL, 'Baseball Cap ', 165, 'Merch', 1,
>> NULL,
>> 7.0, 94, '2006-05-06 14:43:38')
>>
>> Then, I do a SELECT:
>>
>> fw_production=# SELECT COUNT(*) FROM order_lines WHERE order_id = 16899;
>> count -------
>> 0
>>
>> There was about 3 hours between when the line was inserted and when I
>> went
>> to look for it. There is no DELETE in the serverlog for this row.
>>
>> I can't figure out where this row went and why it disappeared! Is it
>> getting
>> deleted some other way that wouldn't be logged? Am I missing something
>> rudimentary?
>>
>> Any help is appreciated.
>>
>> Hunter
>>
>>
>>
>> ---------------------------(end of broadcast)---------------------------
>> TIP 9: In versions below 8.0, the planner will ignore your desire to
>> choose an index scan if your joining column's datatypes do not
>> match
>>
>>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 5: don't forget to increase your free space map settings
>
Thanks for replying.
The only logfile I have is the 'serverlog' file that I have. Looking at that
file, I don't see any indications that there was an error.
The INSERT does return successfully in psql.
Any other possibilities?
> From: Rodrigo Gonzalez <rjgonzale@gmail.com>
> Date: Sat, 06 May 2006 20:33:29 -0300
> To: HH <lists@lastonepicked.com>
> Cc: PostgreSQL <pgsql-general@postgresql.org>
> Subject: Re: [GENERAL] Can't Figure Out Where Rows Are Going
>
> Just to be sure....
>
> Any error msg in log?
>
> Maybe you can run this query in psql and see if it return any error msg
>
> Best regards
>
> Rodrigo
>
> HH wrote:
>> Hello,
>>
>> I am running 8.1.3, built from source, on RHEL4/x64.
>>
>> I have a Web application that uses this database to sell products. We have
>> an order table and an order lines table with a one to many relationship
>> between them.
>>
>> For the past few months I have had a strange problem where sometimes (about
>> 2% of orders), the line item rows disappear. By disappear I mean that they
>> are committed to the database and then when I go to look at the order later,
>> there are no line items. The row in the 'order' table still exists, it is
>> just the line(s) that vanish.
>>
>> As I started looking into this problem I assumed that it was a bug in my Web
>> application. I did some extensive testing and logging to no avail. I turned
>> up the logging on my Web app and I can see the INSERTs but I never saw any
>> DELETE statements though I can't find the child row(s) in the DB.
>>
>> I've been perplexed for quite some time so a few days ago I turned on the
>> following PG logging:
>>
>> log_statement = 'mod'
>>
>> Today, I found an order that has this problem. Grepping my serverlog, I see
>> the following:
>>
>> The line item is inserted:
>>
>> serverlog:LOG: statement: INSERT INTO order_lines ("order_description",
>> "order_id", "updated_at", "band_name", "order_item", "product_id",
>> "line_source", "order_quantity", "extended_price", "unit_price",
>> "catalog_number", "created_at") VALUES('FW "Not My Pres" Trucker Hat',
>> 16899, '2006-05-06 14:43:38', NULL, 'Baseball Cap ', 165, 'Merch', 1, NULL,
>> 7.0, 94, '2006-05-06 14:43:38')
>>
>> Then, I do a SELECT:
>>
>> fw_production=# SELECT COUNT(*) FROM order_lines WHERE order_id = 16899;
>> count
>> -------
>> 0
>>
>> There was about 3 hours between when the line was inserted and when I went
>> to look for it. There is no DELETE in the serverlog for this row.
>>
>> I can't figure out where this row went and why it disappeared! Is it getting
>> deleted some other way that wouldn't be logged? Am I missing something
>> rudimentary?
>>
>> Any help is appreciated.
>>
>> Hunter
>>
>>
>>
>> ---------------------------(end of broadcast)---------------------------
>> TIP 9: In versions below 8.0, the planner will ignore your desire to
>> choose an index scan if your joining column's datatypes do not
>> match
>>
>>
Thanks for taking the time to reply.
If that was occurring, would the log show it? I don't see any sign of a
roll-back occurring in the log and when I run the queries in psql, they seem
to complete properly.
> From: Terry Fielder <terry@ashtonwoodshomes.com>
> Date: Sat, 06 May 2006 19:43:19 -0400
> To: Rodrigo Gonzalez <rjgonzale@gmail.com>
> Cc: HH <lists@lastonepicked.com>, PostgreSQL <pgsql-general@postgresql.org>
> Subject: Re: [GENERAL] Can't Figure Out Where Rows Are Going
>
> Is there an chance the rows are being inserted in a transaction that
> fails and rolls back? Maybe look at all the lines that were inserted
> with that order, and try them manually in psql, character for character,
> and see if an error pops up for any of the lines?
>
> Terry Fielder
> terry@greatgulfhomes.com
> Associate Director Software Development and Deployment
> Great Gulf Homes / Ashton Woods Homes
> Fax: (416) 441-9085
>
>
>
> Rodrigo Gonzalez wrote:
>> Just to be sure....
>>
>> Any error msg in log?
>>
>> Maybe you can run this query in psql and see if it return any error msg
>>
>> Best regards
>>
>> Rodrigo
>>
>> HH wrote:
>>> Hello,
>>>
>>> I am running 8.1.3, built from source, on RHEL4/x64.
>>>
>>> I have a Web application that uses this database to sell products. We
>>> have
>>> an order table and an order lines table with a one to many relationship
>>> between them.
>>>
>>> For the past few months I have had a strange problem where sometimes
>>> (about
>>> 2% of orders), the line item rows disappear. By disappear I mean that
>>> they
>>> are committed to the database and then when I go to look at the order
>>> later,
>>> there are no line items. The row in the 'order' table still exists,
>>> it is
>>> just the line(s) that vanish.
>>>
>>> As I started looking into this problem I assumed that it was a bug in
>>> my Web
>>> application. I did some extensive testing and logging to no avail. I
>>> turned
>>> up the logging on my Web app and I can see the INSERTs but I never
>>> saw any
>>> DELETE statements though I can't find the child row(s) in the DB.
>>>
>>> I've been perplexed for quite some time so a few days ago I turned on
>>> the
>>> following PG logging:
>>>
>>> log_statement = 'mod'
>>>
>>> Today, I found an order that has this problem. Grepping my serverlog,
>>> I see
>>> the following:
>>>
>>> The line item is inserted:
>>>
>>> serverlog:LOG: statement: INSERT INTO order_lines ("order_description",
>>> "order_id", "updated_at", "band_name", "order_item", "product_id",
>>> "line_source", "order_quantity", "extended_price", "unit_price",
>>> "catalog_number", "created_at") VALUES('FW "Not My Pres" Trucker Hat',
>>> 16899, '2006-05-06 14:43:38', NULL, 'Baseball Cap ', 165, 'Merch', 1,
>>> NULL,
>>> 7.0, 94, '2006-05-06 14:43:38')
>>>
>>> Then, I do a SELECT:
>>>
>>> fw_production=# SELECT COUNT(*) FROM order_lines WHERE order_id = 16899;
>>> count -------
>>> 0
>>>
>>> There was about 3 hours between when the line was inserted and when I
>>> went
>>> to look for it. There is no DELETE in the serverlog for this row.
>>>
>>> I can't figure out where this row went and why it disappeared! Is it
>>> getting
>>> deleted some other way that wouldn't be logged? Am I missing something
>>> rudimentary?
>>>
>>> Any help is appreciated.
>>>
>>> Hunter
>>>
>>>
>>>
>>> ---------------------------(end of broadcast)---------------------------
>>> TIP 9: In versions below 8.0, the planner will ignore your desire to
>>> choose an index scan if your joining column's datatypes do not
>>> match
>>>
>>>
>>
>> ---------------------------(end of broadcast)---------------------------
>> TIP 5: don't forget to increase your free space map settings
>>
HH <lists@lastonepicked.com> writes:
> I can't figure out where this row went and why it disappeared! Is it getting
> deleted some other way that wouldn't be logged? Am I missing something
> rudimentary?
Aside from the suggestion already made that the inserting transaction
got rolled back instead of committed, I'd wonder about indirect
deletions due to ON DELETE CASCADE foreign keys, or deletions executed
by PL-language functions. Neither of those would produce obvious log
entries for their effects...
regards, tom lane
Thanks Tom.
I don't use any PL language functions in my app explicitly but perhaps
something implicit when using one of the command line tools or something
like that? I don't have anything pointing in that direction.
I double checked the definition for the 'orders' table (header) and also the
'order_lines', just to make sure there wasn't something in there that could
be throwing me off.
I didn't see anything in 'orders' of any interest at all. I've included both
below in case I missed something in there.
I appreciate everyone trying to help and any other ideas are very much
appreciated. I hope to be able to trace the cause at some point.
-
db_production=# \d orders
Table "public.orders"
Column | Type |
Modifiers
------------------------+-----------------------------+---------------------
--------------------------------
id | integer | not null default
nextval('orders_id_seq'::regclass)
billing_address_1 | character varying(255) |
billing_address_2 | character varying(255) |
billing_city | character varying(255) |
billing_state_province | character varying(255) |
billing_postal_code | character varying(255) |
billing_country | character varying(255) |
phone_number | character varying(255) |
email_address | character varying(255) |
store_name | character varying(255) |
cardholders_name | character varying(255) |
card_type | character varying(255) |
card_number | character varying(255) |
card_security_code | character varying(255) |
expires_month | character varying(255) |
expires_year | character varying(255) |
sent_to_gateway | timestamp without time zone |
gateway_confirmation | character varying(255) |
avs_address | character varying(255) |
avs_zip_code | character varying(255) |
created_at | timestamp without time zone |
updated_at | timestamp without time zone |
billing_first_name | character varying(255) |
billing_last_name | character varying(255) |
shipping_cost | double precision |
sales_tax | double precision |
order_status | character varying(255) |
processor_type | character varying(255) |
ipn_notification | character varying(255) |
ipn_date | timestamp without time zone |
ipn_email | character varying(255) |
ip_address | character varying(255) |
Indexes:
"orders_pkey" PRIMARY KEY, btree (id)
"orders_order_status_index" btree (order_status)
'order_lines'
fatwreck_production=# \d order_lines;
Table "public.order_lines"
Column | Type |
Modifiers
-------------------+-----------------------------+--------------------------
--------------------------------
id | integer | not null default
nextval('order_lines_id_seq'::regclass)
order_id | integer |
order_item | character varying(255) |
order_description | character varying(255) |
order_quantity | integer |
unit_price | numeric |
extended_price | numeric |
created_at | timestamp without time zone |
updated_at | timestamp without time zone |
band_name | character varying(255) |
catalog_number | character varying(255) |
product_id | character varying(255) |
line_source | character varying(255) |
Indexes:
"order_lines_pkey" PRIMARY KEY, btree (id)
"order_lines_order_id_index" btree (order_id)
Foreign-key constraints:
"order_lines_order_id_fkey" FOREIGN KEY (order_id) REFERENCES orders(id)
> From: Tom Lane <tgl@sss.pgh.pa.us>
> Date: Sat, 06 May 2006 22:04:56 -0400
> To: HH <lists@lastonepicked.com>
> Cc: PostgreSQL <pgsql-general@postgresql.org>
> Subject: Re: [GENERAL] Can't Figure Out Where Rows Are Going
>
> HH <lists@lastonepicked.com> writes:
>> I can't figure out where this row went and why it disappeared! Is it getting
>> deleted some other way that wouldn't be logged? Am I missing something
>> rudimentary?
>
> Aside from the suggestion already made that the inserting transaction
> got rolled back instead of committed, I'd wonder about indirect
> deletions due to ON DELETE CASCADE foreign keys, or deletions executed
> by PL-language functions. Neither of those would produce obvious log
> entries for their effects...
>
> regards, tom lane
If you're using a (java) web app with a connection pool is there a
possibility that some connections are configured with auto-commit=false
and that some future transaction issues a rollback which may include the
insert of the order items?
Perhaps some kind of persistance manager is doing this without your
realising it (hibernate, JDO etc)
Or that the connection pool recycled the connection without issuing a
commit.
Although that doesn't necessarily explain why you can see the rows
outside of that particular transaction...
If this is a java app, try asking the postgres-jdbc list.
John
HH wrote:
> Thanks Tom.
>
> I don't use any PL language functions in my app explicitly but perhaps
> something implicit when using one of the command line tools or something
> like that? I don't have anything pointing in that direction.
>
> I double checked the definition for the 'orders' table (header) and also the
> 'order_lines', just to make sure there wasn't something in there that could
> be throwing me off.
>
> I didn't see anything in 'orders' of any interest at all. I've included both
> below in case I missed something in there.
>
> I appreciate everyone trying to help and any other ideas are very much
> appreciated. I hope to be able to trace the cause at some point.
>
> -
> db_production=# \d orders
> Table "public.orders"
> Column | Type |
> Modifiers
> ------------------------+-----------------------------+---------------------
> --------------------------------
> id | integer | not null default
> nextval('orders_id_seq'::regclass)
> billing_address_1 | character varying(255) |
> billing_address_2 | character varying(255) |
> billing_city | character varying(255) |
> billing_state_province | character varying(255) |
> billing_postal_code | character varying(255) |
> billing_country | character varying(255) |
> phone_number | character varying(255) |
> email_address | character varying(255) |
> store_name | character varying(255) |
> cardholders_name | character varying(255) |
> card_type | character varying(255) |
> card_number | character varying(255) |
> card_security_code | character varying(255) |
> expires_month | character varying(255) |
> expires_year | character varying(255) |
> sent_to_gateway | timestamp without time zone |
> gateway_confirmation | character varying(255) |
> avs_address | character varying(255) |
> avs_zip_code | character varying(255) |
> created_at | timestamp without time zone |
> updated_at | timestamp without time zone |
> billing_first_name | character varying(255) |
> billing_last_name | character varying(255) |
> shipping_cost | double precision |
> sales_tax | double precision |
> order_status | character varying(255) |
> processor_type | character varying(255) |
> ipn_notification | character varying(255) |
> ipn_date | timestamp without time zone |
> ipn_email | character varying(255) |
> ip_address | character varying(255) |
> Indexes:
> "orders_pkey" PRIMARY KEY, btree (id)
> "orders_order_status_index" btree (order_status)
>
> 'order_lines'
>
> fatwreck_production=# \d order_lines;
> Table "public.order_lines"
> Column | Type |
> Modifiers
> -------------------+-----------------------------+--------------------------
> --------------------------------
> id | integer | not null default
> nextval('order_lines_id_seq'::regclass)
> order_id | integer |
> order_item | character varying(255) |
> order_description | character varying(255) |
> order_quantity | integer |
> unit_price | numeric |
> extended_price | numeric |
> created_at | timestamp without time zone |
> updated_at | timestamp without time zone |
> band_name | character varying(255) |
> catalog_number | character varying(255) |
> product_id | character varying(255) |
> line_source | character varying(255) |
> Indexes:
> "order_lines_pkey" PRIMARY KEY, btree (id)
> "order_lines_order_id_index" btree (order_id)
> Foreign-key constraints:
> "order_lines_order_id_fkey" FOREIGN KEY (order_id) REFERENCES orders(id)
>
>
>
>>From: Tom Lane <tgl@sss.pgh.pa.us>
>>Date: Sat, 06 May 2006 22:04:56 -0400
>>To: HH <lists@lastonepicked.com>
>>Cc: PostgreSQL <pgsql-general@postgresql.org>
>>Subject: Re: [GENERAL] Can't Figure Out Where Rows Are Going
>>
>>HH <lists@lastonepicked.com> writes:
>>
>>>I can't figure out where this row went and why it disappeared! Is it getting
>>>deleted some other way that wouldn't be logged? Am I missing something
>>>rudimentary?
>>
>>Aside from the suggestion already made that the inserting transaction
>>got rolled back instead of committed, I'd wonder about indirect
>>deletions due to ON DELETE CASCADE foreign keys, or deletions executed
>>by PL-language functions. Neither of those would produce obvious log
>>entries for their effects...
>>
>>regards, tom lane
>
>
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 3: Have you checked our extensive FAQ?
>
> http://www.postgresql.org/docs/faq
Tom Lane wrote: > Aside from the suggestion already made that the inserting transaction > got rolled back instead of committed, I'd wonder about indirect > deletions due to ON DELETE CASCADE foreign keys, or deletions executed > by PL-language functions. Neither of those would produce obvious log > entries for their effects... > Is there no way to trace all SQL statements executed including PL-language functions? There is at least one functional unit in PostgreSQL (the optimizer for example) which does at least some processing of all SQL statements, I presume. Thanks Peter
Are the relevant COMMITs appearing in the log? If the commits fail for whatever reason does/can the application (and postgresql) log that? If the commits are successful then you shouldn't have to need to look for roll-backs. It might be a good idea for teh webapp to log unsuccessful commits. And maybe even log important commits that are successful. Regards, Link. At 05:30 PM 5/6/2006 -0700, HH wrote: >Thanks for taking the time to reply. > >If that was occurring, would the log show it? I don't see any sign of a >roll-back occurring in the log and when I run the queries in psql, they seem >to complete properly.
Turn PITR on
Restore database to the state immediately after transaction is commited and
look for rows presence.
Andrus.
"HH" <lists@lastonepicked.com> wrote in message
news:C082766B.DD7B9%lists@lastonepicked.com...
> Hello,
>
> I am running 8.1.3, built from source, on RHEL4/x64.
>
> I have a Web application that uses this database to sell products. We have
> an order table and an order lines table with a one to many relationship
> between them.
>
> For the past few months I have had a strange problem where sometimes
> (about
> 2% of orders), the line item rows disappear. By disappear I mean that they
> are committed to the database and then when I go to look at the order
> later,
> there are no line items. The row in the 'order' table still exists, it is
> just the line(s) that vanish.
>
> As I started looking into this problem I assumed that it was a bug in my
> Web
> application. I did some extensive testing and logging to no avail. I
> turned
> up the logging on my Web app and I can see the INSERTs but I never saw any
> DELETE statements though I can't find the child row(s) in the DB.
>
> I've been perplexed for quite some time so a few days ago I turned on the
> following PG logging:
>
> log_statement = 'mod'
>
> Today, I found an order that has this problem. Grepping my serverlog, I
> see
> the following:
>
> The line item is inserted:
>
> serverlog:LOG: statement: INSERT INTO order_lines ("order_description",
> "order_id", "updated_at", "band_name", "order_item", "product_id",
> "line_source", "order_quantity", "extended_price", "unit_price",
> "catalog_number", "created_at") VALUES('FW "Not My Pres" Trucker Hat',
> 16899, '2006-05-06 14:43:38', NULL, 'Baseball Cap ', 165, 'Merch', 1,
> NULL,
> 7.0, 94, '2006-05-06 14:43:38')
>
> Then, I do a SELECT:
>
> fw_production=# SELECT COUNT(*) FROM order_lines WHERE order_id = 16899;
> count
> -------
> 0
>
> There was about 3 hours between when the line was inserted and when I went
> to look for it. There is no DELETE in the serverlog for this row.
>
> I can't figure out where this row went and why it disappeared! Is it
> getting
> deleted some other way that wouldn't be logged? Am I missing something
> rudimentary?
>
> Any help is appreciated.
>
> Hunter
>
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 9: In versions below 8.0, the planner will ignore your desire to
> choose an index scan if your joining column's datatypes do not
> match
>
Thanks.
Actually, the Web app is a Ruby on Rails app and RoR doesn't use connection
pooling in its current implementation.
I'll do some more investigation here to double check but this is an area
where Rails is pretty simple and straightforward.
Yes, since I can see the rows outside of that transaction, I (incorrectly?)
assumed that meant it was committed.
I will keep looking for other reasons.
Hunter
> From: John Sidney-Woollett <johnsw@wardbrook.com>
> Date: Sun, 07 May 2006 09:11:10 +0100
> To: HH <lists@lastonepicked.com>
> Cc: Tom Lane <tgl@sss.pgh.pa.us>, PostgreSQL <pgsql-general@postgresql.org>
> Subject: Re: [GENERAL] Can't Figure Out Where Rows Are Going
>
> If you're using a (java) web app with a connection pool is there a
> possibility that some connections are configured with auto-commit=false
> and that some future transaction issues a rollback which may include the
> insert of the order items?
>
> Perhaps some kind of persistance manager is doing this without your
> realising it (hibernate, JDO etc)
>
> Or that the connection pool recycled the connection without issuing a
> commit.
>
> Although that doesn't necessarily explain why you can see the rows
> outside of that particular transaction...
>
> If this is a java app, try asking the postgres-jdbc list.
>
> John
>
> HH wrote:
>> Thanks Tom.
>>
>> I don't use any PL language functions in my app explicitly but perhaps
>> something implicit when using one of the command line tools or something
>> like that? I don't have anything pointing in that direction.
>>
>> I double checked the definition for the 'orders' table (header) and also the
>> 'order_lines', just to make sure there wasn't something in there that could
>> be throwing me off.
>>
>> I didn't see anything in 'orders' of any interest at all. I've included both
>> below in case I missed something in there.
>>
>> I appreciate everyone trying to help and any other ideas are very much
>> appreciated. I hope to be able to trace the cause at some point.
>>
>> -
>> db_production=# \d orders
>> Table "public.orders"
>> Column | Type |
>> Modifiers
>> ------------------------+-----------------------------+---------------------
>> --------------------------------
>> id | integer | not null default
>> nextval('orders_id_seq'::regclass)
>> billing_address_1 | character varying(255) |
>> billing_address_2 | character varying(255) |
>> billing_city | character varying(255) |
>> billing_state_province | character varying(255) |
>> billing_postal_code | character varying(255) |
>> billing_country | character varying(255) |
>> phone_number | character varying(255) |
>> email_address | character varying(255) |
>> store_name | character varying(255) |
>> cardholders_name | character varying(255) |
>> card_type | character varying(255) |
>> card_number | character varying(255) |
>> card_security_code | character varying(255) |
>> expires_month | character varying(255) |
>> expires_year | character varying(255) |
>> sent_to_gateway | timestamp without time zone |
>> gateway_confirmation | character varying(255) |
>> avs_address | character varying(255) |
>> avs_zip_code | character varying(255) |
>> created_at | timestamp without time zone |
>> updated_at | timestamp without time zone |
>> billing_first_name | character varying(255) |
>> billing_last_name | character varying(255) |
>> shipping_cost | double precision |
>> sales_tax | double precision |
>> order_status | character varying(255) |
>> processor_type | character varying(255) |
>> ipn_notification | character varying(255) |
>> ipn_date | timestamp without time zone |
>> ipn_email | character varying(255) |
>> ip_address | character varying(255) |
>> Indexes:
>> "orders_pkey" PRIMARY KEY, btree (id)
>> "orders_order_status_index" btree (order_status)
>>
>> 'order_lines'
>>
>> fatwreck_production=# \d order_lines;
>> Table "public.order_lines"
>> Column | Type |
>> Modifiers
>> -------------------+-----------------------------+--------------------------
>> --------------------------------
>> id | integer | not null default
>> nextval('order_lines_id_seq'::regclass)
>> order_id | integer |
>> order_item | character varying(255) |
>> order_description | character varying(255) |
>> order_quantity | integer |
>> unit_price | numeric |
>> extended_price | numeric |
>> created_at | timestamp without time zone |
>> updated_at | timestamp without time zone |
>> band_name | character varying(255) |
>> catalog_number | character varying(255) |
>> product_id | character varying(255) |
>> line_source | character varying(255) |
>> Indexes:
>> "order_lines_pkey" PRIMARY KEY, btree (id)
>> "order_lines_order_id_index" btree (order_id)
>> Foreign-key constraints:
>> "order_lines_order_id_fkey" FOREIGN KEY (order_id) REFERENCES orders(id)
>>
>>
>>
>>> From: Tom Lane <tgl@sss.pgh.pa.us>
>>> Date: Sat, 06 May 2006 22:04:56 -0400
>>> To: HH <lists@lastonepicked.com>
>>> Cc: PostgreSQL <pgsql-general@postgresql.org>
>>> Subject: Re: [GENERAL] Can't Figure Out Where Rows Are Going
>>>
>>> HH <lists@lastonepicked.com> writes:
>>>
>>>> I can't figure out where this row went and why it disappeared! Is it
>>>> getting
>>>> deleted some other way that wouldn't be logged? Am I missing something
>>>> rudimentary?
>>>
>>> Aside from the suggestion already made that the inserting transaction
>>> got rolled back instead of committed, I'd wonder about indirect
>>> deletions due to ON DELETE CASCADE foreign keys, or deletions executed
>>> by PL-language functions. Neither of those would produce obvious log
>>> entries for their effects...
>>>
>>> regards, tom lane
>>
>>
>>
>>
>> ---------------------------(end of broadcast)---------------------------
>> TIP 3: Have you checked our extensive FAQ?
>>
>> http://www.postgresql.org/docs/faq
>
> ---------------------------(end of broadcast)---------------------------
> TIP 6: explain analyze is your friend
Thanks for the suggestion. I will try to see if we can do this.
One issue is that we don't know the minute this occurs (the rows disappear).
We haven't been able to pinpoint it to any specific event or timing.
We're stil trying to narrow that down.
> From: Andrus <eetasoft@online.ee>
> Organization: Hub.Org Networking Services
> Date: Sun, 7 May 2006 21:23:32 +0300
> To: <pgsql-general@postgresql.org>
> Subject: Re: [GENERAL] Can't Figure Out Where Rows Are Going
>
> Turn PITR on
> Restore database to the state immediately after transaction is commited and
> look for rows presence.
>
> Andrus.
>
>
> "HH" <lists@lastonepicked.com> wrote in message
> news:C082766B.DD7B9%lists@lastonepicked.com...
>> Hello,
>>
>> I am running 8.1.3, built from source, on RHEL4/x64.
>>
>> I have a Web application that uses this database to sell products. We have
>> an order table and an order lines table with a one to many relationship
>> between them.
>>
>> For the past few months I have had a strange problem where sometimes
>> (about
>> 2% of orders), the line item rows disappear. By disappear I mean that they
>> are committed to the database and then when I go to look at the order
>> later,
>> there are no line items. The row in the 'order' table still exists, it is
>> just the line(s) that vanish.
>>
>> As I started looking into this problem I assumed that it was a bug in my
>> Web
>> application. I did some extensive testing and logging to no avail. I
>> turned
>> up the logging on my Web app and I can see the INSERTs but I never saw any
>> DELETE statements though I can't find the child row(s) in the DB.
>>
>> I've been perplexed for quite some time so a few days ago I turned on the
>> following PG logging:
>>
>> log_statement = 'mod'
>>
>> Today, I found an order that has this problem. Grepping my serverlog, I
>> see
>> the following:
>>
>> The line item is inserted:
>>
>> serverlog:LOG: statement: INSERT INTO order_lines ("order_description",
>> "order_id", "updated_at", "band_name", "order_item", "product_id",
>> "line_source", "order_quantity", "extended_price", "unit_price",
>> "catalog_number", "created_at") VALUES('FW "Not My Pres" Trucker Hat',
>> 16899, '2006-05-06 14:43:38', NULL, 'Baseball Cap ', 165, 'Merch', 1,
>> NULL,
>> 7.0, 94, '2006-05-06 14:43:38')
>>
>> Then, I do a SELECT:
>>
>> fw_production=# SELECT COUNT(*) FROM order_lines WHERE order_id = 16899;
>> count
>> -------
>> 0
>>
>> There was about 3 hours between when the line was inserted and when I went
>> to look for it. There is no DELETE in the serverlog for this row.
>>
>> I can't figure out where this row went and why it disappeared! Is it
>> getting
>> deleted some other way that wouldn't be logged? Am I missing something
>> rudimentary?
>>
>> Any help is appreciated.
>>
>> Hunter
>>
>>
>>
>> ---------------------------(end of broadcast)---------------------------
>> TIP 9: In versions below 8.0, the planner will ignore your desire to
>> choose an index scan if your joining column's datatypes do not
>> match
>>
>
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 3: Have you checked our extensive FAQ?
>
> http://www.postgresql.org/docs/faq
Would it be possible to create a constraint that makes rows of a certain table impossible to delete? Perhaps by adding a constraint of that type, I would be able to get some more logging of the event that makes the rows disappear? When they were getting blown away, the constraint would prevent it and thus I would hope, some event would be logged. Possible? Ill-advised? > From: Lincoln Yeoh <lyeoh@pop.jaring.my> > Date: Sun, 07 May 2006 17:48:32 +0800 > To: HH <lists@lastonepicked.com> > Cc: PostgreSQL <pgsql-general@postgresql.org> > Subject: Re: [GENERAL] Can't Figure Out Where Rows Are Going > > Are the relevant COMMITs appearing in the log? > > If the commits fail for whatever reason does/can the application (and > postgresql) log that? > > If the commits are successful then you shouldn't have to need to look for > roll-backs. > > It might be a good idea for teh webapp to log unsuccessful commits. And > maybe even log important commits that are successful. > > Regards, > > Link. > > At 05:30 PM 5/6/2006 -0700, HH wrote: > >> Thanks for taking the time to reply. >> >> If that was occurring, would the log show it? I don't see any sign of a >> roll-back occurring in the log and when I run the queries in psql, they seem >> to complete properly. > > > > ---------------------------(end of broadcast)--------------------------- > TIP 3: Have you checked our extensive FAQ? > > http://www.postgresql.org/docs/faq
HH <lists@lastonepicked.com> writes:
> Would it be possible to create a constraint that makes rows of a certain
> table impossible to delete?
REVOKE DELETE ON foo FROM ...
This assumes you don't run your apps as database superuser of course.
regards, tom lane