Bug 32442 - Invalid Template Toolkit in notices can cause errors
Summary: Invalid Template Toolkit in notices can cause errors
Status: CLOSED FIXED
Alias: None
Product: Koha
Classification: Unclassified
Component: Notices (show other bugs)
Version: master
Hardware: All All
: P5 - low major (vote)
Assignee: Jonathan Druart
QA Contact: Marcel de Rooy
URL:
Keywords:
Depends on: 31211 31373
Blocks:
  Show dependency treegraph
 
Reported: 2022-12-09 18:14 UTC by Lucas Gass
Modified: 2023-12-28 20:42 UTC (History)
6 users (show)

See Also:
Change sponsored?: ---
Patch complexity: Small patch
Documentation contact:
Documentation submission:
Text to go in the release notes:
Version(s) released in:
23.05.00,22.11.03


Attachments
Bug 32442: Add tests (1.71 KB, patch)
2022-12-14 07:47 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 32442: (bug 28739 follow-up) Ensure txn is rollbacked (2.20 KB, patch)
2022-12-14 07:47 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 32442: Add tests (1.76 KB, patch)
2022-12-16 14:50 UTC, Nick Clemens
Details | Diff | Splinter Review
Bug 32442: (bug 28739 follow-up) Ensure txn is rollbacked (2.25 KB, patch)
2022-12-16 14:51 UTC, Nick Clemens
Details | Diff | Splinter Review
Bug 32442: Add tests (1.85 KB, patch)
2023-01-31 13:09 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 32442: (bug 28739 follow-up) Ensure txn is rollbacked (2.35 KB, patch)
2023-01-31 13:09 UTC, Marcel de Rooy
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Lucas Gass 2022-12-09 18:14:15 UTC
I have been noticing something while testing notices lately that I wanted to point out and see if anyone else can recreate, this is happening for me in KTD:

To recreate:

1. Go to any notice and create some invalid Template Toolkit: 

