Bug 26518 - Adding a record can succeed even if adding the biblioitem fails
Summary: Adding a record can succeed even if adding the biblioitem fails
Status: RESOLVED FIXED
Alias: None
Product: Koha
Classification: Unclassified
Component: Cataloging (show other bugs)
Version: master
Hardware: All All
: P5 - low major (vote)
Assignee: Jonathan Druart
QA Contact: Testopia
URL:
Keywords:
Depends on: 26639
Blocks: 27245
  Show dependency treegraph
 
Reported: 2020-09-23 15:23 UTC by Nick Clemens
Modified: 2020-12-16 21:34 UTC (History)
7 users (show)

See Also:
Change sponsored?: ---
Patch complexity: ---
Text to go in the release notes:
Version(s) released in:
20.11.00, 20.05.07, 19.11.13


Attachments
Bug 26518: Use Koha::Biblio[item] in AddBiblio (12.24 KB, patch)
2020-09-29 11:30 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 26518: Raise exception if the insert failed (1.81 KB, patch)
2020-09-29 11:30 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 26518: Does not return from the catch block (1.56 KB, patch)
2020-10-09 08:26 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 26518: Hide expected DBI warnings (1.07 KB, patch)
2020-10-09 10:09 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 26518: Use Koha::Biblio[item] in AddBiblio (12.29 KB, patch)
2020-10-12 13:02 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 26518: Raise exception if the insert failed (1.81 KB, patch)
2020-10-12 13:02 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 26518: Hide expected DBI warnings (1.07 KB, patch)
2020-10-12 13:02 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 26518: Move BiblioAutoLink within the transaction (1.51 KB, patch)
2020-10-12 13:02 UTC, Jonathan Druart
Details | Diff | Splinter Review
Screenshot - After patch applied and attempting to save the record (28.46 KB, image/png)
2020-11-05 09:08 UTC, David Nind
Details
Bug 26518: Use Koha::Biblio[item] in AddBiblio (12.34 KB, patch)
2020-11-16 16:37 UTC, Victor Grousset/tuxayo
Details | Diff | Splinter Review
Bug 26518: Raise exception if the insert failed (1.86 KB, patch)
2020-11-16 16:37 UTC, Victor Grousset/tuxayo
Details | Diff | Splinter Review
Bug 26518: Hide expected DBI warnings (1.13 KB, patch)
2020-11-16 16:37 UTC, Victor Grousset/tuxayo
Details | Diff | Splinter Review
Bug 26518: Move BiblioAutoLink within the transaction (1.57 KB, patch)
2020-11-16 16:37 UTC, Victor Grousset/tuxayo
Details | Diff | Splinter Review
Bug 26518: Use Koha::Biblio[item] in AddBiblio (12.41 KB, patch)
2020-11-23 12:11 UTC, Nick Clemens
Details | Diff | Splinter Review
Bug 26518: Raise exception if the insert failed (1.92 KB, patch)
2020-11-23 12:11 UTC, Nick Clemens
Details | Diff | Splinter Review
Bug 26518: Hide expected DBI warnings (1.18 KB, patch)
2020-11-23 12:11 UTC, Nick Clemens
Details | Diff | Splinter Review
Bug 26518: Move BiblioAutoLink within the transaction (1.62 KB, patch)
2020-11-23 12:11 UTC, Nick Clemens
Details | Diff | Splinter Review
Bug 26518: (QA follow-up) Expect warnings, don't supress them (1.70 KB, patch)
2020-11-23 12:11 UTC, Nick Clemens
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Nick Clemens 2020-09-23 15:23:01 UTC
We can end up creating biblios in the catalog that are malformed

To test:
1 - Add new record with field 010:
    ThisisgoingtobetoomanycharactersfortheLCCNfield
