Re: BUG #8842: lo_open/fastpath transaction inconsistency - Mailing list pgsql-bugs
From | Bruce Momjian |
---|---|
Subject | Re: BUG #8842: lo_open/fastpath transaction inconsistency |
Date | |
Msg-id | 20140416175501.GG7443@momjian.us Whole thread Raw |
In response to | BUG #8842: lo_open/fastpath transaction inconsistency (ludovic.pollet@kurmi-software.com) |
Responses |
Re: BUG #8842: lo_open/fastpath transaction inconsistency
(Ludovic POLLET <ludovic.pollet@kurmi-software.com>)
|
List | pgsql-bugs |
I see no one replied to you. Can you recreate the problem in a newer version of Postgres? --------------------------------------------------------------------------- On Wed, Jan 15, 2014 at 12:49:35PM +0000, ludovic.pollet@kurmi-software.com wrote: > The following bug has been logged on the website: > > Bug reference: 8842 > Logged by: Ludovic P > Email address: ludovic.pollet@kurmi-software.com > PostgreSQL version: 9.0.3 > Operating system: Windows > Description: > > Summary: > > Accessing LOB using the lo_open function via fastpath call sometime fails > for blob that have been concurrently deleted after the start of the > transaction, with a message "large object xxx does not exist". > However, the same access pattern implemented using plain sql select > loread(lo_open(...)) just works reliably. > > I suspect that the "fastpath" way of calling lo_open is broken regarding > transaction consistency (ie it sees data that are otherwise not visible to > the transaction). > > Details: > > I have a table (async_operations) that holds an oid row (result) that is > really a reference to a lob. > > create table async_operations ( > idASYNC_OPERATION int4 not null, > result oid, > ... (removed for clarity) > primary key (idASYNC_OPERATION)) > > This table has a trigger that manage the lob (ie lo_delete on update/ > delete) > > create trigger t_async_operations_result before update or delete on > async_operations for each row execute procedure lo_manage(result) > / > > Two kinds of transaction may happen : > 'update transaction' create a new lob and update the result oid (and the > trigger delete the old one > 'consult transaction' select an entry, and perform a lo_open/loread on the > lob. > > When load transaction is implemented using the jdbc api, random failures > happen in fastpath function call to to_open, just after the commit of an > 'update transaction'. > > Here is an extract of the service side query trace of my application (9.0.3, > default_transaction_isolation = 'repeatable read'. latest 9.3 and higher > isolation level behave the same). The log pattern is '%m %c %x %v'. > > > Transaction 5/37 is 'update transaction' > Transaction 3/2510 is a 'consult transaction', but it first does a plain sql > way (to show that the sql way works), then a fastpath way (returning the > error) > Transaction 4/414 is 'consult transaction' that loops the plain sql way. It > correctly reads the initial lob oid and content before and after commit, and > keep reading during the whole transaction. (this was intended to double > check that the transaction could not see value commited concurrently) > > It shows that within the Transaction 3/2510, the call to lo_open using > select statement success while the call to lo_open using fastpath fails > (still in the SAME transaction). So I the problem seemns not related to the > client (in that case the jdbc driver), but to the server. > > 2014-01-15 11:44:40.429 CET 52d6668a.8fc 0 5/37LOG: statement: BEGIN;select > asyncopera0_.idASYNC_OPERATION as idASYNC1_570_0_, asyncopera0_.result as > result570_0_ from async_operations asyncopera0_ where > asyncopera0_.idASYNC_OPERATION=304837 > 2014-01-15 11:44:40.430 CET 52d6668a.8fc 0 5/37LOG: fastpath function call: > "lo_open" (OID 952) > 2014-01-15 11:44:40.430 CET 52d6668a.8fc 0 5/37LOG: fastpath function call: > "lo_creat" (OID 957) > 2014-01-15 11:44:40.430 CET 52d6668a.8fc 493216 5/37LOG: fastpath function > call: "lo_open" (OID 952) > 2014-01-15 11:44:40.430 CET 52d6668a.8fc 493216 5/37LOG: fastpath function > call: "lowrite" (OID 955) > 2014-01-15 11:44:40.430 CET 52d6668a.8fc 493216 5/37LOG: fastpath function > call: "lo_close" (OID 953) > 2014-01-15 11:44:40.431 CET 52d6668a.8fc 493216 5/37LOG: statement: update > async_operations set result=581532 where idASYNC_OPERATION=304837 > ... > 2014-01-15 11:44:40.908 CET 52d66616.d28 0 4/414LOG: statement: > BEGIN;select result from async_operations where idASYNC_OPERATION=304837 > 2014-01-15 11:44:40.908 CET 52d66616.d28 0 4/414LOG: statement: select > loread(lo_open(581531, 262144), 1000000) > ... > 2014-01-15 11:44:40.931 CET 52d66611.26f0 0 3/2510LOG: statement: > BEGIN;select result from async_operations where idASYNC_OPERATION=304837 > 2014-01-15 11:44:40.931 CET 52d6668a.8fc 493216 5/37LOG: statement: COMMIT > 2014-01-15 11:44:40.931 CET 52d66616.d28 0 4/414LOG: statement: select > result from async_operations where idASYNC_OPERATION=304837 > 2014-01-15 11:44:40.931 CET 52d66611.26f0 0 3/2510LOG: statement: select > loread(lo_open(581531, 262144), 1000000) > 2014-01-15 11:44:40.931 CET 52d66616.d28 0 4/414LOG: statement: select > loread(lo_open(581531, 262144), 1000000) > 2014-01-15 11:44:40.932 CET 52d66611.26f0 0 3/2510LOG: statement: select > asyncopera0_.idASYNC_OPERATION as idASYNC1_570_0_, asyncopera0_.userId as > userId570_0_, asyncopera0_.originalUserId as original3_570_0_, > asyncopera0_.executerTitle as executer4_570_0_, asyncopera0_.flag as > flag570_0_, asyncopera0_.status as status570_0_, asyncopera0_.startTime as > startTime570_0_, asyncopera0_.endTime as endTime570_0_, > asyncopera0_.description as descript9_570_0_, asyncopera0_.encodedForm as > encoded10_570_0_, asyncopera0_.result as result570_0_, > asyncopera0_.fileContent as fileCon12_570_0_, > asyncopera0_.fileContentEncoding as fileCon13_570_0_, > asyncopera0_.fileProc_class as fileProc14_570_0_, asyncopera0_.pojoName1 as > pojoName15_570_0_, asyncopera0_.pojoName2 as pojoName16_570_0_, > asyncopera0_.language as language570_0_, asyncopera0_.additionalHeaderField > as additio18_570_0_, asyncopera0_.massOperation as massOpe19_570_0_, > asyncopera0_.node as node570_0_, asyncopera0_.execNode as execNode570_0_ > from async_operations asyncopera0_ where > asyncopera0_.idASYNC_OPERATION=304837 > 2014-01-15 11:44:40.932 CET 52d66616.d28 0 4/414LOG: statement: select > result from async_operations where idASYNC_OPERATION=304837 > 2014-01-15 11:44:40.932 CET 52d66616.d28 0 4/414LOG: statement: select > loread(lo_open(581531, 262144), 1000000) > 2014-01-15 11:44:40.932 CET 52d66611.26f0 0 3/2510LOG: fastpath function > call: "lo_open" (OID 952) > => This should work since the access using statement in the same transaction > was ok (I triple checked in the code that the OID passed to lo_open was the > same as the previous select, in this case 581531) > 2014-01-15 11:44:40.932 CET 52d66611.26f0 0 3/2510ERROR: large object > 581531 does not exist > 2014-01-15 11:44:40.932 CET 52d66616.d28 0 4/414LOG: statement: select > result from async_operations where idASYNC_OPERATION=304837 > 2014-01-15 11:44:40.932 CET 52d66616.d28 0 4/414LOG: statement: select > loread(lo_open(581531, 262144), 1000000) > > > > > > > -- > Sent via pgsql-bugs mailing list (pgsql-bugs@postgresql.org) > To make changes to your subscription: > http://www.postgresql.org/mailpref/pgsql-bugs -- Bruce Momjian <bruce@momjian.us> http://momjian.us EnterpriseDB http://enterprisedb.com + Everyone has their own god. +
pgsql-bugs by date: