Login | Register For Free | Help
Search for: (Advanced)

Mailing List Archive: DAViCal: General

Deadlock on bulk insert/delete with Lightning

 

 

DAViCal general RSS feed   Index | Next | Previous | View Threaded


lst_hoe02 at kwsoft

Mar 16, 2011, 7:36 AM

Post #1 of 9 (776 views)
Permalink
Deadlock on bulk insert/delete with Lightning

Hello

Bulk insert (import) and delete of events fail with the below listed
errors in the PostgreSQL log. We use latest DaviCAL and
Thunderbird/Lightning as client. Normal operation is fine eg.
create/read/alter/delete works fine when done sequentiell eg. by-hand.
When we try to import a calendar or mark a couple of events and do
"delete" Lightning throw some error and PostgreSQL complain about the
mentioned dead-lock.
Lightning is 1.0b3pre.20110202
Thunderbird 3.1.9
Client OS is XP-SP3
DaviCAL is 0.9.9.4-1
PostgreSQL is 8.4.7

Error from PostgreSQL log:

Mar 16 09:24:59 mailer postgres[9938]: [4-1] 2011-03-16 09:24:59 CET
FEHLER: Verklemmung (Deadlock) entdeckt
Mar 16 09:24:59 mailer postgres[9938]: [4-2] 2011-03-16 09:24:59 CET
DETAIL: Prozess 9938 wartet auf ShareLock-Sperre auf Transaktion
19397; blockiert von Prozess 9939.
Mar 16 09:24:59 mailer postgres[9938]: [4-3] Prozess 9939 wartet auf
ExclusiveLock-Sperre auf Tupel (3, 20) von Relation 288400 von
Datenbank 288259; blockiert von Prozess 9938.
Mar 16 09:24:59 mailer postgres[9938]: [4-4] Prozess 9938: DELETE
FROM caldav_data WHERE dav_id = 4002
Mar 16 09:24:59 mailer postgres[9938]: [4-5] Prozess 9939: DELETE
FROM caldav_data WHERE dav_id = 4000
Mar 16 09:24:59 mailer postgres[9938]: [4-6] 2011-03-16 09:24:59 CET
TIPP: Einzelheiten zur Anfrage finden Sie im Serverlog.
Mar 16 09:24:59 mailer postgres[9938]: [4-7] 2011-03-16 09:24:59 CET
ZUSAMMENHANG: SQL-Anweisung ?UPDATE collection SET modified =
current_timestamp, dav_etag = md5( $1 ::text|| $2 ) WHERE
collection_id = $3 ?
Mar 16 09:24:59 mailer postgres[9938]: [4-8] PL/pgSQL function
"caldav_data_modified" line 26 at SQL-Anweisung
Mar 16 09:24:59 mailer postgres[9938]: [4-9] 2011-03-16 09:24:59 CET
ANWEISUNG: DELETE FROM caldav_data WHERE dav_id = 4002
Mar 16 09:24:59 mailer postgres[9938]: [5-1] 2011-03-16 09:24:59 CET
FEHLER: aktuelle Transaktion wurde abgebrochen, Befehle werden bis
zum Ende der Transaktion ignoriert
Mar 16 09:24:59 mailer postgres[9938]: [5-2] 2011-03-16 09:24:59 CET
ANWEISUNG: DEALLOCATE pdo_pgsql_stmt_0865ee4c

Any hint how to debug?

Regards

Andreas



-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 6046 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://lists.davical.org/pipermail/davical-users/attachments/20110316/e7e88117/attachment.bin>
-------------- next part --------------


florianr at uni-paderborn

Mar 16, 2011, 8:25 AM

Post #2 of 9 (699 views)
Permalink
Deadlock on bulk insert/delete with Lightning [In reply to]

Hello Andreas,

I assume that for Andrew it would be very helpfull if you could provide
him with an example ics file to reproduce the error. He would then be
able to add it to the DaviCal regression tests.

Regards,
Florian

