[MDEV-27802] Server crashes while continuously inserting records with MediumBlob data field. Created: 2022-02-11  Updated: 2022-02-11

Status: Open
Project: MariaDB Server
Component/s: None
Affects Version/s: 10.5.12
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Jelari Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: innodb
Environment:

Raspberry PI - 4B ( 4GB Ram), mariadb version 10.5.12


 Description   

*1) I created a table with multiple columns of Medium Blob field. *

create table TABLE1(B1 MEDIUMBLOB, B2 MEDIUMBLOB, B3 MEDIUMBLOB, B4 MEDIUMBLOB, B5 MEDIUMBLOB, B6 MEDIUMBLOB, B7 MEDIUMBLOB, B8 MEDIUMBLOB, B9 MEDIUMBLOB, B10 MEDIUMBLOB);

2) the client code is in JavaScript-NodeJs combo. Below is the code for your reference.

const mysql = require("mysql");
 
var i=0;
 
 
 
const db = mysql.createPool({
 
  user: "root",
 
  host: "localhost",
 
  password: "1234",
 
  database: "testDB",
 
});
 
var q=0;
 
for (var a=0;a<1000;a++){
 
	console.log("before query: " + a);
 
db.query(
 
    `INSERT INTO TABLE1(B1, B2, B3, B4, B5, B6, B7, B8, B9, B10) VALUES(load_file("/var/lib/mysql-files/binfile1"),load_file("/var/lib/mysql-files/binfile2"),load_file("/var/lib/mysql-files/binfile1"),load_file("/var/lib/mysql-files/binfile1"),"NA","NA","NA","NA", "NA", "NA")`,
 
    (err, result) => {
 
      if (err) {
 
        console.log("error", err);
 
      } else {
 
        console.log("query successs: " + q++);
 
      }
 
    }
 
);
 
i++;
 
}

*AFter some time I receive the below error. *

Feb 11 02:42:57 raspberrypi mariadbd[11825]: 2022-02-11  2:42:57 213 [Warning] Aborted      connection 213 to db: 'testDB' user: 'root' host: 'localhost' (Got an error reading c     ommunication packets)
 
4975 Feb 11 02:59:10 raspberrypi mariadbd[11825]: 2022-02-11  2:59:10 0 [ERROR] InnoDB: Spa     ce id and page no stored in the page, read in are [page id: space=9, page number=97984     ], should be [page id: space=9, page number=360128]
 
4976 Feb 11 02:59:10 raspberrypi mariadbd[11825]: InnoDB: Next record offset is nonsensical      52955 in record at offset 101
 
4977 Feb 11 02:59:10 raspberrypi mariadbd[11825]: InnoDB: rec address 0x9eb7c065, space id      9, page 97984
 
4978 Feb 11 02:59:10 raspberrypi mariadbd[11825]: 2022-02-11 02:59:10 0x999f5380  InnoDB: A     ssertion failure in file ./storage/innobase/include/page0page.ic line 445
 
4979 Feb 11 02:59:10 raspberrypi mariadbd[11825]: InnoDB: We intentionally generate a memor     y trap.
 
4980 Feb 11 02:59:10 raspberrypi mariadbd[11825]: InnoDB: Submit a detailed bug report to h     ttps://jira.mariadb.org/
 
4981 Feb 11 02:59:10 raspberrypi mariadbd[11825]: InnoDB: If you get repeated assertion fai     lures or crashes, even
 
4982 Feb 11 02:59:10 raspberrypi mariadbd[11825]: InnoDB: immediately after the mysqld star     tup, there may be
 
Feb 11 02:59:10 raspberrypi mariadbd[11825]: InnoDB: corruption in the InnoDB tablespa     ce. Please refer to
 
4984 Feb 11 02:59:10 raspberrypi mariadbd[11825]: InnoDB: https://mariadb.com/kb/en/library     /innodb-recovery-modes/
 
4985 Feb 11 02:59:10 raspberrypi mariadbd[11825]: InnoDB: about forcing recovery.
 
4986 Feb 11 02:59:10 raspberrypi mariadbd[11825]: 220211  2:59:10 [ERROR] mysqld got signal      6 ;
 
