[MDEV-30518] main.func_json_notembedded fails on s390x: outputs massive amount of text - Jira

Details

Type: Bug
Status: Open (View Workflow)
Priority: Major
Resolution: Unresolved
Affects Version/s: 10.11.5
Fix Version/s: None
Component/s: Tests
Labels:
None

Description

While testing https://github.com/MariaDB/server/pull/2448 and doing builds on multiple architectures I noticed that on Launchpad the s390x build fails on:

...

main.mysqltest_tracking_info             w3 [ pass ]      1

main.negation_elimination                w1 [ pass ]      5

main.nested_profiling                    w3 [ pass ]      2

main.mysql                               w2 [ pass ]  107941

worker[4] Test still running: main.func_json_notembedded

worker[4] Test still running: main.func_json_notembedded

worker[4] Test still running: main.func_json_notembedded

worker[4] Test still running: main.func_json_notembedded

worker[4] Test still running: main.func_json_notembedded

worker[4] Trying to dump core for [mysqltest - pid: 41359, winpid: 41359]

worker[4] Trying to dump core for [mysqld.1 - pid: 40608, winpid: 40608]

main.func_json_notembedded               w4 [ fail ]  timeout after 7200 seconds

        Test ended at 2023-01-30 04:10:27

Test case timeout after 7200 seconds

== /<<PKGBUILDDIR>>/builddir/mysql-test/var/4/log/func_json_notembedded.log ==

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

select json_loose(@arr);

json_loose(@arr)

[1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567,

...

1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 2345678]

select json_merge_patch(@obj, @obj);

 == /<<PKGBUILDDIR>>/builddir/mysql-test/var/4/tmp/analyze-timeout-mysqld.1.err ==

mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local server through socket '/<<PKGBUILDDIR>>/builddir/mysql-test/var/tm' (111)

 - saving '/<<PKGBUILDDIR>>/builddir/mysql-test/var/4/log/main.func_json_notembedded/' to '/<<PKGBUILDDIR>>/builddir/mysql-test/var/log/main.func_json_notembedded/'

Test main.func_json_notembedded has failed 2 times, no more retries!

***Warnings generated in error logs during shutdown after running tests: main.func_json_notembedded

Attempting backtrace. You can use the following information to find out

...

Completed: Failed 2/1030 tests, 99.81% were successful.

Failing test(s): main.func_json_notembedded

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation

at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

Errors/warnings were found in logfiles during server shutdown after running the

following sequence(s) of tests:

    main.fulltext_distinct main.fulltext2 main.func_json_notembedded main.fulltext_derived_4257 main.func_digest main.func_if main.fulltext_derived_4316 main.func_json main.func_int main.func_bit main.func_in main.fulltext_multi main.frm_bad_row_type-7333 main.func_date_add main.fulltext_var main.fulltext3 main.flush_table main.func_isnull main.func_concat main.fulltext main.flush_ssl main.fulltext_update main.func_crypt main.func_encrypt_nossl main.func_default main.func_encrypt_ucs2 main.func_equal main.fulltext_cache main.fulltext_charsets main.fulltext_left_join main.func_des_encrypt main.func_group main.fulltext_order_by main.func_hybrid_type main.func_extract main.func_compress

    main.func_json_notembedded

161 tests were skipped, 63 by the test itself.

...

Full log at https://launchpadlibrarian.net/648708349/buildlog_ubuntu-lunar-s390x.mariadb_1%3A10.11.1-2~ubuntu23.04.1~1675043290.397d3975e3e.dev.otto_BUILDING.txt.gz

This seems a bit similar to ~~MDEV-27955~~, MDEV-28714 and ~~MDEV-24909~~ but none of them had this failure that it prints out the whole output, so filing this as a new bug.

I am aware that MariaDB Foundation might not care about s390x architecture, but often this kind of bugs reveal deeper problems, so it might be good to take a look. As an example the failure originally on armhf that lead to https://github.com/MariaDB/server/pull/2448 was at first just one architecture issue, but later revealed that the time code in question had not been updated in 10+ years and needed to be modernized for the sake of all architectures.

Attachments

Issue Links

relates to

MDEV-27955 main.func_json_notembedded test fails on out-of-memory on MariaDB 10.6.7

Closed

Activity

Ascending order - Click to sort in descending order

Otto Kekäläinen added a comment - 2023-02-05 21:21

In ~~MDEV-27955~~ the test required too much memory or was too slow and timed out.

Time out happened again on hppa in https://buildd.debian.org/status/fetch.php?pkg=mariadb&arch=hppa&ver=1%3A10.11.1-2&stamp=1675231483&raw=0

