Skip to content

Virtualmin SQL problem

Solved Performance
  • @phenomlab This is now fixed. For reference, your system is running at its maximum capacity with even the virtual memory 100% allocated. I needed to reboot the server to release the lock (which I’ve completed with no issues) and have also modified

    etc/mysql/mysql.conf.d/mysqld.cnf
    

    And increased the thread_stack size from 128k to 256k. The mysql service has now started successfully. You should run a backup of all databases ASAP so that remaining transactions are committed and the transaction logs are flushed.

    22450ab2-01db-4fdb-bbed-b6f700a2bec0-image.png

  • phenomlabundefined phenomlab has marked this topic as solved on
  • @phenomlab

    I come back to you regarding the MySQL problem of virtualmin.

    the service run smoothly, the backups of virtualmin are made without error, but I always have files with large sizes that always get bigger.

    The /var/log/mysql/error.log is empty.

    MySQL.idb is as 15 Go ???!! Very Big
    Same for undo_001 (4,12 Go) and undo_002 (14,32 Go)

    image.png

    Virtualmin backup log:
    becbd82e-dc1d-446c-9fe1-402f7406f410-image.png

    I still don’t understand.

    Your help is welcome 😉

  • phenomlabundefined phenomlab has marked this topic as unsolved on
  • @DownPW You should consider using the below inside the my.cnf file, then restart the mySQL service

    SET GLOBAL innodb_undo_log_truncate=ON;
    
  • @phenomlab

    Are you sure for my.cnf file because it is located on /etc/alternatives/my.cnf

    863ce682-b3f5-4cd4-b4a1-0d7f5cf63750-image.png

    And here is the file:

    e00d4526-09ec-43aa-ae5a-5af8388ef104-image.png

    like this ?:

    be3fa85c-ef10-4b69-8096-7461cce87cc8-image.png

    if i see into webmin the mySQL servers, it’s already activated:

    0154ab2a-dac9-4dbc-94be-b439a49dccd8-image.png

  • @phenomlab

    If I add this line on my.cnf file, the mySQL service don’t start - failed

    This is problematic because mySQL takes 36 GB of disk space so it alone takes up half of the server’s disk space.

    I don’t think this is a normal situation.

  • @DownPW it’s certainly not normal as I’ve never seen this on any virtualmin build and I’ve created hundreds of them. Are you able to manually delete the undo files ?

  • @phenomlab

    I have delete these 2 files manually with webmin. Stop and start the service

    3d2cc6df-8c05-4bf2-8abd-02cb4d864968-image.png

    I will monitor this and get back to you if it happens again.

  • –> For mysql.ibd file, is his size normal? (15,6 Go)

  • @DownPW not normal, no, but you mustn’t delete it or it will cause you issues.

  • @DownPW the thing that concerns me here is that I’ve never seen an issue like this occur with no cause or action taken by someone else.

    Do you know if anyone else who has access to the server has made any changes ?

  • @phenomlab said in Virtualmin SQL problem:

    the thing that concerns me here is that I’ve never seen an issue like this occur with no cause or action taken by someone else.
    Do you know if anyone else who has access to the server has made any changes ?

    hmm no or nothing special. we don’t touch mySQL but it seems to be a known problem
    We manage our nodebb/virtualmin/wiki backup, manage iframely or nodebb, update package but nothing more…

    –> Could you take a look at it when you have time?

  • @DownPW yes, of course. I’ll see what I can do with this over the weekend.

  • @phenomlab That’s great, Thanks Mark 👍

  • @DownPW I’ve just re read this post and apologies - this command

    SET GLOBAL innodb_undo_log_truncate=ON;
    

    Has to be entered within the mySQL console then the service stopped and restarted.

    Can you try this first before we do anything else?

  • @phenomlab

    Hello 😊

    Can yo read this post and the screen at the end (mySQL variable already activate) :

    https://sudonix.com/user/downpw

  • @DownPW can you post the output from the mySQL console

    SELECT NAME, SPACE_TYPE, STATE FROM INFORMATION_SCHEMA.INNODB_TABLESPACES WHERE SPACE_TYPE = 'Undo' ORDER BY NAME;
    

    I’m interested to see exactly which tables are causing this. It’s absolutely an artefact of a transaction that has not been completed. The question here is exactly what has caused this. I considered the possibility that this could be a bug in the virtualmin version you are running, although mine is the same, and I’m not experiencing this issue at all.

    To be completely sure, I build another instance on my local network at home and couldn’t replicate this either.

    Can you check with anyone else who has access to this server to see if any installations or upgrades have been attempted that night have failed? Understanding the origin is important at this stage in order to prevent recurrence.

    The below SQL statement should produce a list of running transactions

    SELECT trx.trx_id,
           trx.trx_started,
           trx.trx_mysql_thread_id
    FROM INFORMATION_SCHEMA.INNODB_TRX trx
    JOIN INFORMATION_SCHEMA.PROCESSLIST ps ON trx.trx_mysql_thread_id = ps.id
    WHERE trx.trx_started < CURRENT_TIMESTAMP - INTERVAL 1 SECOND
      AND ps.user != 'system_user';
    

    Finally, you should be able to identify the process itself, and kill it by using the below SQL

    SELECT *
    FROM performance_schema.threads
    WHERE processlist_id = thread_id;
    

    Ideally, once the rogue process has been killed, the rollback attempt should be terminated and disk space reclaimed (after a few hours)

    Let me know how you get on.

    You should also perhaps review this article as it will likely be very useful

    https://stackoverflow.com/questions/62740079/mysql-undo-log-keep-growing

  • @phenomlab

    Yep Mister. I will do this tonight after work 😉

    Thanks

  • @DownPW Great. Keep me updated. Interested to know the outcome.

  • @phenomlab

    Since I manually deleted these 2 big files: undo_001 & undo_002, these 2 files have been regenerated and have not changed in size for 2 days (16Mb)

    Only the mysql.ibd file (15,6 Go) is still big but it doesn’t change in size for the moment.

    We have no other information to our knowledge but I see an update of kernel which was not yet done because it required a reboot at that time.

    – Here is the output of :

    SELECT NAME, SPACE_TYPE, STATE FROM INFORMATION_SCHEMA.INNODB_TABLESPACES WHERE SPACE_TYPE = 'Undo' ORDER BY NAME;

    mysql> SELECT NAME, SPACE_TYPE, STATE FROM INFORMATION_SCHEMA.INNODB_TABLESPACES WHERE SPACE_TYPE = 'Undo' ORDER BY NAME;
    +-----------------+------------+--------+
    | NAME            | SPACE_TYPE | STATE  |
    +-----------------+------------+--------+
    | innodb_undo_001 | Undo       | active |
    | innodb_undo_002 | Undo       | active |
    +-----------------+------------+--------+
    2 rows in set (0.05 sec)
    

    – Here is the output of :

    SELECT trx.trx_id,
           trx.trx_started,
           trx.trx_mysql_thread_id
    FROM INFORMATION_SCHEMA.INNODB_TRX trx
    JOIN INFORMATION_SCHEMA.PROCESSLIST ps ON trx.trx_mysql_thread_id = ps.id
    WHERE trx.trx_started < CURRENT_TIMESTAMP - INTERVAL 1 SECOND
      AND ps.user != 'system_user';
    

    I don’t know if I write it correctly in SQL console ?

    mysql> SELECT trx.trx_id,
        ->        trx.trx_started,
        ->        trx.trx_mysql_thread_id
        -> FROM INFORMATION_SCHEMA.INNODB_TRX trx
        -> JOIN INFORMATION_SCHEMA.PROCESSLIST ps ON trx.trx_mysql_thread_id = ps.id
        -> WHERE trx.trx_started < CURRENT_TIMESTAMP - INTERVAL 1 SECOND
        ->   AND ps.user != 'system_user';
    Empty set (0.00 sec)
    

    Well that doesn’t tell me why the mysql.ibd file is 15.6 GB 😒

  • @phenomlab

    Here is the result of another mySQL query to see the size of all my databases
    but it gave the following result :

    mysql> SELECT table_schema AS "Database", 
        -> ROUND(SUM(data_length + index_length) / 1024 / 1024, 2) AS "Size (MB)" 
        -> FROM information_schema.TABLES 
        -> GROUP BY table_schema;
    +--------------------+-----------+
    | Database           | Size (MB) |
    +--------------------+-----------+
    | information_schema |      0.00 |
    | mysql              |      2.59 |
    | performance_schema |      0.00 |
    | sys                |      0.02 |
    +--------------------+-----------+
    4 rows in set (0.41 sec)
    

    –> None of these results come close to the size of the mysql.ibd file.

    BTW following is the result of other query i found for check the unused space of tablespace :

    mysql> select table_name, SUM(data_length+index_length), MAX(data_free) 
        -> from information_schema.tables 
        -> where table_schema='mysql' 
        -> group by table_name 
        -> with rollup;
    +------------------------------------------------------+-------------------------------+----------------+
    | TABLE_NAME                                           | SUM(data_length+index_length) | MAX(data_free) |
    +------------------------------------------------------+-------------------------------+----------------+
    | columns_priv                                         |                         16384 |    16326328320 |
    | component                                            |                         16384 |    16326328320 |
    | db                                                   |                         32768 |    16326328320 |
    | default_roles                                        |                         16384 |    16326328320 |
    | engine_cost                                          |                         16384 |    16326328320 |
    | func                                                 |                         16384 |    16326328320 |
    | general_log                                          |                             0 |              0 |
    | global_grants                                        |                         49152 |    16326328320 |
    | gtid_executed                                        |                         16384 |    16326328320 |
    | help_category                                        |                         32768 |    16326328320 |
    | help_keyword                                         |                        262144 |    16326328320 |
    | help_relation                                        |                         98304 |    16326328320 |
    | help_topic                                           |                       1687552 |    16326328320 |
    | innodb_index_stats                                   |                         16384 |    16326328320 |
    | innodb_table_stats                                   |                         16384 |    16326328320 |
    | password_history                                     |                         16384 |    16326328320 |
    | plugin                                               |                         16384 |    16326328320 |
    | procs_priv                                           |                         32768 |    16326328320 |
    | proxies_priv                                         |                         32768 |    16326328320 |
    | replication_asynchronous_connection_failover         |                         32768 |    16326328320 |
    | replication_asynchronous_connection_failover_managed |                         16384 |    16326328320 |
    | replication_group_configuration_version              |                         16384 |    16326328320 |
    | replication_group_member_actions                     |                         32768 |    16326328320 |
    | role_edges                                           |                         16384 |    16326328320 |
    | server_cost                                          |                         16384 |    16326328320 |
    | servers                                              |                         16384 |    16326328320 |
    | slave_master_info                                    |                         16384 |    16326328320 |
    | slave_relay_log_info                                 |                         16384 |    16326328320 |
    | slave_worker_info                                    |                         16384 |    16326328320 |
    | slow_log                                             |                             0 |              0 |
    | tables_priv                                          |                         32768 |    16326328320 |
    | time_zone                                            |                         16384 |    16326328320 |
    | time_zone_leap_second                                |                         16384 |    16326328320 |
    | time_zone_name                                       |                         16384 |    16326328320 |
    | time_zone_transition                                 |                         16384 |    16326328320 |
    | time_zone_transition_type                            |                         16384 |    16326328320 |
    | user                                                 |                         16384 |    16326328320 |
    | NULL                                                 |                       2719744 |    16326328320 |
    +------------------------------------------------------+-------------------------------+----------------+
    38 rows in set (0.00 sec)
    

    Another Query for search transation, I don’t see any lock transaction on database :

    part of the result :

    ------------
    TRANSACTIONS
    ------------
    Trx id counter 11707713
    Purge done for trx's n:o < 11707713 undo n:o < 0 state: running but idle
    History list length 0
    LIST OF TRANSACTIONS FOR EACH SESSION:
    ---TRANSACTION 421688359443672, not started
    0 lock struct(s), heap size 1128, 0 row lock(s)
    ---TRANSACTION 421688359442864, not started
    0 lock struct(s), heap size 1128, 0 row lock(s)
    ---TRANSACTION 421688359442056, not started
    0 lock struct(s), heap size 1128, 0 row lock(s)
    

    All the result :

    show engine innodb status\G
    *************************** 1. row ***************************
      Type: InnoDB
      Name: 
    Status: 
    =====================================
    2022-11-07 21:13:43 140213236291328 INNODB MONITOR OUTPUT
    =====================================
    Per second averages calculated from the last 35 seconds
    -----------------
    BACKGROUND THREAD
    -----------------
    srv_master_thread loops: 31 srv_active, 0 srv_shutdown, 257609 srv_idle
    srv_master_thread log flush and writes: 0
    ----------
    SEMAPHORES
    ----------
    OS WAIT ARRAY INFO: reservation count 24
    OS WAIT ARRAY INFO: signal count 21
    RW-shared spins 0, rounds 0, OS waits 0
    RW-excl spins 0, rounds 0, OS waits 0
    RW-sx spins 0, rounds 0, OS waits 0
    Spin rounds per wait: 0.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx
    ------------
    TRANSACTIONS
    ------------
    Trx id counter 11707713
    Purge done for trx's n:o < 11707713 undo n:o < 0 state: running but idle
    History list length 0
    LIST OF TRANSACTIONS FOR EACH SESSION:
    ---TRANSACTION 421688359443672, not started
    0 lock struct(s), heap size 1128, 0 row lock(s)
    ---TRANSACTION 421688359442864, not started
    0 lock struct(s), heap size 1128, 0 row lock(s)
    ---TRANSACTION 421688359442056, not started
    0 lock struct(s), heap size 1128, 0 row lock(s)
    --------
    FILE I/O
    --------
    I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
    I/O thread 1 state: waiting for completed aio requests (log thread)
    I/O thread 2 state: waiting for completed aio requests (read thread)
    I/O thread 3 state: waiting for completed aio requests (read thread)
    I/O thread 4 state: waiting for completed aio requests (read thread)
    I/O thread 5 state: waiting for completed aio requests (read thread)
    I/O thread 6 state: waiting for completed aio requests (write thread)
    I/O thread 7 state: waiting for completed aio requests (write thread)
    I/O thread 8 state: waiting for completed aio requests (write thread)
    I/O thread 9 state: waiting for completed aio requests (write thread)
    Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
     ibuf aio reads:, log i/o's:
    Pending flushes (fsync) log: 0; buffer pool: 0
    472 OS file reads, 2095 OS file writes, 963 OS fsyncs
    0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
    -------------------------------------
    INSERT BUFFER AND ADAPTIVE HASH INDEX
    -------------------------------------
    Ibuf: size 1, free list len 0, seg size 2, 0 merges
    merged operations:
     insert 0, delete mark 0, delete 0
    discarded operations:
     insert 0, delete mark 0, delete 0
    Hash table size 34679, node heap has 2 buffer(s)
    Hash table size 34679, node heap has 0 buffer(s)
    Hash table size 34679, node heap has 7 buffer(s)
    Hash table size 34679, node heap has 2 buffer(s)
    Hash table size 34679, node heap has 2 buffer(s)
    Hash table size 34679, node heap has 0 buffer(s)
    Hash table size 34679, node heap has 2 buffer(s)
    Hash table size 34679, node heap has 1 buffer(s)
    0.00 hash searches/s, 0.00 non-hash searches/s
    ---
    LOG
    ---
    Log sequence number          72770518572
    Log buffer assigned up to    72770518572
    Log buffer completed up to   72770518572
    Log written up to            72770518572
    Log flushed up to            72770518572
    Added dirty pages up to      72770518572
    Pages flushed up to          72770518572
    Last checkpoint at           72770518572
    Log minimum file id is       22221
    Log maximum file id is       22221
    694 log i/o's done, 0.00 log i/o's/second
    ----------------------
    BUFFER POOL AND MEMORY
    ----------------------
    Total large memory allocated 0
    Dictionary memory allocated 582286
    Buffer pool size   8192
    Free buffers       7161
    Database pages     1015
    Old database pages 354
    Modified db pages  0
    Pending reads      0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 750, not young 5674
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 450, created 565, written 1087
    0.00 reads/s, 0.00 creates/s, 0.00 writes/s
    No buffer pool page gets since the last printout
    Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
    LRU len: 1015, unzip_LRU len: 0
    I/O sum[0]:cur[0], unzip sum[0]:cur[0]
    --------------
    ROW OPERATIONS
    --------------
    0 queries inside InnoDB, 0 queries in queue
    0 read views open inside InnoDB
    Process ID=679488, Main thread ID=140212411815680 , state=sleeping
    Number of rows inserted 0, updated 0, deleted 0, read 0
    0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
    Number of system rows inserted 46, updated 459, deleted 8, read 37463
    0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
    ----------------------------
    END OF INNODB MONITOR OUTPUT
    ============================
    
    1 row in set (0.01 sec)
    

Did this solution help you?
Did you find the suggested solution useful? Why not buy me a coffee? It's a nice gesture, and a great way to show your appreciation 💗