4987 Feb 11 02:59:10 raspberrypi mariadbd[11825]: This could be because you hit a bug. It i     s also possible that this binary
 
4988 Feb 11 02:59:10 raspberrypi mariadbd[11825]: or one of the libraries it was linked aga     inst is corrupt, improperly built,
 
4989 Feb 11 02:59:10 raspberrypi mariadbd[11825]: or misconfigured. This error can also be      caused by malfunctioning hardware.
 
4990 Feb 11 02:59:10 raspberrypi mariadbd[11825]: To report this bug, see https://mariadb.c     om/kb/en/reporting-bugs
 
4991 Feb 11 02:59:10 raspberrypi mariadbd[11825]: We will try our best to scrape up some in     fo that will hopefully help
 
4992 Feb 11 02:59:10 raspberrypi mariadbd[11825]: diagnose the problem, but since we have a     lready crashed,
 
4993 Feb 11 02:59:10 raspberrypi mariadbd[11825]: something is definitely wrong and this ma     y fail.
 
Feb 11 02:59:10 raspberrypi mariadbd[11825]: Server version: 10.5.12-MariaDB-0+deb11u1
 
4995 Feb 11 02:59:10 raspberrypi mariadbd[11825]: key_buffer_size=134217728
 
4996 Feb 11 02:59:10 raspberrypi mariadbd[11825]: read_buffer_size=131072
 
4997 Feb 11 02:59:10 raspberrypi mariadbd[11825]: max_used_connections=12
 
4998 Feb 11 02:59:10 raspberrypi mariadbd[11825]: max_threads=153
 
4999 Feb 11 02:59:10 raspberrypi mariadbd[11825]: thread_count=11
 
5000 Feb 11 02:59:10 raspberrypi mariadbd[11825]: It is possible that mysqld could use up t     o
 
5001 Feb 11 02:59:10 raspberrypi mariadbd[11825]: key_buffer_size + (read_buffer_size + sor     t_buffer_size)*max_threads = 466524 K  bytes of memory
 
5002 Feb 11 02:59:10 raspberrypi mariadbd[11825]: Hope that's ok; if not, decrease some var     iables in the equation.
 
5003 Feb 11 02:59:10 raspberrypi mariadbd[11825]: Thread pointer: 0x0
 
Feb 11 02:59:10 raspberrypi mariadbd[11825]: Attempting backtrace. You can use the following information to find out
 
Feb 11 02:59:10 raspberrypi mariadbd[11825]: where mysqld died. If you see no messages after this, something went
 
Feb 11 02:59:10 raspberrypi mariadbd[11825]: terribly wrong...
 
Feb 11 02:59:10 raspberrypi mariadbd[11825]: stack_bottom = 0x0 thread_stack 0x49000
 
Feb 11 02:59:10 raspberrypi mariadbd[11825]: The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
 
Feb 11 02:59:10 raspberrypi mariadbd[11825]: information that should help you find out what is causing the crash.

*3) Below are different setting values. *

Variable_name | Value |
 
+-------------------------------------+----------------+
 
| aria_pagecache_buffer_size | 134217728 |
 
| aria_sort_buffer_size | 268434432 |
 
| bulk_insert_buffer_size | 8388608 |
 
| innodb_buffer_pool_chunk_size | 134217728 |
 
| innodb_buffer_pool_dump_at_shutdown | ON |
 
| innodb_buffer_pool_dump_now | OFF |
 
| innodb_buffer_pool_dump_pct | 25 |
 
| innodb_buffer_pool_filename | ib_buffer_pool |
 
| innodb_buffer_pool_instances | 1 |
 
| innodb_buffer_pool_load_abort | OFF |
 
| innodb_buffer_pool_load_at_startup | ON |
 
| innodb_buffer_pool_load_now | OFF |
 
| innodb_buffer_pool_size | 134217728 |
 
| innodb_change_buffer_max_size | 25 |
 
| innodb_change_buffering | all |
 
| innodb_log_buffer_size | 16777216 |
 
