Bug 23825 - Object.t is failing - Exception not caught
Summary: Object.t is failing - Exception not caught
Status: CLOSED FIXED
Alias: None
Product: Koha
Classification: Unclassified
Component: Test Suite (show other bugs)
Version: unspecified
Hardware: All All
: P5 - low normal (vote)
Assignee: Marcel de Rooy
QA Contact: Tomás Cohen Arazi
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-10-16 13:16 UTC by Jonathan Druart
Modified: 2021-06-14 21:29 UTC (History)
4 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:
19.11.00, 19.05.12


Attachments
Bug 23825: Koha/Object.t might fail on a backtick (1.47 KB, patch)
2019-10-18 09:34 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 23825: Add tests (1.43 KB, patch)
2019-10-24 10:51 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 23825: Koha/Object.t might fail on a backtick (1.61 KB, patch)
2019-10-24 12:38 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 23825: Add tests (1.64 KB, patch)
2019-10-24 12:39 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 23825: (QA follow-up) Remove database name (2.38 KB, patch)
2019-10-28 09:03 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 23825: (QA follow-up) Remove database name (2.44 KB, patch)
2019-10-28 09:03 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 23825: table name is not always displayed (1.08 KB, patch)
2019-11-05 10:09 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 23825: table name is not always displayed (1.17 KB, patch)
2019-11-05 13:13 UTC, Marcel de Rooy
Details | Diff | Splinter Review
Bug 23825: Koha/Object.t might fail on a backtick (1.64 KB, patch)
2019-11-13 16:17 UTC, Martin Renvoize
Details | Diff | Splinter Review
Bug 23825: Add tests (1.66 KB, patch)
2019-11-13 16:17 UTC, Martin Renvoize
Details | Diff | Splinter Review
Bug 23825: (QA follow-up) Remove database name (2.46 KB, patch)
2019-11-13 16:17 UTC, Martin Renvoize
Details | Diff | Splinter Review
Bug 23825: table name is not always displayed (1.19 KB, patch)
2019-11-13 16:17 UTC, Martin Renvoize
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Jonathan Druart 2019-10-16 13:16:08 UTC
Something weird here:

kohadev-koha@kohadevbox:/home/vagrant/kohaclone$ prove t/db_dependent/Koha/Object.t
t/db_dependent/Koha/Object.t .. 3/11
        #   Failed test 'Exception thrown correctly'
        #   at t/db_dependent/Koha/Object.t line 359.
        # expecting: Koha::Exceptions::Object::BadValue
        # found: DBIx::Class::Exception (DBIx::Class::Storage::DBI::_dbh_execute(): Incorrect datetime value: 'wrong_value' for column `koha_kohadev`.`borrowers`.`lastseen` at row 1 at /home/vagrant/kohaclone/Koha/Object.pm line 156
        # )
        # Looks like you failed 1 test of 1.

    #   Failed test 'Bad value tests'
    #   at t/db_dependent/Koha/Object.t line 363.
    # Looks like you failed 1 test of 16.


Not on Jenkins

It's the following exception's message that is not caught correctly by the regex:
DBIx::Class::Storage::DBI::_dbh_execute(): Incorrect datetime value: 'wrong_value' for column `koha_kohadev`.`borrowers`.`lastseen` at row 1 at /home/vagrant/kohaclone/Koha/Object.pm line 156

Note the backticks.
Comment 1 Jonathan Druart 2019-10-16 13:24:13 UTC
FWIW I get the test passed with:

-            elsif( $_->{msg} =~ /Incorrect (?<type>\w+) value: '(?<value>.*)' for column '(?<property>\w+)'/ ) {
+            elsif( $_->{msg} =~ /Incorrect (?<type>\w+) value: '(?<value>.*)' for column (?<property>`\w+)/ ) {


But I guess it will make it failed for someone else.
Comment 2 Marcel de Rooy 2019-10-18 09:34:25 UTC
Created attachment 94401 [details] [review]
Bug 23825: Koha/Object.t might fail on a backtick

If the SQL error message contains a backtick instead of a regular quote,
the regex for throwing an exception did not work.
Example:
Incorrect datetime value: 'wrong_value' for column `koha_master`.`borrowers`.`lastseen`
Note the backtics where the regex contains a regular quote.

This patch makes it more flexible: it allows one \W character before the
column name, even optional.

Test plan:
Run Koha/Object.t

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 3 Marcel de Rooy 2019-10-18 09:35:05 UTC
(In reply to Jonathan Druart from comment #1)
> FWIW I get the test passed with:
> 
> -            elsif( $_->{msg} =~ /Incorrect (?<type>\w+) value:
> '(?<value>.*)' for column '(?<property>\w+)'/ ) {
> +            elsif( $_->{msg} =~ /Incorrect (?<type>\w+) value:
> '(?<value>.*)' for column (?<property>`\w+)/ ) {
> 
> 
> But I guess it will make it failed for someone else.

Yeah but we can make it a bit more flexible. See my patch. Could you QA it ?
Comment 4 Marcel de Rooy 2019-10-18 09:35:39 UTC
Moving to SO: trivial change
Comment 5 Jonathan Druart 2019-10-24 10:51:37 UTC
Created attachment 94654 [details] [review]
Bug 23825: Add tests
Comment 6 Jonathan Druart 2019-10-24 10:53:34 UTC
Marcel, I do not think it is correct. I have added some tests (they should not be there, I would have expected t/Koha/Exceptions.t to test that part). However I am not sure about the property. What was it before? table.column or only column?
Anyway, now it's the DB name, which is obviously wrong.
Comment 7 Marcel de Rooy 2019-10-24 12:04:41 UTC
Hmm Will have a look
Comment 8 Marcel de Rooy 2019-10-24 12:11:44 UTC
(In reply to Jonathan Druart from comment #6)
> Marcel, I do not think it is correct. I have added some tests (they should
> not be there, I would have expected t/Koha/Exceptions.t to test that part).
> However I am not sure about the property. What was it before? table.column
> or only column?
> Anyway, now it's the DB name, which is obviously wrong.

You're right about the db name.
But previously it did not work either. Apart from the quote, it also picked the first word (so the database).
I will parse the whole thing into the property field. Hang on
Comment 9 Marcel de Rooy 2019-10-24 12:38:56 UTC
Created attachment 94661 [details] [review]
Bug 23825: Koha/Object.t might fail on a backtick

If the SQL error message contains a backtick instead of a regular quote,
the regex for throwing an exception did not work.
Example:
Incorrect datetime value: 'wrong_value' for column `koha_master`.`borrowers`.`lastseen`
Note the backtics where the regex contains a regular quote.

This patch makes it more flexible: it allows one \W character before the
column name, even optional.

Test plan:
Run Koha/Object.t

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 10 Marcel de Rooy 2019-10-24 12:39:00 UTC
Created attachment 94662 [details] [review]
Bug 23825: Add tests

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
[EDIT]
Changed 'is' to 'like' with regex since we also have the db name.
Comment 11 Jonathan Druart 2019-10-24 13:55:39 UTC
Do we know to root of the issue? Why do we have those tests failing suddenly?
Comment 12 Marcel de Rooy 2019-10-24 13:59:18 UTC
(In reply to Jonathan Druart from comment #11)
> Do we know to root of the issue? Why do we have those tests failing suddenly?

Trigger for this report was the See also.
Comment 13 Jonathan Druart 2019-10-24 14:13:20 UTC
(In reply to Marcel de Rooy from comment #12)
> (In reply to Jonathan Druart from comment #11)
> > Do we know to root of the issue? Why do we have those tests failing suddenly?
> 
> Trigger for this report was the See also.

Yes, but it was not related. The issue existed before these patches were pushed.
Comment 14 Marcel de Rooy 2019-10-25 06:43:37 UTC
(In reply to Jonathan Druart from comment #13)
> (In reply to Marcel de Rooy from comment #12)
> > (In reply to Jonathan Druart from comment #11)
> > > Do we know to root of the issue? Why do we have those tests failing suddenly?
> > 
> > Trigger for this report was the See also.
> 
> Yes, but it was not related. The issue existed before these patches were
> pushed.

OK. There are two things:

[1] Your second patch here introduces using the captured names of the regex like property. Which actually had the wrong value in the first place, but it was not used yet. So undetected.
[2] On the see also report I noted that the regex in sub store did not work. Probably due to a difference between MySQL and MariaDB in using regular quotes or backtics.
Comment 15 Jonathan Druart 2019-10-25 09:39:40 UTC
(In reply to Marcel de Rooy from comment #14)
> (In reply to Jonathan Druart from comment #13)
> > (In reply to Marcel de Rooy from comment #12)
> > > (In reply to Jonathan Druart from comment #11)
> > > > Do we know to root of the issue? Why do we have those tests failing suddenly?
> > > 
> > > Trigger for this report was the See also.
> > 
> > Yes, but it was not related. The issue existed before these patches were
> > pushed.
> 
> OK. There are two things:
> 
> [1] Your second patch here introduces using the captured names of the regex
> like property. Which actually had the wrong value in the first place, but it
> was not used yet. So undetected.
> [2] On the see also report I noted that the regex in sub store did not work.
> Probably due to a difference between MySQL and MariaDB in using regular
> quotes or backtics.

Marcel, I think we should not display the DB name in the message.
Comment 16 Marcel de Rooy 2019-10-28 09:03:13 UTC Comment hidden (obsolete)
Comment 17 Marcel de Rooy 2019-10-28 09:03:55 UTC
Created attachment 94804 [details] [review]
Bug 23825: (QA follow-up) Remove database name

As requested on comment15.

Test plan:
Run t/db_dependent/Koha/Object.t again

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 18 Tomás Cohen Arazi 2019-10-28 17:45:53 UTC
I'm having trouble reproducing this issue. Can you elaborate on the MySQL/MariaDB versions you are testing in?
Comment 19 Marcel de Rooy 2019-10-29 15:38:31 UTC
(In reply to Tomás Cohen Arazi from comment #18)
> I'm having trouble reproducing this issue. Can you elaborate on the
> MySQL/MariaDB versions you are testing in?

Thx for trying.
mysql -v
Server version: 10.4.4-MariaDB-1:10.4.4+maria~bionic mariadb.org binary distribution
Running in a Docker container btw.
Comment 20 Jonathan Druart 2019-10-30 07:39:25 UTC
10.4.8-MariaDB-1:10.4.8+maria~stretch for me. Note that I upgraded using a specific repo (to get the latest), before (last week) I had the one packaged for Stretch and got the same failure.
Comment 21 Martin Renvoize 2019-10-31 16:17:15 UTC
I've now updated Jenkins to test a broader range of DB servers, but I've stuck to those that ship by default with our chosen supported OS's.. and as such we still won't be catching a DB server this new.. should we do you think?
Comment 22 Marcel de Rooy 2019-10-31 20:58:34 UTC
(In reply to Martin Renvoize from comment #21)
> I've now updated Jenkins to test a broader range of DB servers, but I've
> stuck to those that ship by default with our chosen supported OS's.. and as
> such we still won't be catching a DB server this new.. should we do you
> think?

Dont think so as to Jenkins personally. But this report actually only is about the type of quotes used in an error message, adds tests and improves the regex. So I do not really understand why this keeps hanging..
Comment 23 Martin Renvoize 2019-11-04 16:19:23 UTC
Downgrading from Major as this only affects very new DBMS versions which the majority of people will not be running.

Having said that, so long as it doesn't break tests on the current stable DBMS versions then I don't have a problem with pushing it.

I've not tested this yet myself, but if someone here can verify the tests continue to work with MySQL5.5, MariaDB10.1 and MariaDB10.3 then this feels OK to push at this point.
Comment 24 Jonathan Druart 2019-11-05 10:03:39 UTC
10.4.8-MariaDB-1:10.4.8+maria~stretch
  master: fail
  with patches: ok

10.1.41-MariaDB-0+deb9u1
  master: ok
  with patches: fail

        #   Failed test 'Column should be the expected one'
        #   at t/db_dependent/Koha/Object.t line 413.
        #                   'lastseen'
        #     doesn't match '(?^u:borrowers\.lastseen)'
        # Looks like you failed 1 test of 3.
Comment 25 Jonathan Druart 2019-11-05 10:09:29 UTC
Created attachment 95044 [details] [review]
Bug 23825: table name is not always displayed
Comment 26 Jonathan Druart 2019-11-05 10:10:21 UTC
With this last patch I got the tests passing for both 10.4.8-MariaDB-1:10.4.8+maria~stretch and 10.1.41-MariaDB-0+deb9u1
Comment 27 Marcel de Rooy 2019-11-05 13:13:54 UTC
Created attachment 95053 [details] [review]
Bug 23825: table name is not always displayed

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Comment 28 Martin Renvoize 2019-11-13 16:17:14 UTC
Created attachment 95402 [details] [review]
Bug 23825: Koha/Object.t might fail on a backtick

If the SQL error message contains a backtick instead of a regular quote,
the regex for throwing an exception did not work.
Example:
Incorrect datetime value: 'wrong_value' for column `koha_master`.`borrowers`.`lastseen`
Note the backtics where the regex contains a regular quote.

This patch makes it more flexible: it allows one \W character before the
column name, even optional.

Test plan:
Run Koha/Object.t

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 29 Martin Renvoize 2019-11-13 16:17:19 UTC
Created attachment 95403 [details] [review]
Bug 23825: Add tests

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
[EDIT]
Changed 'is' to 'like' with regex since we also have the db name.
Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 30 Martin Renvoize 2019-11-13 16:17:23 UTC
Created attachment 95404 [details] [review]
Bug 23825: (QA follow-up) Remove database name

As requested on comment15.

Test plan:
Run t/db_dependent/Koha/Object.t again

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 31 Martin Renvoize 2019-11-13 16:17:28 UTC
Created attachment 95405 [details] [review]
Bug 23825: table name is not always displayed

Signed-off-by: Marcel de Rooy <m.de.rooy@rijksmuseum.nl>
Signed-off-by: Martin Renvoize <martin.renvoize@ptfs-europe.com>
Comment 32 Martin Renvoize 2019-11-13 16:17:59 UTC
Thanks for the perseverance here guys, Passing QA
Comment 33 Martin Renvoize 2019-11-13 16:23:52 UTC
Nice work!

Pushed to master for 19.11.00
Comment 34 Victor Grousset/tuxayo 2020-06-22 19:56:34 UTC
While testing the advertised "Experimental MariaDB 10.3 support" for 19.05.x, it turns out that this patch applied and fix two failure.

Will try to backport for 19.11.13

For the record the fixed failures are:

kohadev-koha@665e4031f5cf:/kohadevbox/koha$ time prove -r t/db_dependent/Circulation/MarkIssueReturned.t t/db_dependent/Koha/Object.t
t/db_dependent/Circulation/MarkIssueReturned.t .. 2/4 DBD::mysql::st execute failed: Incorrect datetime value: 'bad_date' for column `koha_kohadev`.`issues`.`returndate` at row 1 [for Statement "UPDATE `issues` SET `returndate` = ? WHERE ( `issue_id` = ? )" with ParamValues: 0='bad_date', 1=252] at /usr/share/perl5/DBIx/Class/Storage/DBI.pm line 1836.

    #   Failed test 'An exception is thrown on bad date'
    #   at t/db_dependent/Circulation/MarkIssueReturned.t line 181.
    # expecting: Koha::Exceptions::Object::BadValue
    # found: DBIx::Class::Exception (DBIx::Class::Storage::DBI::_dbh_execute(): Incorrect datetime value: 'bad_date' for column `koha_kohadev`.`issues`.`returndate` at row 1 at /kohadevbox/koha/Koha/Object.pm line 157
    # )
    # Looks like you failed 1 test of 3.
t/db_dependent/Circulation/MarkIssueReturned.t .. 3/4 
#   Failed test 'Manually pass a return date'
#   at t/db_dependent/Circulation/MarkIssueReturned.t line 185.
t/db_dependent/Circulation/MarkIssueReturned.t .. 4/4 # Looks like you failed 1 test of 4.
t/db_dependent/Circulation/MarkIssueReturned.t .. Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/4 subtests 
t/db_dependent/Koha/Object.t .................... 7/12 
        #   Failed test 'Exception thrown correctly'
        #   at t/db_dependent/Koha/Object.t line 359.
        # expecting: Koha::Exceptions::Object::BadValue
        # found: DBIx::Class::Exception (DBIx::Class::Storage::DBI::_dbh_execute(): Incorrect datetime value: 'wrong_value' for column `koha_kohadev`.`borrowers`.`lastseen` at row 1 at /kohadevbox/koha/Koha/Object.pm line 157
        # )
        # Looks like you failed 1 test of 1.

    #   Failed test 'Bad value tests'
    #   at t/db_dependent/Koha/Object.t line 363.
    # Looks like you failed 1 test of 16.
t/db_dependent/Koha/Object.t .................... 10/12 
#   Failed test 'store() tests'
#   at t/db_dependent/Koha/Object.t line 366.
# Looks like you failed 1 test of 12.
t/db_dependent/Koha/Object.t .................... Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/12 subtests 

Test Summary Report
-------------------
t/db_dependent/Circulation/MarkIssueReturned.t (Wstat: 256 Tests: 4 Failed: 1)
  Failed test:  3
  Non-zero exit status: 1
t/db_dependent/Koha/Object.t                  (Wstat: 256 Tests: 12 Failed: 1)
  Failed test:  10
  Non-zero exit status: 1
Files=2, Tests=16, 13 wallclock secs ( 0.05 usr  0.01 sys +  9.84 cusr  1.82 csys = 11.72 CPU)
Result: FAIL
Comment 35 Victor Grousset/tuxayo 2020-06-22 23:22:53 UTC
Good news: Backported to 19.05.x branch for 19.05.12

Thanks Tomas for the additional analysis :)