[% IF ( 1 == 1 %]
test
[% END %]

2. Save and continue 

3. Notice the Template Toolkit error:
This is good. 

3. Correct the error:

[% IF ( 1 == 1 ) %]
test
[% END %]

4. Now save again. This time I see the Template Toolkit error like:
DBIx::Class::Storage::DBI::mysql::_exec_svp_rollback(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_0 does not exist at /kohadevbox/koha/C4/Letters.pm line 1624 

5. Save anyways

6. Logout of Koha and attempt to log back in: 
It explodes with this error:

{UNKNOWN}: Transaction aborted: DBIx::Class::Storage::DBI::mysql::_exec_svp_release(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_4 does not exist at /kohadevbox/koha/Koha/Object.pm line 170
. Rollback failed: DBIx::Class::Storage::DBI::mysql::_exec_svp_rollback(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_3 does not exist at /kohadevbox/koha/Koha/Patron.pm line 363 at /kohadevbox/koha/Koha/Patron.pm line 363
 at /usr/share/perl5/DBIx/Class/Exception.pm line 77
Comment 1 Nick Clemens 2022-12-09 18:38:52 UTC
The issue seems to be combination of the try/catch (bug 31211)  with the nested transaction (bug 28739) - when we fail we never rollback the transaction
Comment 2 Jonathan Druart 2022-12-14 07:47:36 UTC
Created attachment 144564 [details] [review]
Bug 32442: Add tests
Comment 3 Jonathan Druart 2022-12-14 07:47:40 UTC
Created attachment 144565 [details] [review]
Bug 32442: (bug 28739 follow-up) Ensure txn is rollbacked

If the TT process call is returning false and so the croak is raised,
then the txn is not rollbacked and the txn is not commited either.

We need to ensure the txn will be correctly rollbacked.

Test plan:
1. Go to any notice and create some invalid Template Toolkit:

[% IF ( 1 == 1 %]
test
[% END %]

2. Save and continue

3. Logout of Koha and attempt to log back in
=> Without this patch you got
Transaction aborted: DBIx::Class::Storage::DBI::mysql::_exec_svp_release(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_4 does not exist at /kohadevbox/koha/Koha/Object.pm line 170
. Rollback failed: DBIx::Class::Storage::DBI::mysql::_exec_svp_rollback(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_3 does not exist at /kohadevbox/koha/Koha/Patron.pm line 363 at /kohadevbox/koha/Koha/Patron.pm line 363
 at /usr/share/perl5/DBIx/Class/Exception.pm line 77
=> With this patch applied the login works successfully

QA Note: The test is not testing that the txn is rolledback, I didn't
manage to test that.
Comment 4 Marcel de Rooy 2022-12-16 07:42:24 UTC
QA: Looking here
Comment 5 Marcel de Rooy 2022-12-16 07:50:31 UTC
Applied both patches, ran the test. Passed.
Ran the test again:

# Subtest: regression tests
    1..8
DBIx::Class::Storage::DBI::_dbh_execute(): DBI Exception: DBD::mysql::st execute failed: Duplicate entry 'a_t_barcode' for key 'itembarcodeidx' at /usr/share/koha/Koha/Object.pm line 170
    # No tests run!
not ok 25 - No tests run for subtest "regression tests"
#   Failed test 'No tests run for subtest "regression tests"'
#   at t/db_dependent/Letters/TemplateToolkit.t line 1045.

Checked my data:
Lots of garbage items from the unit test in my database.

This is not production ready yet :)
Comment 6 Jonathan Druart 2022-12-16 13:18:32 UTC
Problem introduced by this patch?
Comment 7 Nick Clemens 2022-12-16 14:50:56 UTC
Created attachment 144686 [details] [review]
Bug 32442: Add tests

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 8 Nick Clemens 2022-12-16 14:51:00 UTC
Created attachment 144687 [details] [review]
Bug 32442: (bug 28739 follow-up) Ensure txn is rollbacked

If the TT process call is returning false and so the croak is raised,
then the txn is not rollbacked and the txn is not commited either.

We need to ensure the txn will be correctly rollbacked.

Test plan:
1. Go to any notice and create some invalid Template Toolkit:

[% IF ( 1 == 1 %]
test
[% END %]

2. Save and continue

3. Logout of Koha and attempt to log back in
=> Without this patch you got
Transaction aborted: DBIx::Class::Storage::DBI::mysql::_exec_svp_release(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_4 does not exist at /kohadevbox/koha/Koha/Object.pm line 170
. Rollback failed: DBIx::Class::Storage::DBI::mysql::_exec_svp_rollback(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_3 does not exist at /kohadevbox/koha/Koha/Patron.pm line 363 at /kohadevbox/koha/Koha/Patron.pm line 363
 at /usr/share/perl5/DBIx/Class/Exception.pm line 77
=> With this patch applied the login works successfully

QA Note: The test is not testing that the txn is rolledback, I didn't
manage to test that.

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 9 Nick Clemens 2022-12-16 14:52:18 UTC
(In reply to Marcel de Rooy from comment #5)
> This is not production ready yet :)

I was able to run multiple times with no problems - the test plan in staff interface worked as well
Comment 10 Marcel de Rooy 2023-01-27 08:44:41 UTC
Running the test adds barcodes to the table like:

+---------------------+
| barcode             |
+---------------------+
| a_t_barcode         |
| another_t_barcode   |
| another_t_barcode_3 |
| IROjihTVYw1IMlUDV4  |
| msuHU5tofEXn        |
| NMhOFzbI7Yjf        |
| oTfqL7AeaoSq9tDTJWQ |
| Pu2W1UbP7HAvqZkum   |
| sblzCdKniw_bfJubrZA |
| SXpFbuhE5TtTTq      |
| twTvJHKIkgDCZqh9R   |
| U8T51kYicLV4_JP     |
| UmNgCvommVa         |
| vf_sVPEcyM861c9     |
| wY_QRsZyUSpFc       |
+---------------------+

This might not be the direct cause of this patch. But we should fix it here now where we are also dealing with the rollback etc.
Comment 11 Jonathan Druart 2023-01-31 08:32:18 UTC
(In reply to Marcel de Rooy from comment #10)
> Running the test adds barcodes to the table like:
> 
> +---------------------+
> | barcode             |
> +---------------------+
> | a_t_barcode         |
> | another_t_barcode   |
> | another_t_barcode_3 |
> | IROjihTVYw1IMlUDV4  |
> | msuHU5tofEXn        |
> | NMhOFzbI7Yjf        |
> | oTfqL7AeaoSq9tDTJWQ |
> | Pu2W1UbP7HAvqZkum   |
> | sblzCdKniw_bfJubrZA |
> | SXpFbuhE5TtTTq      |
> | twTvJHKIkgDCZqh9R   |
> | U8T51kYicLV4_JP     |
> | UmNgCvommVa         |
> | vf_sVPEcyM861c9     |
> | wY_QRsZyUSpFc       |
> +---------------------+
> 
> This might not be the direct cause of this patch. But we should fix it here
> now where we are also dealing with the rollback etc.

I don't recreate and, if true, I don't think it should be done on this bug report. That sounds something different.

select count(*) from items; # 961

prove t/db_dependent/Letters/TemplateToolkit.t
t/db_dependent/Letters/TemplateToolkit.t .. ok     
All tests successful.

select count(*) from items; # 961
Comment 12 Marcel de Rooy 2023-01-31 12:30:45 UTC
Running prove with test gave no additional items for me too.
Running the script from the commandline itself does:
| a_t_barcode         |
| another_t_barcode   |
| another_t_barcode_3 |
| BMFPNewTkRQ7        |
| CSNGMjPP6jg         |
| XdvEtgyDT2vFo9xLw   |
Comment 13 Marcel de Rooy 2023-01-31 12:35:41 UTC
It is probably the LOCK in SendCirculationAlert..
Comment 14 Marcel de Rooy 2023-01-31 13:09:39 UTC
Created attachment 145862 [details] [review]
Bug 32442: Add tests

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 15 Marcel de Rooy 2023-01-31 13:09:45 UTC
Created attachment 145863 [details] [review]
Bug 32442: (bug 28739 follow-up) Ensure txn is rollbacked

If the TT process call is returning false and so the croak is raised,
then the txn is not rollbacked and the txn is not commited either.

We need to ensure the txn will be correctly rollbacked.

Test plan:
1. Go to any notice and create some invalid Template Toolkit:

[% IF ( 1 == 1 %]
test
[% END %]

2. Save and continue

3. Logout of Koha and attempt to log back in
=> Without this patch you got
Transaction aborted: DBIx::Class::Storage::DBI::mysql::_exec_svp_release(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_4 does not exist at /kohadevbox/koha/Koha/Object.pm line 170
. Rollback failed: DBIx::Class::Storage::DBI::mysql::_exec_svp_rollback(): DBI Exception: DBD::mysql::db do failed: SAVEPOINT savepoint_3 does not exist at /kohadevbox/koha/Koha/Patron.pm line 363 at /kohadevbox/koha/Koha/Patron.pm line 363
 at /usr/share/perl5/DBIx/Class/Exception.pm line 77
=> With this patch applied the login works successfully

QA Note: The test is not testing that the txn is rolledback, I didn't
manage to test that.

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 16 Tomás Cohen Arazi 2023-01-31 13:48:23 UTC
Pushed to master for 23.05.

Nice work everyone, thanks!
Comment 17 Jacob O'Mara 2023-01-31 17:46:45 UTC
Nice work, thanks everyone!

Pushed to 22.11.x for the next release.
Comment 18 Lucas Gass 2023-02-03 21:54:56 UTC
Not needed in 22.05.x, no backport