Am 16.03.2011 15:36, schrieb lst_hoe02 at kwsoft.de:
> Hello
>
> Bulk insert (import) and delete of events fail with the below listed
> errors in the PostgreSQL log. We use latest DaviCAL and
> Thunderbird/Lightning as client. Normal operation is fine eg.
> create/read/alter/delete works fine when done sequentiell eg. by-hand.
> When we try to import a calendar or mark a couple of events and do
> "delete" Lightning throw some error and PostgreSQL complain about the
> mentioned dead-lock.
> Lightning is 1.0b3pre.20110202
> Thunderbird 3.1.9
> Client OS is XP-SP3
> DaviCAL is 0.9.9.4-1
> PostgreSQL is 8.4.7
>
> Error from PostgreSQL log:
>
> Mar 16 09:24:59 mailer postgres[9938]: [4-1] 2011-03-16 09:24:59 CET
> FEHLER: Verklemmung (Deadlock) entdeckt
> Mar 16 09:24:59 mailer postgres[9938]: [4-2] 2011-03-16 09:24:59 CET
> DETAIL: Prozess 9938 wartet auf ShareLock-Sperre auf Transaktion
> 19397; blockiert von Prozess 9939.
> Mar 16 09:24:59 mailer postgres[9938]: [4-3] Prozess 9939 wartet
> auf ExclusiveLock-Sperre auf Tupel (3, 20) von Relation 288400 von
> Datenbank 288259; blockiert von Prozess 9938.
> Mar 16 09:24:59 mailer postgres[9938]: [4-4] Prozess 9938: DELETE
> FROM caldav_data WHERE dav_id = 4002
> Mar 16 09:24:59 mailer postgres[9938]: [4-5] Prozess 9939: DELETE
> FROM caldav_data WHERE dav_id = 4000
> Mar 16 09:24:59 mailer postgres[9938]: [4-6] 2011-03-16 09:24:59 CET
> TIPP: Einzelheiten zur Anfrage finden Sie im Serverlog.
> Mar 16 09:24:59 mailer postgres[9938]: [4-7] 2011-03-16 09:24:59 CET
> ZUSAMMENHANG: SQL-Anweisung ?UPDATE collection SET modified =
> current_timestamp, dav_etag = md5( $1 ::text|| $2 ) WHERE
> collection_id = $3 ?
> Mar 16 09:24:59 mailer postgres[9938]: [4-8] PL/pgSQL function
> "caldav_data_modified" line 26 at SQL-Anweisung
> Mar 16 09:24:59 mailer postgres[9938]: [4-9] 2011-03-16 09:24:59 CET
> ANWEISUNG: DELETE FROM caldav_data WHERE dav_id = 4002
> Mar 16 09:24:59 mailer postgres[9938]: [5-1] 2011-03-16 09:24:59 CET
> FEHLER: aktuelle Transaktion wurde abgebrochen, Befehle werden bis
> zum Ende der Transaktion ignoriert
> Mar 16 09:24:59 mailer postgres[9938]: [5-2] 2011-03-16 09:24:59 CET
> ANWEISUNG: DEALLOCATE pdo_pgsql_stmt_0865ee4c
>
> Any hint how to debug?
>
> Regards
>
> Andreas
>
>
>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.davical.org/pipermail/davical-users/attachments/20110316/cf19b31f/attachment.htm>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 6404 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://lists.davical.org/pipermail/davical-users/attachments/20110316/cf19b31f/attachment.bin>
-------------- next part --------------


lst_hoe02 at kwsoft

Mar 16, 2011, 8:30 AM

Post #3 of 9 (702 views)
Permalink
Deadlock on bulk insert/delete with Lightning [In reply to]

Zitat von Florian Rittmeier <florianr at uni-paderborn.de>:

> Hello Andreas,
>
> I assume that for Andrew it would be very helpfull if you could provide
> him with an example ics file to reproduce the error. He would then be
> able to add it to the DaviCal regression tests.
>
> Regards,
> Florian

At least for my case it is easly reproduceable. Simply create a couple
(>10) events, let Lightning show all events, mark them and press delete.
So it does not look like its data related but more of a race condition.

Regards

Andreas



-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 6046 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://lists.davical.org/pipermail/davical-users/attachments/20110316/40915cc5/attachment.bin>
-------------- next part --------------


mir at datanom

Mar 16, 2011, 8:46 AM

Post #4 of 9 (772 views)
Permalink
Deadlock on bulk insert/delete with Lightning [In reply to]

Looks like a missing commit or abort some where


lst_hoe02 at kwsoft.de wrote:

