Bug #83708 uint expression is used for the value that is passed as my_off_t for DDL log
Submitted: 6 Nov 2016 17:38 Modified: 18 Mar 2020 17:20
Reporter: Valeriy Kravchuk Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: DDL Severity:S3 (Non-critical)
Version:5.7 OS:Any
Assigned to: CPU Architecture:Any
Tags: DDL, ddl_log.log

[6 Nov 2016 17:38] Valeriy Kravchuk
Description:
Please, check the following code in sql/sql_table.cc:

static bool read_ddl_log_file_entry(uint entry_no)
{
  bool error= FALSE;
  File file_id= global_ddl_log.file_id;
  uchar *file_entry_buf= (uchar*)global_ddl_log.file_entry_buf;
  uint io_size= global_ddl_log.io_size;
  DBUG_ENTER("read_ddl_log_file_entry");

  mysql_mutex_assert_owner(&LOCK_gdl);
  if (mysql_file_pread(file_id, file_entry_buf, io_size, io_size * entry_no,
                       MYF(MY_WME)) != io_size)
    error= TRUE;
  DBUG_RETURN(error);
}

I see two potential problems with it:

1. We multiply two uint values, io_size (that is typically 4096, see:

include/my_global.h:332:#define IO_SIZE                 4096

etc)

and entry_no, without any type cast. The resulting expression is going to be of uint type (4 bytes long unsigned), but formal parameter of mysql_file_pread (and my_pread that it ends up defined as) is of type my_off_t. This type is 8 bytes long (on 64-bit systems) usually:

#if defined(_WIN32)
typedef unsigned long long my_off_t;
typedef unsigned long long os_off_t;
#else
typedef off_t os_off_t;
#if SIZEOF_OFF_T > 4
typedef ulonglong my_off_t;
#else
typedef unsigned long my_off_t;
#endif
#endif /*_WIN32*/

So, we may end up passing the value of 4294955008 all the time whenever entry_no > 1048573

Function to write DDL log (static bool write_ddl_log_file_entry(uint entry_no)) is affected in a similar way it seems.

2. We pass MY_WME flag, that is, we just write error to the error log in case of failure, but continue attempts to read in my_pread() indefinitely:

#define MY_FFNF         1       /* Fatal if file not found */
#define MY_FNABP        2       /* Fatal if not all bytes read/writen */
#define MY_NABP         4       /* Error if not all bytes read/writen */
#define MY_FAE          8       /* Fatal if any error */
#define MY_WME          16      /* Write message on error */
...

So, when offset is big enough we start to loop indefinitely, adding messages to error log and holding LOCK_gdl mutex. As a result, any concurrent DDL activity is essentially blocked forever until we get rid of ddl_log.dll file that is 4G in size.

How to repeat:
Read the code.

There are reasons to think that as soon as more than 1048573 entries (4096 bytes each) are written to the DDL Log (see https://dev.mysql.com/doc/refman/5.7/en/ddl-log.html) so that it becomes 4G in size, there is no way to read the entries from it successfully.

Suggested fix:
Make sure the value of offset passed to mysql_file_pread() and my_file_pwrite() is of type my_off_t in all cases and is not affected by artificial 4 bytes limits.

Additionally, consider other flags (MY_FNABP?) when I/O happens with some mutex hold.
[6 Nov 2016 19:11] MySQL Verification Team
Visual studio assembly:

; 721  :   if (mysql_file_pread(file_id, file_entry_buf, io_size, io_size * entry_no,
; 722  :                        MYF(MY_WME)) != io_size)

	mov	eax, DWORD PTR io_size$[rsp]
	imul	eax, DWORD PTR entry_no$[rsp]
	mov	eax, eax
	mov	ecx, DWORD PTR io_size$[rsp]
	mov	DWORD PTR [rsp+48], 16
	mov	QWORD PTR [rsp+40], rax
	mov	QWORD PTR [rsp+32], rcx
	mov	r9, QWORD PTR file_entry_buf$[rsp]
	mov	r8d, DWORD PTR file_id$[rsp]
	mov	edx, 722				; 000002d2H
	lea	rcx, OFFSET FLAT:$SG172779
	call	?inline_mysql_file_pread@@YA_KPEBDIHPEAE_K2H@Z ; inline_mysql_file_pread

Now I casted it;   Does the following look better?

; 721  :   if (mysql_file_pread(file_id, file_entry_buf, (size_t)io_size, (my_off_t)((my_off_t)io_size * (my_off_t)entry_no),
; 722  :                        MYF(MY_WME)) != io_size)

	mov	eax, DWORD PTR io_size$[rsp]
	mov	ecx, DWORD PTR entry_no$[rsp]
	imul	rax, rcx
	mov	ecx, DWORD PTR io_size$[rsp]
	mov	DWORD PTR [rsp+48], 16
	mov	QWORD PTR [rsp+40], rax
	mov	QWORD PTR [rsp+32], rcx
	mov	r9, QWORD PTR file_entry_buf$[rsp]
	mov	r8d, DWORD PTR file_id$[rsp]
	mov	edx, 722				; 000002d2H
	lea	rcx, OFFSET FLAT:$SG172783
	call	?inline_mysql_file_pread@@YA_KPEBDIHPEAE_K2H@Z ; inline_mysql_file_pread
[7 Nov 2016 15:34] MySQL Verification Team
Hi Valerii, 

Based on your and Shane's exposition, I have concluded that this is truly a bug.

Fully verified.
[21 Apr 2017 10:56] Dmitry Lenev
Posted by developer:
 
The below patch which has been pushed into mysql-trunk (should appear in 8.0.2)
removes code in question. So I am closing this bug as "Fixed".

--------------------------------------------------------------------------------

commit 6aa762d6e1a801c5c1dcc54d7e12bafc2acdeabd
Author: Dmitry Lenev <dmitry.lenev@oracle.com>
Date:   Fri Apr 21 09:52:09 2017 +0300

    Removed old partitioning DDL implementation which is no longer in use.
    
    After WL#8971 "Deprecate and remove partition engine" and WL#9559
    "InnoDB_New_DD: Support in-place ALTER PARTITION" code implementing
    "fast" partitioning DDL (fast_alter_partition_table() and related
    functions) became unused.
    
    This patch removes this dead code (including DDL_LOG implementation
    used by it) as a follow-up to the above WLs.
[28 Apr 2017 2:00] Jon Stephens
Fixed in MySQL 8.0.2. This is cleanup of dead code only and makes no user-visible changes, so no changelog entry is required.

Closed.
[18 Mar 2020 14:58] Jon Stephens
This actually was part of of DDL log removal, which completely escaped my notice at the time, and which is certainly a user-visible change. Will be fixing the documentation about this shortly.
[18 Mar 2020 17:20] Jon Stephens
Removal of ddl log file now noted in the MySQL 8.0 Manual.

Setting back to Closed.