| innodb_sort_buffer_size | 1048576 |
 
| join_buffer_size | 262144 |
 
| join_buffer_space_limit | 2097152 |
 
| key_buffer_size | 134217728 |
 
| mrr_buffer_size | 262144 |
 
| myisam_sort_buffer_size | 134216704 |
 
| net_buffer_length | 16384 |
 
| preload_buffer_size | 32768 |
 
| read_buffer_size | 131072 |
 
| read_rnd_buffer_size | 262144 |
 
| sort_buffer_size | 2097152 |
 
| sql_buffer_result | OFF |

please advise.



 Comments   
Comment by Daniel Black [ 2022-02-11 ]

Thank you for the bug report with code. For completeness, what is the size of the binfile1 and binfile2?

Comment by Jelari [ 2022-02-11 ]

The size is 3.6 MB all the bin files. Addition information is that it is a 3D point cloud data ( PCD format )

Comment by Jelari [ 2022-02-11 ]

Here is the system information for your reference.

pi@raspberrypi:/etc $ cat os-release
 
PRETTY_NAME="Raspbian GNU/Linux 11 (bullseye)"
 
NAME="Raspbian GNU/Linux"
 
VERSION_ID="11"
 
VERSION="11 (bullseye)"
 
VERSION_CODENAME=bullseye
 
ID=raspbian
 
ID_LIKE=debian
 
HOME_URL="http://www.raspbian.org/"
 
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
 
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
 
 
 
cat /proc/meminfo
 
MemTotal: 3930860 kB
 
MemFree: 3199472 kB
 
MemAvailable: 3535532 kB
 
Buffers: 44300 kB
 
Cached: 492060 kB
 
SwapCached: 5596 kB
 
Active: 354080 kB
 
Inactive: 233948 kB
 
Active(anon): 58076 kB
 
Inactive(anon): 85012 kB
 
Active(file): 296004 kB
 
Inactive(file): 148936 kB
 
Unevictable: 51372 kB
 
Mlocked: 16 kB
 
HighTotal: 3264512 kB
 
HighFree: 2695360 kB
 
LowTotal: 666348 kB
 
LowFree: 504112 kB
 
SwapTotal: 102396 kB
 
SwapFree: 17804 kB
 
Dirty: 8 kB
 
Writeback: 0 kB
 
AnonPages: 97664 kB
 
Mapped: 157288 kB
 
Shmem: 91404 kB
 
KReclaimable: 28736 kB
 
Slab: 49016 kB
 
SReclaimable: 28736 kB
 
SUnreclaim: 20280 kB
 
KernelStack: 2080 kB
 
PageTables: 5572 kB
 
NFS_Unstable: 0 kB
 
Bounce: 0 kB
 
WritebackTmp: 0 kB
 
CommitLimit: 2067824 kB
 
Committed_AS: 1456284 kB
 
VmallocTotal: 245760 kB
 
VmallocUsed: 5784 kB
 
VmallocChunk: 0 kB
 
Percpu: 576 kB
 
CmaTotal: 327680 kB
 
CmaFree: 271824 kB

Comment by Jelari [ 2022-02-11 ]

What I partially understand from the source code is that the next pointer offset value of the record is corrupted or invalid, due to which the system is unable to more forward in linked list. The assert failure happens in the below code:
436 if (offs >= srv_page_size)

{ 437 fprintf(stderr, 438 "InnoDB: Next record offset is nonsensical %lu" 439 " in record at offset %lu\n" 440 "InnoDB: rec address %p, space id %lu, page %lu\n", 441 (ulong) offs, (ulong) page_offset(rec), 442 (void*) rec, 443 (ulong) page_get_space_id(page), 444 (ulong) page_get_page_no(page)); 445 ut_error; 446 }

else if (offs == 0) {

In the line 445. Logical guess is the offset value is going beyond the page size. But i wonder how storing the BLOB files leads to this corruption. THERE IS NEITHER POWER FAILURE NOR THE MACHINE IS REBOOTED. So, there won't be a chance of partial buffer write also.

Please advise.

Generated at Thu Feb 08 09:55:41 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.