Otto Kekäläinen added a comment - 2023-02-05 21:21 In MDEV-27955 the test required too much memory or was too slow and timed out. Time out happened again on hppa in https://buildd.debian.org/status/fetch.php?pkg=mariadb&arch=hppa&ver=1%3A10.11.1-2&stamp=1675231483&raw=0

Otto Kekäläinen added a comment - 2023-02-05 21:33

The test failure on ppc64 is probably also related as it crashes/timeouts on this same test:

Otto Kekäläinen added a comment - 2023-02-05 21:33 The test failure on ppc64 is probably also related as it crashes/timeouts on this same test: https://buildd.debian.org/status/fetch.php?pkg=mariadb&arch=ppc64&ver=1%3A10.11.1-2&stamp=1675212385&raw=0 https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1029374

Otto Kekäläinen added a comment - 2023-02-10 17:14

The same failure was now also seen on sparc64 in https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1030630

Otto Kekäläinen added a comment - 2023-02-10 17:14 The same failure was now also seen on sparc64 in https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1030630

Ehsan Kiani Far added a comment - 2023-07-25 19:50

I tried to manually run this test on s390x and x64 by running this query:

set @obj=concat_ws('','{', repeat('"a":"b",', 1250000/2), '"c":"d"}');

set @arr=concat_ws('','[', repeat('1234567,', 1250000/2), '2345678]');

select length(@obj), length(@arr);

set max_statement_time=0.0001;

select json_array_append(@arr, '$[0]', 1);

on x64, the `select json_array_append(@arr, '$[0]', 1);` query results an error as expected since it takes much more that `max_statement_time` limit.
on s390x on the other hand, it completes the query and returns the result in about 0.137 (`1 row in set (0.137 sec)`) seconds which is much more that the configured `max_statement_time`. the logic for the expected behaviour was implemented in https://jira.mariadb.org/browse/MDEV-24909 issue with this PR: https://github.com/MariaDB/server/commit/7808cf9a8b4430262df23b6410de61c499ee740d
that implementation fixed the issue on x64 but that doesn't work on s390x. Any idea what might be wrong?

Ehsan Kiani Far added a comment - 2023-07-25 19:50 I tried to manually run this test on s390x and x64 by running this query: set @obj=concat_ws( '' , '{' , repeat( '"a":"b",' , 1250000/2), '"c":"d"}' ); set @arr=concat_ws( '' , '[' , repeat( '1234567,' , 1250000/2), '2345678]' ); select length(@obj), length(@arr); set max_statement_time=0.0001; select json_array_append(@arr, '$[0]' , 1); on x64, the `select json_array_append(@arr, '$ [0] ', 1);` query results an error as expected since it takes much more that `max_statement_time` limit. on s390x on the other hand, it completes the query and returns the result in about 0.137 (`1 row in set (0.137 sec)`) seconds which is much more that the configured `max_statement_time`. the logic for the expected behaviour was implemented in https://jira.mariadb.org/browse/MDEV-24909 issue with this PR: https://github.com/MariaDB/server/commit/7808cf9a8b4430262df23b6410de61c499ee740d that implementation fixed the issue on x64 but that doesn't work on s390x. Any idea what might be wrong?

Otto Kekäläinen added a comment - 2023-10-07 05:36

I ran all tests on all available architectures at https://launchpad.net/~otto/+archive/ubuntu/mariadb/+builds?build_text=&build_state=all and this failure with long string of 1234567, 1234567, 1234567, 1234567... is still visible on multiple architectures.

Otto Kekäläinen added a comment - 2023-10-07 05:36 I ran all tests on all available architectures at https://launchpad.net/~otto/+archive/ubuntu/mariadb/+builds?build_text=&build_state=all and this failure with long string of 1234567, 1234567, 1234567, 1234567... is still visible on multiple architectures.

Otto Kekäläinen added a comment - 2023-10-09 18:29

So it has been established that this is not s390x-specific, but can happen on multiple architectures. However for some reason it seems to be most frequent on s390x.

Output from https://launchpadlibrarian.net/691064783/buildlog_ubuntu-mantic-s390x.mariadb_1%3A10.11.5-3~bpo23.10.1~1696830433.49186426d72+feature.re.enable.all.tests_BUILDING.txt.gz

worker[1] Test still running: main.func_json_notembedded

worker[1] Test still running: main.func_json_notembedded

worker[1] Test still running: main.func_json_notembedded

worker[1] Test still running: main.func_json_notembedded

worker[1] Test still running: main.func_json_notembedded

worker[1] Trying to dump core for [mysqltest - pid: 262516, winpid: 262516]

worker[1] Trying to dump core for [mysqld.1 - pid: 261907, winpid: 261907]

