Renewal notices are sent as digests - all renewed items are collected in one e-mail that is sent out with the process_messagequeue. We have a library, where sometimes this doesn't work. Instead of one single e-mail notice to the patron for one 'process_messagequeue' interval, multiple renewal notices are generated. The majority of e-mails is generated correctly. Looking at the code, this is about how it works: - AddRenewal is exectuted per item and calls - SendCirculationAlert which calls - C4::Message->find_last_message to help decide if a new notice has to be generated or an existing one can be amended In order to test this, you need: - EnhancedMessagingPreferences - Check-out notice checked for the patron you test with - RenewalSendNotice activated - A notice called RENEWAL As I see no problem in the logic so far, I think it could be a race condition where find_last_message doesn't find an existing notice (yet)?
We have one installation with Plack and 3.22.14 now, where this happens a lot - with renewal notices, but also with checkout/check-in notices. Any advice on why this happens and how it could be fixed would be much appreciated.
(In reply to Katrin Fischer from comment #1) > We have one installation with Plack and 3.22.14 now, where this happens a > lot - with renewal notices, but also with check-in notices. Any > advice on why this happens and how it could be fixed would be much > appreciated. Check-out notices appear to be safe - hard to be so fast.
Created attachment 60057 [details] [review] Bug 15854: Simplify the code to limit race conditions There is an obvious race condition when CHECKIN and RENEWAL are generated from circulation.pl calling svc/renew or svc/checkin in AJAX. The 2 first queries will try to get the id of the last message (find_last_message) and if it does not exist, they will insert it. Theorically that could be lead to have several "digest" messages for a given patron. I did not recreate more than 2 messages, from the third one at least one of the two firsts existed in the DB already. This patch just simplifies the code to make the SELECT and INSERT or UPDATE closer and limit the race condition possibilities. Test plan: 0. Set RenewalSendNotice and circ rules to have a lot of renewals available 1. Use batch checkouts (or one by one) to check out several items to a patron 2. Empty message_queue (at least of this patron) 3. Renew them all at once ("select all" link, "renew or check in" button) 4. Check the message_queue Without this patch you have lot of chances to faced a race condition and get at least 2 messages for the same patron. This is not expected, we expect 1 digest with all the messages. With this patch apply you have lot of chances not to face it, but it's not 100% safe as we do not use a mechanism to lock the table at the DBMS level.
Created attachment 60058 [details] [review] Bug 15854: Use a READ and WRITE LOCK on message_queue To make sure we will not never get a race conditions for these kinds of notices, we need to add a LOCK on the message_queue table. This does not smell the best way to do that, but I faced deadlock issues when I tried to use "UPDATE FOR" https://dev.mysql.com/doc/refman/5.7/en/innodb-locking-reads.html https://dev.mysql.com/doc/refman/5.7/en/lock-tables.html https://dev.mysql.com/doc/refman/5.7/en/commit.html To test this patch, or another solution, you need to apply manually this change: my $message = C4::Message->find_last_message($borrower, $type, $mtt); unless ( $message ) { + sleep(1); C4::Message->enqueue($letter, $borrower, $mtt); } else { And repeat the test plan from first patch. Do not forget to truncate the message_queue table.
Anyone familiar with lock, deadlock and transaction?
Created attachment 60813 [details] [review] Bug 15854: Simplify the code to limit race conditions There is an obvious race condition when CHECKIN and RENEWAL are generated from circulation.pl calling svc/renew or svc/checkin in AJAX. The 2 first queries will try to get the id of the last message (find_last_message) and if it does not exist, they will insert it. Theorically that could be lead to have several "digest" messages for a given patron. I did not recreate more than 2 messages, from the third one at least one of the two firsts existed in the DB already. This patch just simplifies the code to make the SELECT and INSERT or UPDATE closer and limit the race condition possibilities. Test plan: 0. Set RenewalSendNotice and circ rules to have a lot of renewals available 1. Use batch checkouts (or one by one) to check out several items to a patron 2. Empty message_queue (at least of this patron) 3. Renew them all at once ("select all" link, "renew or check in" button) 4. Check the message_queue Without this patch you have lot of chances to faced a race condition and get at least 2 messages for the same patron. This is not expected, we expect 1 digest with all the messages. With this patch apply you have lot of chances not to face it, but it's not 100% safe as we do not use a mechanism to lock the table at the DBMS level. Tested both patches together, works as expected. Signed-off-by: Marc Véron <veron@veron.ch>
Created attachment 60814 [details] [review] Bug 15854: Use a READ and WRITE LOCK on message_queue To make sure we will not never get a race conditions for these kinds of notices, we need to add a LOCK on the message_queue table. This does not smell the best way to do that, but I faced deadlock issues when I tried to use "UPDATE FOR" https://dev.mysql.com/doc/refman/5.7/en/innodb-locking-reads.html https://dev.mysql.com/doc/refman/5.7/en/lock-tables.html https://dev.mysql.com/doc/refman/5.7/en/commit.html To test this patch, or another solution, you need to apply manually this change: my $message = C4::Message->find_last_message($borrower, $type, $mtt); unless ( $message ) { + sleep(1); C4::Message->enqueue($letter, $borrower, $mtt); } else { And repeat the test plan from first patch. Do not forget to truncate the message_queue table. Followed test plans, works as expected. Signed-off-by: Marc Véron <veron@veron.ch>
Created attachment 61421 [details] [review] Bug 15854: Simplify the code to limit race conditions There is an obvious race condition when CHECKIN and RENEWAL are generated from circulation.pl calling svc/renew or svc/checkin in AJAX. The 2 first queries will try to get the id of the last message (find_last_message) and if it does not exist, they will insert it. Theorically that could be lead to have several "digest" messages for a given patron. I did not recreate more than 2 messages, from the third one at least one of the two firsts existed in the DB already. This patch just simplifies the code to make the SELECT and INSERT or UPDATE closer and limit the race condition possibilities. Test plan: 0. Set RenewalSendNotice and circ rules to have a lot of renewals available 1. Use batch checkouts (or one by one) to check out several items to a patron 2. Empty message_queue (at least of this patron) 3. Renew them all at once ("select all" link, "renew or check in" button) 4. Check the message_queue Without this patch you have lot of chances to faced a race condition and get at least 2 messages for the same patron. This is not expected, we expect 1 digest with all the messages. With this patch apply you have lot of chances not to face it, but it's not 100% safe as we do not use a mechanism to lock the table at the DBMS level. Tested both patches together, works as expected. Signed-off-by: Marc Véron <veron@veron.ch> Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Created attachment 61422 [details] [review] Bug 15854: Use a READ and WRITE LOCK on message_queue To make sure we will not never get a race conditions for these kinds of notices, we need to add a LOCK on the message_queue table. This does not smell the best way to do that, but I faced deadlock issues when I tried to use "UPDATE FOR" https://dev.mysql.com/doc/refman/5.7/en/innodb-locking-reads.html https://dev.mysql.com/doc/refman/5.7/en/lock-tables.html https://dev.mysql.com/doc/refman/5.7/en/commit.html To test this patch, or another solution, you need to apply manually this change: my $message = C4::Message->find_last_message($borrower, $type, $mtt); unless ( $message ) { + sleep(1); C4::Message->enqueue($letter, $borrower, $mtt); } else { And repeat the test plan from first patch. Do not forget to truncate the message_queue table. Followed test plans, works as expected. Signed-off-by: Marc Véron <veron@veron.ch> Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Well done Jonathan, not a simple one there. Passing QA.
Pushed to Master - Should be in the 17.05 release. Thanks!
These patches have been pushed to 16.11.x and will be in 16.11.06 .
Pushed to 3.22.x, will be in 3.22.19
" LOCK TABLES is not transaction-safe and implicitly commits any active transaction before attempting to lock the tables. " This is bad for tests...
(In reply to Jonathan Druart from comment #14) > " LOCK TABLES is not transaction-safe and implicitly commits any active > transaction before attempting to lock the tables. " > > This is bad for tests... Will need to be fixed, see bug 18364. Stable releases should be safe, SendCirculationAlert is not covered by tests
(In reply to Jonathan Druart from comment #15) > Stable releases should be safe, SendCirculationAlert is not covered by tests It may not be called directly from a test. But what about indirect calls? Maybe from AddReturn or AddRenewal or AddIssue ?
(In reply to Marcel de Rooy from comment #16) > (In reply to Jonathan Druart from comment #15) > > Stable releases should be safe, SendCirculationAlert is not covered by tests > > It may not be called directly from a test. > But what about indirect calls? Maybe from AddReturn or AddRenewal or > AddIssue ? AFAIK we do not have tests covering messaging preferences.
(In reply to Jonathan Druart from comment #5) > Anyone familiar with lock, deadlock and transaction? In PostgreSQL but not with MySQL.
Why aren't we logging individual events (e.g. checkout, checkin, renew, etc), and then bundling them together before sending out notices if they're digests? If it's not a digest, you could log it and run generate_notice which puts it into a mail queue. If it is a digest, you could log it with a digest/delay flag. Then periodically (e.g. every fifteen minutes), you could group_by to get the patron ids for all digests, then iterate through each patron while getting all the digest events for that patron, and then queue an email. process_message_queue could then just run like normal. I think that would be a lot simpler than using locks. After all, the message_queue should just be FIFO, right? Once it's in there, it's in there as a finished product ready to go out.
(In reply to David Cook from comment #19) > After all, the message_queue should just be FIFO, right? Once it's in there, > it's in there as a finished product ready to go out. Handling digests differently doesnt sound bad to me.
(In reply to Marcel de Rooy from comment #20) > (In reply to David Cook from comment #19) > > After all, the message_queue should just be FIFO, right? Once it's in there, > > it's in there as a finished product ready to go out. > > Handling digests differently doesnt sound bad to me. Well, the way digests are handled is pretty bad IMO. But anyway we are looking for a quick solution to fix an important issue, not rethinking the way we are sending messages.
(In reply to Julian Maurice from comment #13) > Pushed to 3.22.x, will be in 3.22.19 Pushed to 16.05.x, for 16.05.12 release