>Hello
>
>Bulk insert (import) and delete of events fail with the below listed
>errors in the PostgreSQL log. We use latest DaviCAL and
>Thunderbird/Lightning as client. Normal operation is fine eg.
>create/read/alter/delete works fine when done sequentiell eg. by-hand.
>
>When we try to import a calendar or mark a couple of events and do
>"delete" Lightning throw some error and PostgreSQL complain about the
>mentioned dead-lock.
>Lightning is 1.0b3pre.20110202
>Thunderbird 3.1.9
>Client OS is XP-SP3
>DaviCAL is 0.9.9.4-1
>PostgreSQL is 8.4.7
>
>Error from PostgreSQL log:
>
>Mar 16 09:24:59 mailer postgres[9938]: [4-1] 2011-03-16 09:24:59 CET
>FEHLER: Verklemmung (Deadlock) entdeckt
>Mar 16 09:24:59 mailer postgres[9938]: [4-2] 2011-03-16 09:24:59 CET
>DETAIL: Prozess 9938 wartet auf ShareLock-Sperre auf Transaktion
>19397; blockiert von Prozess 9939.
>Mar 16 09:24:59 mailer postgres[9938]: [4-3] Prozess 9939 wartet auf
>ExclusiveLock-Sperre auf Tupel (3, 20) von Relation 288400 von
>Datenbank 288259; blockiert von Prozess 9938.
>Mar 16 09:24:59 mailer postgres[9938]: [4-4] Prozess 9938: DELETE
>FROM caldav_data WHERE dav_id = 4002
>Mar 16 09:24:59 mailer postgres[9938]: [4-5] Prozess 9939: DELETE
>FROM caldav_data WHERE dav_id = 4000
>Mar 16 09:24:59 mailer postgres[9938]: [4-6] 2011-03-16 09:24:59 CET
>TIPP: Einzelheiten zur Anfrage finden Sie im Serverlog.
>Mar 16 09:24:59 mailer postgres[9938]: [4-7] 2011-03-16 09:24:59 CET
>ZUSAMMENHANG: SQL-Anweisung ?UPDATE collection SET modified =
>current_timestamp, dav_etag = md5( $1 ::text|| $2 ) WHERE
>collection_id = $3 ?
>Mar 16 09:24:59 mailer postgres[9938]: [4-8] PL/pgSQL function
>"caldav_data_modified" line 26 at SQL-Anweisung
>Mar 16 09:24:59 mailer postgres[9938]: [4-9] 2011-03-16 09:24:59 CET
>ANWEISUNG: DELETE FROM caldav_data WHERE dav_id = 4002
>Mar 16 09:24:59 mailer postgres[9938]: [5-1] 2011-03-16 09:24:59 CET
>FEHLER: aktuelle Transaktion wurde abgebrochen, Befehle werden bis
>zum Ende der Transaktion ignoriert
>Mar 16 09:24:59 mailer postgres[9938]: [5-2] 2011-03-16 09:24:59 CET
>ANWEISUNG: DEALLOCATE pdo_pgsql_stmt_0865ee4c
>
>Any hint how to debug?
>
>Regards
>
>Andreas
>
>
>

--
Sent from my Android phone with K-9 Mail. Please excuse my brevity.


lst_hoe02 at kwsoft

Mar 16, 2011, 11:28 AM

Post #5 of 9 (702 views)
Permalink
Deadlock on bulk insert/delete with Lightning [In reply to]

Zitat von mir at datanom.net:

> Looks like a missing commit or abort some where
>

Can someone confirm the problem?
If yes this would maybe mean there is an error in the stored procedurs?

Regards

Andreas


-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 6046 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://lists.davical.org/pipermail/davical-users/attachments/20110316/dd500650/attachment.bin>
-------------- next part --------------


florianr at uni-paderborn

Mar 16, 2011, 1:50 PM

Post #6 of 9 (688 views)
Permalink
Deadlock on bulk insert/delete with Lightning [In reply to]

Hello Andreas,

I reported a problem a few weeks before. As far as I remember, there
were also log entries similar to yours. Andrew alread has a bunch of
test data and confirmed to fix it with the next release.

Regards,
Florian

-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 6404 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://lists.davical.org/pipermail/davical-users/attachments/20110316/3fab08be/attachment.bin>
-------------- next part --------------


andrew at morphoss

Mar 16, 2011, 5:27 PM

Post #7 of 9 (698 views)
Permalink
Deadlock on bulk insert/delete with Lightning [In reply to]