main.func_json_notembedded               w1 [ fail ]  timeout after 7200 seconds

        Test ended at 2023-10-09 08:50:09

Test case timeout after 7200 seconds

== /<<PKGBUILDDIR>>/builddir/mysql-test/var/1/log/func_json_notembedded.log ==

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

    1234567,

select json_loose(@arr);

json_loose(@arr)

[1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567,

...

1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 2345678]

select json_merge(@obj, @arr);

json_merge(@obj, @arr)

[{"a": "b", "a": "b", "a": "b", "a": "b", "a": "b", "a": "b", "a": "b", "a": "b",

...

"b", "a": "b", "a": "b", "a": "b", "a": "b", "c": "d"}, 1234567, 1234567, 1234567, 1234567, 1234567,

...

1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 2345678]

select json_merge(@obj, @arr);

json_merge(@obj, @arr)

[{"a": "b", "a": "b", "a": "b", "a": "b", "a": "b",

...

"b", "a": "b", "a": "b", "c": "d"}, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567,

...

1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 2345678]

select json_merge_patch(@obj, @obj);

 == /<<PKGBUILDDIR>>/builddir/mysql-test/var/1/tmp/analyze-timeout-mysqld.1.err ==

mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local server through socket '/<<PKGBUILDDIR>>/builddir/mysql-test/var/tm' (111)

 - skipping '/<<PKGBUILDDIR>>/builddir/mysql-test/var/1/log/main.func_json_notembedded/'

Test main.func_json_notembedded has failed 2 times, no more retries!

***Warnings generated in error logs during shutdown after running tests: main.func_json_notembedded

Attempting backtrace. You can use the following information to find out

No backtrace is printed though.

Otto Kekäläinen added a comment - 2023-10-09 18:29 So it has been established that this is not s390x-specific, but can happen on multiple architectures. However for some reason it seems to be most frequent on s390x. Output from https://launchpadlibrarian.net/691064783/buildlog_ubuntu-mantic-s390x.mariadb_1%3A10.11.5-3~bpo23.10.1~1696830433.49186426d72+feature.re.enable.all.tests_BUILDING.txt.gz worker[1] Test still running: main.func_json_notembedded worker[1] Test still running: main.func_json_notembedded worker[1] Test still running: main.func_json_notembedded worker[1] Test still running: main.func_json_notembedded worker[1] Test still running: main.func_json_notembedded worker[1] Trying to dump core for [mysqltest - pid: 262516, winpid: 262516] worker[1] Trying to dump core for [mysqld.1 - pid: 261907, winpid: 261907] main.func_json_notembedded w1 [ fail ] timeout after 7200 seconds Test ended at 2023-10-09 08:50:09 Test case timeout after 7200 seconds == /<<PKGBUILDDIR>>/builddir/mysql-test/var/1/log/func_json_notembedded.log == 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 2345678 ] select json_loose(@arr); json_loose(@arr) [1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, ... 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 2345678] select json_merge(@obj, @arr); json_merge(@obj, @arr) [{"a": "b", "a": "b", "a": "b", "a": "b", "a": "b", "a": "b", "a": "b", "a": "b", ... "b", "a": "b", "a": "b", "a": "b", "a": "b", "c": "d"}, 1234567, 1234567, 1234567, 1234567, 1234567, ... 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 2345678] select json_merge(@obj, @arr); json_merge(@obj, @arr) [{"a": "b", "a": "b", "a": "b", "a": "b", "a": "b", ... "b", "a": "b", "a": "b", "c": "d"}, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, ... 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 1234567, 2345678] select json_merge_patch(@obj, @obj); == /<<PKGBUILDDIR>>/builddir/mysql-test/var/1/tmp/analyze-timeout-mysqld.1.err == mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local server through socket '/<<PKGBUILDDIR>>/builddir/mysql-test/var/tm' (111) - skipping '/<<PKGBUILDDIR>>/builddir/mysql-test/var/1/log/main.func_json_notembedded/' Test main.func_json_notembedded has failed 2 times, no more retries! ***Warnings generated in error logs during shutdown after running tests: main.func_json_notembedded Attempting backtrace. You can use the following information to find out No backtrace is printed though.

Otto Kekäläinen added a comment - 2025-04-19 20:08

Seems this test is nowadays automatically skipped in default build/test suite:

main.func_json_notembedded               [ skipped ]  Requires debug build

Otto Kekäläinen added a comment - 2025-04-19 20:08 Seems this test is nowadays automatically skipped in default build/test suite: main.func_json_notembedded [ skipped ] Requires debug build

People

Assignee:: Unassigned

Reporter:: Otto Kekäläinen

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Dates

Created:: 2023-01-31 06:17

Updated:: 3 days ago 08:52

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server