2 - Check the logs, note the error about failure to create biblioitem:
DBD::mysql::st execute failed: Data too long for column 'lccn' at row 1 [for Statement "INSERT INTO biblioitems SET
        biblionumber    = ?,
        volume          = ?,
        number          = ?,
        itemtype        = ?,
        isbn            = ?,
        issn            = ?,
        publicationyear = ?,
        publishercode   = ?,
        volumedate      = ?,
        volumedesc      = ?,
        collectiontitle = ?,
        collectionissn  = ?,
        collectionvolume= ?,
        editionstatement= ?,
        editionresponsibility = ?,
        illus           = ?,
        pages           = ?,
        notes           = ?,
        size            = ?,
        place           = ?,
        lccn            = ?,
        url             = ?,
        cn_source       = ?,
        cn_class        = ?,
        cn_item         = ?,
        cn_suffix       = ?,
        cn_sort         = ?,
        totalissues     = ?,
        ean             = ?,
        agerestriction  = ?
        " with ParamValues: 0='1681', 1=undef, 2=undef, 3=undef, 4=undef, 5=undef, 6=undef, 7=undef, 8=undef, 9=undef, 10=undef, 11=undef, 12=undef, 13=undef, 14=undef, 15=undef, 16=undef, 17=undef, 18=undef, 19=undef, 20="This is the ongest field i can think of", 21=undef, 22=undef, 23=undef, 24=undef, 25=undef, 26='', 27=undef, 28=undef, 29=undef] at /kohadevbox/koha/C4/Biblio.pm line 2926.
ERROR in _koha_add_biblioitem INSERT INTO biblioitems SET

3 - Record saves successfully otherwise
4 - Attempt to add an item:
Can't call method "biblioitemnumber" on an undefined value at /kohadevbox/koha/Koha/Item.pm line 83.
 at /kohadevbox/koha/Koha/Item.pm line 82
Comment 1 Jonathan Druart 2020-09-29 11:30:12 UTC
Created attachment 110902 [details] [review]
Bug 26518: Use Koha::Biblio[item] in AddBiblio
Comment 2 Jonathan Druart 2020-09-29 11:30:17 UTC
Created attachment 110903 [details] [review]
Bug 26518: Raise exception if the insert failed
Comment 3 Jonathan Druart 2020-09-29 11:31:36 UTC
This first patch fixes the problem when using the UI, but the tests fail.
I guess there is something do tweak for the dev_install and strict_mode config flag.

Attaching them here in case someone else wants to give it a try.
Comment 4 Jonathan Druart 2020-10-08 08:34:43 UTC
Can I get some help on this one please?
Comment 5 Nick Clemens 2020-10-08 18:39:03 UTC
(In reply to Jonathan Druart from comment #4)
> Can I get some help on this one please?

The return in the catch returns from the catch, not the AddBiblio function.
Have the catch set biblionumber and biblioitemnumber as undef and it clears up part

The other problem is that the test is nested in a transaction so the inner one fails but leaves the rollback for the outer, so the bib count changes until the tests finish. I don't know how to fix it - you can move the txn->begin in the tests after the first test but that seems dangerous
Comment 6 Jonathan Druart 2020-10-09 08:26:35 UTC
Created attachment 111387 [details] [review]
Bug 26518: Does not return from the catch block
Comment 7 Jonathan Druart 2020-10-09 09:46:19 UTC
I am scared a bit.

Take the following code:

#!/usr/bin/perl

use Modern::Perl;

use Test::More tests => 1;

use Koha::Database;
use Koha::Cities;
use Koha::Exceptions;
use Try::Tiny;

my $schema = Koha::Database->new->schema;

subtest 'City' => sub {
    plan tests => 2;


    my $nb_cities = Koha::Cities->count;
    my $city_id;


    $city_id = add_city();


    is( $city_id, undef);
    is( Koha::Cities->count, $nb_cities );
};

sub add_city{
    my $city_id;
    try {
        $schema->txn_do(sub {
            $city_id = Koha::City->new({ city_name => "test" })->store->cityid;

            Koha::Exceptions::ObjectNotCreated->throw;
        });
    } catch {
        $city_id = undef;
        warn $_;
    };
    return $city_id;
}

=> The city won't be added.

Now surround $city_id = add_city(); with a transaction:

    $schema->storage->txn_do(sub {

        $city_id = add_city();

    });

=> The city is added.

Which means that what we are doing in the "sub add_city" depends on how the caller is handling things, and that is very scary.

We are going to hit very weird side-effects.
Comment 9 Jonathan Druart 2020-10-09 10:02:23 UTC
See bug 26639 - Turn auto_savepoint ON

which is, hopefully, the correct path to follow.
Comment 10 Jonathan Druart 2020-10-09 10:09:28 UTC
Created attachment 111389 [details] [review]
Bug 26518: Hide expected DBI warnings
Comment 11 Jonathan Druart 2020-10-09 10:09:51 UTC
And tests are now passing on top of bug 26639!
Comment 12 Martin Renvoize 2020-10-09 10:40:45 UTC
Did we want to prevent the action at a distance that can add authority records at the same time?
Comment 13 Marcel de Rooy 2020-10-12 06:22:17 UTC
(In reply to Jonathan Druart from comment #7)
> => The city is added.
> 
> Which means that what we are doing in the "sub add_city" depends on how the
> caller is handling things, and that is very scary.
> 
> We are going to hit very weird side-effects.

The inner transaction does not do a rollback anymore. The outer transaction commits.
We came across this already when calling some routines that include a txn_do from the test scripts.
Comment 14 Martin Renvoize 2020-10-12 12:44:55 UTC
(In reply to Marcel de Rooy from comment #13)
> (In reply to Jonathan Druart from comment #7)
> > => The city is added.
> > 
> > Which means that what we are doing in the "sub add_city" depends on how the
> > caller is handling things, and that is very scary.
> > 
> > We are going to hit very weird side-effects.
> 
> The inner transaction does not do a rollback anymore. The outer transaction
> commits.
> We came across this already when calling some routines that include a txn_do
> from the test scripts.

See bug 26639 Marcel, we've fixed the issue there.
Comment 15 Jonathan Druart 2020-10-12 13:02:13 UTC
Created attachment 111512 [details] [review]
Bug 26518: Use Koha::Biblio[item] in AddBiblio

Bug 26518: Does not return from the catch block
Comment 16 Jonathan Druart 2020-10-12 13:02:18 UTC
Created attachment 111513 [details] [review]
Bug 26518: Raise exception if the insert failed
Comment 17 Jonathan Druart 2020-10-12 13:02:22 UTC
Created attachment 111514 [details] [review]
Bug 26518: Hide expected DBI warnings
Comment 18 Jonathan Druart 2020-10-12 13:02:28 UTC
Created attachment 111515 [details] [review]
Bug 26518: Move BiblioAutoLink within the transaction

We don't want the authorities to be created if the biblio insert fails
later
Comment 19 David Nind 2020-11-05 09:08:45 UTC
Created attachment 113046 [details]
Screenshot - After patch applied and attempting to save the record

I can replicate the issue.

After applying the patches I attempt to add another new record. 

When saving the record, I don't get the add new item screen - see the screenshot attached. 

The record is not added, it shows up in the reservoir, and there are these warnings are in the log:
 66 [2020/11/05 08:29:42] [WARN] DBD::mysql::st execute failed: Data too long for column 'lccn' at row 1 [for Statement "INSERT INTO `biblioitems` ( `agerestriction`, `biblionumber`, `cn_class`, `cn_ite    m`, `cn_sort`, `cn_source`, `cn_suffix`, `collectionissn`, `collectiontitle`, `collectionvolume`, `ean`, `editionresponsibility`, `editionstatement`, `illus`, `isbn`, `issn`, `itemtype`, `lccn`, `no    tes`, `number`, `pages`, `place`, `publicationyear`, `publishercode`, `size`, `timestamp`, `totalissues`, `url`, `volume`, `volumedate`, `volumedesc`) VALUES ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?,     ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, current_timestamp, ?, ?, ?, ?, ? )" with ParamValues: 0=undef, 1='448', 2=undef, 3=undef, 4='', 5="ddc", 6=undef, 7=undef, 8=undef, 9=undef, 10=undef, 11=undef,     12=undef, 13="ill. ;", 14="9780132480529 (pbk. : alk. paper) | 0132480522 (pbk. : alk. paper)", 15=undef, 16="BK", 17="ThisisgoingtobetoomanycharactersfortheLCCNfield", 18=undef, 19=undef, 20="xix,     281 p. :", 21="Upper Saddle River, NJ :", 22=undef, 23="IBM Press : | Pearson,", 24="24 cm.", 25=undef, 26=undef, 27=undef, 28=undef, 29=undef] at /usr/share/perl5/DBIx/Class/Storage/DBI.pm line 183    6.
 67 [2020/11/05 08:29:42] [WARN] DBIx::Class::Storage::DBI::_dbh_execute(): Data too long for column 'lccn' at row 1 at /kohadevbox/koha/Koha/Object.pm line 169
 68 [2020/11/05 08:29:42] [WARN] DBIx::Class::Storage::DBI::_dbh_execute(): Data too long for column 'lccn' at row 1 at /kohadevbox/koha/Koha/Object.pm line 169
 69 [2020/11/05 08:29:42] [WARN] Use of uninitialized value $biblionumber in concatenation (.) or string at /kohadevbox/koha/cataloguing/addbiblio.pl line 870.
 70 [2020/11/05 08:29:42] [WARN] Use of uninitialized value $searchid in concatenation (.) or string at /kohadevbox/koha/cataloguing/addbiblio.pl line 870.
 71 [2020/11/05 08:29:42] [WARN] Use of uninitialized value $frameworkcode in string eq at /kohadevbox/koha/cataloguing/additem.pl line 432.
 72 [2020/11/05 08:29:42] [WARN] GetMarcBiblio called with undefined biblionumber at /kohadevbox/koha/cataloguing/additem.pl line 453.

My notes for testing (koha-testing-docker):
1. Run through the test plan in the bug description
2. Run the tests: prove -v t/db_dependent/Biblio.t - these should pass
3. Delete the record created
4. Apply the patches
5. Repeat the test plan, this time:
   - There should be no errors in /var/log/koha/kohadev/plack-intranet-error.log
   - You should be able to successfully add an item
Comment 20 Victor Grousset/tuxayo 2020-11-12 22:51:38 UTC
> When saving the record, I don't get the add new item screen - see the screenshot attached. 

Same error
Comment 21 Victor Grousset/tuxayo 2020-11-12 22:53:44 UTC
I have still error in logs

> [2020/11/12 22:42:00] [WARN] DBIx::Class::Storage::DBI::_dbh_execute(): Data too long for column 'lccn' at row 1 at /kohadevbox/koha/Koha/Object.pm line 169
> [2020/11/12 22:42:00] [WARN] DBIx::Class::Storage::DBI::_dbh_execute(): Data too long for column 'lccn' at row 1 at /kohadevbox/koha/Koha/Object.pm line 169
Comment 22 Jonathan Druart 2020-11-16 13:10:46 UTC
Yes, that's the expected behaviour. It's not perfect, we should display an error explaining what happened.

The goal of this patch is to not create the entry in the biblio DB table if the biblioitem creation failed.
Comment 23 Victor Grousset/tuxayo 2020-11-16 16:37:23 UTC
Created attachment 113671 [details] [review]
Bug 26518: Use Koha::Biblio[item] in AddBiblio

Bug 26518: Does not return from the catch block

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>
Comment 24 Victor Grousset/tuxayo 2020-11-16 16:37:27 UTC
Created attachment 113672 [details] [review]
Bug 26518: Raise exception if the insert failed

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>
Comment 25 Victor Grousset/tuxayo 2020-11-16 16:37:30 UTC
Created attachment 113673 [details] [review]
Bug 26518: Hide expected DBI warnings

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>
Comment 26 Victor Grousset/tuxayo 2020-11-16 16:37:33 UTC
Created attachment 113674 [details] [review]
Bug 26518: Move BiblioAutoLink within the transaction

We don't want the authorities to be created if the biblio insert fails
later

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>
Comment 27 Victor Grousset/tuxayo 2020-11-16 16:38:07 UTC
> The goal of this patch is to not create the entry in the biblio DB table if the biblioitem creation failed.

Then it works, thanks for the explanations :)
Comment 28 Nick Clemens 2020-11-23 12:11:02 UTC
Created attachment 113917 [details] [review]
Bug 26518: Use Koha::Biblio[item] in AddBiblio

Bug 26518: Does not return from the catch block

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 29 Nick Clemens 2020-11-23 12:11:05 UTC
Created attachment 113918 [details] [review]
Bug 26518: Raise exception if the insert failed

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 30 Nick Clemens 2020-11-23 12:11:08 UTC
Created attachment 113919 [details] [review]
Bug 26518: Hide expected DBI warnings

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 31 Nick Clemens 2020-11-23 12:11:11 UTC
Created attachment 113920 [details] [review]
Bug 26518: Move BiblioAutoLink within the transaction

We don't want the authorities to be created if the biblio insert fails
later

Signed-off-by: Victor Grousset/tuxayo <victor@tuxayo.net>

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 32 Nick Clemens 2020-11-23 12:11:14 UTC
Created attachment 113921 [details] [review]
Bug 26518: (QA follow-up) Expect warnings, don't supress them

Signed-off-by: Nick Clemens <nick@bywatersolutions.com>
Comment 33 Jonathan Druart 2020-11-25 15:19:52 UTC
Pushed to master for 20.11, thanks to everybody involved!
Comment 34 Andrew Fuerste-Henry 2020-12-14 15:27:45 UTC
Pushed to 20.05.x for 20.05.07
Comment 35 Victor Grousset/tuxayo 2020-12-16 18:04:52 UTC
I doesn't seem to work on 19.11.x

1. apply
2. restart services
3. optional: prove t/db_dependent/Biblio.t (passes)
4. fill a record with 010 = ThisisgoingtobetoomanycharactersfortheLCCNfield
5. save
6. error: "Bibliographic record not found."
Comment 36 Victor Grousset/tuxayo 2020-12-16 18:05:58 UTC
*It doesn't


Not backporting unless this is need and a fix is provided.
Comment 37 Victor Grousset/tuxayo 2020-12-16 19:06:36 UTC
Wait, I got confused.
«Yes, that's the expected behaviour»

Ok, will backport.
Comment 38 Victor Grousset/tuxayo 2020-12-16 21:34:09 UTC
Backported to 19.11.x branch for 19.11.13