On Wed, 2011-03-16 at 16:25 +0100, Florian Rittmeier wrote:
> Hello Andreas,
>
> I assume that for Andrew it would be very helpfull if you could
> provide him with an example ics file to reproduce the error. He would
> then be able to add it to the DaviCal regression tests.

Well, it's easily enough reproducible, unfortunately. It's because
Lightning opens many connections to the webserver to insert events in
parallel when adding (or otherwise modifying) many events at once.

I have some code in HEAD at the moment which *might* fix it which uses
some memcached features to enforce serialisation of the changes in
DAViCal. It's not ideal, but it should work around the problem...

The issue is happening in DAViCal because of some referential integrity
features in the database, and there may be a better solution ultimately
which would re-code the way referential integrity happened for the
collection table.

Of course the fact that it requires many events to be fired at DAViCal
simultaneously makes it difficult to duplicate in a regression test
environment, which is trying hard to produce repeatable effects on the
database rather than random load.


Cheers,
Andrew.

>
> Regards,
> Florian
>
> Am 16.03.2011 15:36, schrieb lst_hoe02 at kwsoft.de:
> > Hello
> >
> > Bulk insert (import) and delete of events fail with the below listed
> > errors in the PostgreSQL log. We use latest DaviCAL and
> > Thunderbird/Lightning as client. Normal operation is fine eg.
> > create/read/alter/delete works fine when done sequentiell eg.
> > by-hand. When we try to import a calendar or mark a couple of events
> > and do "delete" Lightning throw some error and PostgreSQL complain
> > about the mentioned dead-lock.
> > Lightning is 1.0b3pre.20110202
> > Thunderbird 3.1.9
> > Client OS is XP-SP3
> > DaviCAL is 0.9.9.4-1
> > PostgreSQL is 8.4.7
> >
> > Error from PostgreSQL log:
> >
> > Mar 16 09:24:59 mailer postgres[9938]: [4-1] 2011-03-16 09:24:59 CET
> > FEHLER: Verklemmung (Deadlock) entdeckt
> > Mar 16 09:24:59 mailer postgres[9938]: [4-2] 2011-03-16 09:24:59 CET
> > DETAIL: Prozess 9938 wartet auf ShareLock-Sperre auf Transaktion
> > 19397; blockiert von Prozess 9939.
> > Mar 16 09:24:59 mailer postgres[9938]: [4-3] Prozess 9939 wartet
> > auf ExclusiveLock-Sperre auf Tupel (3, 20) von Relation 288400 von
> > Datenbank 288259; blockiert von Prozess 9938.
> > Mar 16 09:24:59 mailer postgres[9938]: [4-4] Prozess 9938:
> > DELETE FROM caldav_data WHERE dav_id = 4002
> > Mar 16 09:24:59 mailer postgres[9938]: [4-5] Prozess 9939:
> > DELETE FROM caldav_data WHERE dav_id = 4000
> > Mar 16 09:24:59 mailer postgres[9938]: [4-6] 2011-03-16 09:24:59 CET
> > TIPP: Einzelheiten zur Anfrage finden Sie im Serverlog.
> > Mar 16 09:24:59 mailer postgres[9938]: [4-7] 2011-03-16 09:24:59 CET
> > ZUSAMMENHANG: SQL-Anweisung ?UPDATE collection SET modified =
> > current_timestamp, dav_etag = md5( $1 ::text|| $2 ) WHERE
> > collection_id = $3 ?
> > Mar 16 09:24:59 mailer postgres[9938]: [4-8] PL/pgSQL function
> > "caldav_data_modified" line 26 at SQL-Anweisung
> > Mar 16 09:24:59 mailer postgres[9938]: [4-9] 2011-03-16 09:24:59 CET
> > ANWEISUNG: DELETE FROM caldav_data WHERE dav_id = 4002
> > Mar 16 09:24:59 mailer postgres[9938]: [5-1] 2011-03-16 09:24:59 CET
> > FEHLER: aktuelle Transaktion wurde abgebrochen, Befehle werden bis
> > zum Ende der Transaktion ignoriert
> > Mar 16 09:24:59 mailer postgres[9938]: [5-2] 2011-03-16 09:24:59 CET
> > ANWEISUNG: DEALLOCATE pdo_pgsql_stmt_0865ee4c
> >
> > Any hint how to debug?
> >
> > Regards
> >
> > Andreas
> >
> >
> >
> >

