[MDEV-8981] [PATCH] main.analyze_format_json fails when test runs for an extended time Created: 2015-10-21  Updated: 2023-11-30  Resolved: 2015-11-06

Status: Closed
Project: MariaDB Server
Component/s: Admin statements, Tests
Affects Version/s: 10.1.8
Fix Version/s: 10.1.9

Type: Bug Priority: Major
Reporter: Brian Evans Assignee: Sergei Petrunia
Resolution: Fixed Votes: 0
Labels: analyze-stmt, patch
Environment:

Gentoo

Issue Links:
Relates
relates to MDEV-32910 cycles can overflow and result in lar... Stalled
Sprint: 10.1.9-1, 10.1.9-2

 Description   

It seems the replace syntax does not take into account exponential numbers.

main.analyze_format_json                 w2 [ fail ]
 
        Test ended at 2015-10-21 14:21:39
 
 
 
CURRENT_TEST: main.analyze_format_json
 
--- /var/tmp/portage/dev-db/mariadb-10.1.8/work/mysql/mysql-test/r/analyze_format_json.result   2015-10-15 11:43:37.000000000 -0400
 
+++ /var/tmp/portage/dev-db/mariadb-10.1.8/work/mysql/mysql-test/r/analyze_format_json.reject   2015-10-21 14:21:39.462940038 -0400
 
@@ -302,7 +302,7 @@
 
   "query_block": {
 
     "select_id": 1,
 
     "r_loops": 1,
 
-    "r_total_time_ms": "REPLACED",
 
+    "r_total_time_ms": "REPLACED"e12,
 
     "table": {
 
       "table_name": "t1",
 
       "access_type": "range",
 
@@ -313,7 +313,7 @@
 
       "r_loops": 1,
 
       "rows": 11,
 
       "r_rows": 10,
 
-      "r_total_time_ms": "REPLACED",
 
+      "r_total_time_ms": "REPLACED"e12,
 
       "filtered": 100,
 
       "r_filtered": 50,
 
       "index_condition": "(t1.pk < 10)",
 
 
 
mysqltest: Result length mismatch
 
 
 
 - saving '/var/tmp/portage/dev-db/mariadb-10.1.8/temp/var-tests/2/log/main.analyze_format_json/' to '/var/tmp/portage/dev-db/mariadb-10.1.8/temp/var-tests/log/main.analyze_format_json/'



 Comments   
Comment by Elena Stepanova [ 2015-10-23 ]

grknight,

Did you do anything special to achieve this?
I can of course fix the test, but I'm not sure it is supposed to happen at all, so I want to figure out the reason first.

Comment by Daniel Black [ 2015-10-23 ]

Exec_time_tracker (sql/sql_analyze_stmt.h) would indicate that its just overflowed a ulonglong (Xe12 puts it in the ballpark of the max ulonglong value)..

my_timer_cycles relies on the asm instruction rdtsc which is just a 64 bit register.

so maybe the stop_tracking function there needs to account for overflowing between calls.

Comment by Brian Evans [ 2015-10-23 ]

@elenst

No, I did not. It was simply run on a VM which did not necessarily have the fastest resources.

Comment by Daniel Black [ 2015-10-24 ]

Thanks grknight, seems you where lucky enough to see an event that may not happen that often. If you didnt' see it I guess we'd get occasional reports of billion second queries in JSON that really took microseconds.

reworked patch and tested overflow maths. Looked at disassembly to verify it wasn't just a compiler optimisation.

disassembly of main part of test program in commit message:

0000000000400536 <main>:
 
  400536:       55                      push   %rbp
 
  400537:       48 89 e5                mov    %rsp,%rbp
 
  40053a:       48 83 ec 20             sub    $0x20,%rsp
 
  40053e:       48 c7 45 f0 e1 ff ff    movq   $0xffffffffffffffe1,-0x10(%rbp)
 
  400545:       ff 
  400546:       48 c7 45 e8 58 02 00    movq   $0x258,-0x18(%rbp)
 
  40054d:       00 
  40054e:       48 c7 45 f8 10 27 00    movq   $0x2710,-0x8(%rbp)
 
  400555:       00 
  400556:       48 8b 45 e8             mov    -0x18(%rbp),%rax
 
  40055a:       48 2b 45 f0             sub    -0x10(%rbp),%rax
 
  40055e:       48 01 45 f8             add    %rax,-0x8(%rbp)
 
  400562:       48 8b 45 e8             mov    -0x18(%rbp),%rax
 
  400566:       48 3b 45 f0             cmp    -0x10(%rbp),%rax
 
  40056a:       0f 92 c0                setb   %al
 
  40056d:       0f b6 c0                movzbl %al,%eax
 
  400570:       48 85 c0                test   %rax,%rax
 
  400573:       74 05                   je     40057a <main+0x44>
 
  400575:       48 83 6d f8 01          subq   $0x1,-0x8(%rbp)
 
  40057a:       48 8b 45 f8             mov    -0x8(%rbp),%rax
 
  40057e:       48 89 c6                mov    %rax,%rsi
 
  400581:       bf 30 06 40 00          mov    $0x400630,%edi
 
  400586:       b8 00 00 00 00          mov    $0x0,%eax
 
  40058b:       e8 80 fe ff ff          callq  400410 <printf@plt>

Comment by Sergei Petrunia [ 2015-11-06 ]

Merged the pull request. danblack, grknight, thanks!

Generated at Thu Feb 08 07:31:14 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.