--
------------------------------------------------------------------------
andrew (AT) morphoss (DOT) com +64(272)DEBIAN
Necessity is the mother of documentation
------------------------------------------------------------------------

-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part
URL: <http://lists.davical.org/pipermail/davical-users/attachments/20110317/02c2759e/attachment-0001.pgp>
-------------- next part --------------


lst_hoe02 at kwsoft

Mar 17, 2011, 2:21 AM

Post #8 of 9 (683 views)
Permalink
Deadlock on bulk insert/delete with Lightning [In reply to]

Zitat von Andrew McMillan <andrew at morphoss.com>:

> On Wed, 2011-03-16 at 16:25 +0100, Florian Rittmeier wrote:
>> Hello Andreas,
>>
>> I assume that for Andrew it would be very helpfull if you could
>> provide him with an example ics file to reproduce the error. He would
>> then be able to add it to the DaviCal regression tests.
>
> Well, it's easily enough reproducible, unfortunately. It's because
> Lightning opens many connections to the webserver to insert events in
> parallel when adding (or otherwise modifying) many events at once.
>
> I have some code in HEAD at the moment which *might* fix it which uses
> some memcached features to enforce serialisation of the changes in
> DAViCal. It's not ideal, but it should work around the problem...
>
> The issue is happening in DAViCal because of some referential integrity
> features in the database, and there may be a better solution ultimately
> which would re-code the way referential integrity happened for the
> collection table.

But this would also get you in trouble if two or more clients try to
update the same calendar, no? So serialisation is urgently needed i
guess...
I have not really understand what is going on in the code but it looks
like the deadlock is raised inside a trigger?

Regards

Andreas


-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 6046 bytes
Desc: S/MIME Cryptographic Signature
URL: <http://lists.davical.org/pipermail/davical-users/attachments/20110317/248c4165/attachment.bin>
-------------- next part --------------


andrew at morphoss

Mar 18, 2011, 1:25 AM

Post #9 of 9 (686 views)
Permalink
Deadlock on bulk insert/delete with Lightning [In reply to]

On Thu, 2011-03-17 at 10:21 +0100, lst_hoe02 at kwsoft.de wrote:
> Zitat von Andrew McMillan <andrew at morphoss.com>:
>
> > On Wed, 2011-03-16 at 16:25 +0100, Florian Rittmeier wrote:
> >> Hello Andreas,
> >>
> >> I assume that for Andrew it would be very helpfull if you could
> >> provide him with an example ics file to reproduce the error. He would
> >> then be able to add it to the DaviCal regression tests.
> >
> > Well, it's easily enough reproducible, unfortunately. It's because
> > Lightning opens many connections to the webserver to insert events in
> > parallel when adding (or otherwise modifying) many events at once.
> >
> > I have some code in HEAD at the moment which *might* fix it which uses
> > some memcached features to enforce serialisation of the changes in
> > DAViCal. It's not ideal, but it should work around the problem...
> >
> > The issue is happening in DAViCal because of some referential integrity
> > features in the database, and there may be a better solution ultimately
> > which would re-code the way referential integrity happened for the
> > collection table.
>
> But this would also get you in trouble if two or more clients try to
> update the same calendar, no? So serialisation is urgently needed i
> guess...

I think "urgently" is overstating it, but it's certainly desirable.

I've never heard of the deadlock occurring other than (various
operations) in Lightning, since the nature of calendar data is (a) that
it changes relatively infrequently, and (b) most calendars are
maintained by a very small number of people. As a result concurrency is
actually very low in real life.


> I have not really understand what is going on in the code but it looks
> like the deadlock is raised inside a trigger?

Yeah, I think it's to do with the trigger code conflicting with a lock
due to a constraint in another process.

Cheers,
Andrew.

--
------------------------------------------------------------------------
andrew (AT) morphoss (DOT) com +64(272)DEBIAN
Rule of Life #1 -- Never get separated from your luggage.
------------------------------------------------------------------------

-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 836 bytes
Desc: This is a digitally signed message part
URL: <http://lists.davical.org/pipermail/davical-users/attachments/20110318/8de0ec07/attachment.pgp>
-------------- next part --------------

DAViCal general RSS feed   Index | Next | Previous | View Threaded
 
 


Interested in having your list archived? Contact Gossamer Threads
 
  Web Applications & Managed Hosting Powered by Gossamer Threads Inc.