MDEV-6812: Merge Kakao: Add global status variables which tell

you the progress of inplace alter table and row log buffer usage

-    (x 100%, it's 4-digit. 10000 means 100.00%)
-    Innodb_onlineddl_rowlog_rows
       Shows how many rows are stored in row log buffer.
-    Innodb_onlineddl_rowlog_pct_used
       Shows row log buffer usage in percent ( *100%, it's 4-digit. 10000 means 100.00% ).
-    Innodb_onlineddl_pct_progress
       Shows the progress of inplace alter table. It might
       be not so accurate because inplace alter is highly
       depend on disk and buffer pool status.
       But still it is useful and better than nothing.

-    Add some log for inplace alter table
       XtraDB/InnoDB will print some message before and
       after doing some task.

storage/innobase/handler/ha_innodb.cc

@@ -801,6 +801,14 @@ static SHOW_VAR innodb_status_variables[]= {
   {"defragment_count",
   (char*) &export_vars.innodb_defragment_count, SHOW_LONG},
 
+  /* Online alter table status variables */
+  {"onlineddl_rowlog_rows",
+  (char*) &export_vars.innodb_onlineddl_rowlog_rows, SHOW_LONG},
+  {"onlineddl_rowlog_pct_used",
+  (char*) &export_vars.innodb_onlineddl_rowlog_pct_used, SHOW_LONG},
+  {"onlineddl_pct_progress",
+  (char*) &export_vars.innodb_onlineddl_pct_progress, SHOW_LONG},
+
   {NullS, NullS, SHOW_LONG}
 };
 

storage/innobase/handler/handler0alter.cc

@@ -3393,6 +3393,11 @@ ha_innobase::prepare_inplace_alter_table(
 	DBUG_ASSERT(ha_alter_info->create_info);
 	DBUG_ASSERT(!srv_read_only_mode);
 
+	/* Init online ddl status variables */
+	onlineddl_rowlog_rows = 0;
+	onlineddl_rowlog_pct_used = 0;
+	onlineddl_pct_progress = 0;
+
 	MONITOR_ATOMIC_INC(MONITOR_PENDING_ALTER_TABLE);
 
 #ifdef UNIV_DEBUG
@@ -4043,6 +4048,11 @@ oom:
 			ctx->thr, prebuilt->table, altered_table);
 	}
 
+	/* Init online ddl status variables */
+	onlineddl_rowlog_rows = 0;
+	onlineddl_rowlog_pct_used = 0;
+	onlineddl_pct_progress = 0;
+
 	DEBUG_SYNC_C("inplace_after_index_build");
 
 	DBUG_EXECUTE_IF("create_index_fail",

storage/innobase/include/row0log.h

@@ -35,6 +35,10 @@ Created 2011-05-26 Marko Makela
 #include "trx0types.h"
 #include "que0types.h"
 
+extern ulint onlineddl_rowlog_rows;
+extern ulint onlineddl_rowlog_pct_used;
+extern ulint onlineddl_pct_progress;
+
 /******************************************************//**
 Allocate the row log for an index and flag the index
 for online creation.

storage/innobase/include/row0merge.h

@@ -40,6 +40,18 @@ Created 13/06/2005 Jan Lindstrom
 #include "lock0types.h"
 #include "srv0srv.h"
 
+/* Cluster index read task is mandatory */
+#define COST_READ_CLUSTERED_INDEX            1.0
+
+/* Basic fixed cost to build all type of index */
+#define COST_BUILD_INDEX_STATIC              0.5
+/* Dynamic cost to build all type of index, dynamic cost will be re-distributed based on page count ratio of each index */
+#define COST_BUILD_INDEX_DYNAMIC             0.5
+
+/* Sum of below two must be 1.0 */
+#define PCT_COST_MERGESORT_INDEX                 0.4
+#define PCT_COST_INSERT_INDEX                    0.6
+
 // Forward declaration
 struct ib_sequence_t;
 
@@ -370,7 +382,10 @@ row_merge_sort(
 	merge_file_t*		file,	/*!< in/out: file containing
 					index entries */
 	row_merge_block_t*	block,	/*!< in/out: 3 buffers */
-	int*			tmpfd)	/*!< in/out: temporary file handle */
+	int*			tmpfd,	/*!< in/out: temporary file handle */
+	const bool		update_progress, /*!< in: update progress status variable or not */
+	const float		pct_progress, /*!< in: total progress percent until now */
+	const float		pct_cost) /*!< in: current progress percent */
 	__attribute__((nonnull));
 /*********************************************************************//**
 Allocate a sort buffer.

storage/innobase/include/srv0srv.h

@@ -903,9 +903,19 @@ struct export_var_t{
 	ulint innodb_truncated_status_writes;	/*!< srv_truncated_status_writes */
 	ulint innodb_available_undo_logs;       /*!< srv_available_undo_logs
 						*/
-	ulint innodb_defragment_compression_failures;
-	ulint innodb_defragment_failures;
-	ulint innodb_defragment_count;
+	ulint innodb_defragment_compression_failures; /*!< Number of
+						defragment re-compression
+						failures */
+
+	ulint innodb_defragment_failures;	/*!< Number of defragment
+						failures*/
+	ulint innodb_defragment_count;		/*!< Number of defragment
+						operations*/
+
+	ulint innodb_onlineddl_rowlog_rows;	/*!< Online alter rows */
+	ulint innodb_onlineddl_rowlog_pct_used; /*!< Online alter percentage
+						of used row log buffer */
+	ulint innodb_onlineddl_pct_progress;	/*!< Online alter progress */
 
 #ifdef UNIV_DEBUG
 	ulint innodb_purge_trx_id_age;		/*!< rw_max_trx_id - purged trx_id */
@@ -917,7 +927,7 @@ struct export_var_t{
 						by page compression */
 	ib_int64_t innodb_page_compression_trim_sect512;/*!< Number of 512b TRIM
 						by page compression */
-	ib_int64_t innodb_page_compression_trim_sect4096;/*!< Number of 4K byte TRIM 
+	ib_int64_t innodb_page_compression_trim_sect4096;/*!< Number of 4K byte TRIM
 						by page compression */
 	ib_int64_t innodb_index_pages_written;  /*!< Number of index pages
 						written */

storage/innobase/row/row0ftsort.cc

@@ -847,7 +847,7 @@ exit:
 
 		error = row_merge_sort(psort_info->psort_common->trx,
 				       psort_info->psort_common->dup,
-				       merge_file[i], block[i], &tmpfd[i]);
+				       merge_file[i], block[i], &tmpfd[i], false, 0.0/* pct_progress */, 0.0/* pct_cost */);
 		if (error != DB_SUCCESS) {
 			close(tmpfd[i]);
 			goto func_exit;

storage/innobase/row/row0log.cc

@@ -40,6 +40,10 @@ Created 2011-05-26 Marko Makela
 
 #include<map>
 
+ulint onlineddl_rowlog_rows;
+ulint onlineddl_rowlog_pct_used;
+ulint onlineddl_pct_progress;
+
 /** Table row modification operations during online table rebuild.
 Delete-marked records are not copied to the rebuilt table. */
 enum row_tab_op {
@@ -470,6 +474,10 @@ write_failed:
 	log->tail.total += size;
 	UNIV_MEM_INVALID(log->tail.buf, sizeof log->tail.buf);
 	mutex_exit(&log->mutex);
+
+	os_atomic_increment_ulint(&onlineddl_rowlog_rows, 1);
+	/* 10000 means 100.00%, 4525 means 45.25% */
+	onlineddl_rowlog_pct_used = (log->tail.total * 10000) / srv_online_max_size;
 }
 
 #ifdef UNIV_DEBUG

storage/innobase/row/row0merge.cc

@@ -23,6 +23,7 @@ New index creation routines using a merge sort
 Created 12/4/2005 Jan Lindstrom
 Completed by Sunny Bains and Marko Makela
 *******************************************************/
+#include <log.h>
 
 #include "row0merge.h"
 #include "row0ext.h"
@@ -1189,7 +1190,8 @@ row_merge_read_clustered_index(
 					AUTO_INCREMENT column, or
 					ULINT_UNDEFINED if none is added */
 	ib_sequence_t&		sequence,/*!< in/out: autoinc sequence */
-	row_merge_block_t*	block)	/*!< in/out: file buffer */
+	row_merge_block_t*	block, /*!< in/out: file buffer */
+	float pct_cost) /*!< in: percent of task weight out of total alter job */
 {
 	dict_index_t*		clust_index;	/* Clustered index */
 	mem_heap_t*		row_heap;	/* Heap memory to create
@@ -1209,11 +1211,21 @@ row_merge_read_clustered_index(
 	os_event_t		fts_parallel_sort_event = NULL;
 	ibool			fts_pll_sort = FALSE;
 	ib_int64_t		sig_count = 0;
+
+	float 			curr_progress;
+	ib_int64_t		read_rows = 0;
+	ib_int64_t		table_total_rows;
 	DBUG_ENTER("row_merge_read_clustered_index");
 
 	ut_ad((old_table == new_table) == !col_map);
 	ut_ad(!add_cols || col_map);
 
+	table_total_rows = dict_table_get_n_rows(old_table);
+	if(table_total_rows == 0) {
+		/* We don't know total row count */
+		table_total_rows = 1;
+	}
+
 	trx->op_info = "reading clustered index";
 
 #ifdef FTS_INTERNAL_DIAG_PRINT
@@ -1711,6 +1723,17 @@ write_buffers:
 		}
 
 		mem_heap_empty(row_heap);
+
+		/* Increment innodb_onlineddl_pct_progress status variable */
+		read_rows++;
+		if(read_rows % 1000 == 0) {
+			/* Update progress for each 1000 rows */
+			curr_progress = (read_rows >= table_total_rows) ?
+					pct_cost : 
+				((pct_cost * read_rows) / table_total_rows);
+			/* presenting 10.12% as 1012 integer */
+			onlineddl_pct_progress = curr_progress * 100;
+		}
 	}
 
 func_exit:
@@ -2173,18 +2196,37 @@ row_merge_sort(
 	merge_file_t*		file,	/*!< in/out: file containing
 					index entries */
 	row_merge_block_t*	block,	/*!< in/out: 3 buffers */
-	int*			tmpfd)	/*!< in/out: temporary file handle */
+	int*			tmpfd,	/*!< in/out: temporary file handle
+					*/
+	const bool		update_progress,
+					/*!< in: update progress
+					status variable or not */
+	const float 		pct_progress,
+					/*!< in: total progress percent
+					until now */
+	const float		pct_cost) /*!< in: current progress percent */
 {
 	const ulint	half	= file->offset / 2;
 	ulint		num_runs;
 	ulint		cur_run = 0;
 	ulint*		run_offset;
 	dberr_t		error	= DB_SUCCESS;
+	ulint		merge_count = 0;
+	ulint		total_merge_sort_count;
+	float		curr_progress = 0;
+
 	DBUG_ENTER("row_merge_sort");
 
 	/* Record the number of merge runs we need to perform */
 	num_runs = file->offset;
 
+	/* Find the number N which 2^N is greater or equal than num_runs */
+	/* N is merge sort running count */
+	total_merge_sort_count = ceil(log2f(num_runs));
+	if(total_merge_sort_count <= 0) {
+		total_merge_sort_count=1;
+	}
+
 	/* If num_runs are less than 1, nothing to merge */
 	if (num_runs <= 1) {
 		DBUG_RETURN(error);
@@ -2214,6 +2256,15 @@ row_merge_sort(
 		error = row_merge(trx, dup, file, block, tmpfd,
 				  &num_runs, run_offset);
 
+		if(update_progress) {
+			merge_count++;
+			curr_progress = (merge_count >= total_merge_sort_count) ?
+				pct_cost :
+				((pct_cost * merge_count) / total_merge_sort_count);
+			/* presenting 10.12% as 1012 integer */;
+			onlineddl_pct_progress = (pct_progress + curr_progress) * 100;
+		}
+
 		if (error != DB_SUCCESS) {
 			break;
 		}
@@ -2283,7 +2334,10 @@ row_merge_insert_index_tuples(
 	dict_index_t*		index,	/*!< in: index */
 	const dict_table_t*	old_table,/*!< in: old table */
 	int			fd,	/*!< in: file descriptor */
-	row_merge_block_t*	block)	/*!< in/out: file buffer */
+	row_merge_block_t*	block,	/*!< in/out: file buffer */
+	const ib_int64_t	table_total_rows, /*!< in: total rows of old table */
+	const float		pct_progress,	/*!< in: total progress percent until now */
+	const float		pct_cost) /*!< in: current progress percent */
 {
 	const byte*		b;
 	mem_heap_t*		heap;
@@ -2293,6 +2347,8 @@ row_merge_insert_index_tuples(
 	ulint			foffs = 0;
 	ulint*			offsets;
 	mrec_buf_t*		buf;
+	ib_int64_t		inserted_rows = 0;
+	float			curr_progress;
 	DBUG_ENTER("row_merge_insert_index_tuples");
 
 	ut_ad(!srv_read_only_mode);
@@ -2469,6 +2525,19 @@ row_merge_insert_index_tuples(
 
 			mem_heap_empty(tuple_heap);
 			mem_heap_empty(ins_heap);
+
+			/* Increment innodb_onlineddl_pct_progress status variable */
+			inserted_rows++;
+			if(inserted_rows % 1000 == 0) {
+				/* Update progress for each 1000 rows */
+				curr_progress = (inserted_rows >= table_total_rows ||
+					table_total_rows <= 0) ?
+						pct_cost :
+					((pct_cost * inserted_rows) / table_total_rows);
+
+				/* presenting 10.12% as 1012 integer */;
+				onlineddl_pct_progress = (pct_progress + curr_progress) * 100;
+			}
 		}
 	}
 
@@ -3464,6 +3533,13 @@ row_merge_build_indexes(
 	fts_psort_t*		merge_info = NULL;
 	ib_int64_t		sig_count = 0;
 	bool			fts_psort_initiated = false;
+
+	float total_static_cost = 0;
+	float total_dynamic_cost = 0;
+	uint total_index_blocks = 0;
+	float pct_cost=0;
+	float pct_progress=0;
+
 	DBUG_ENTER("row_merge_build_indexes");
 
 	ut_ad(!srv_read_only_mode);
@@ -3494,6 +3570,9 @@ row_merge_build_indexes(
 		merge_files[i].fd = -1;
 	}
 
+	total_static_cost = COST_BUILD_INDEX_STATIC * n_indexes + COST_READ_CLUSTERED_INDEX;
+	total_dynamic_cost = COST_BUILD_INDEX_DYNAMIC * n_indexes;
+
 	for (i = 0; i < n_indexes; i++) {
 		if (row_merge_file_create(&merge_files[i]) < 0) {
 			error = DB_OUT_OF_MEMORY;
@@ -3538,6 +3617,12 @@ row_merge_build_indexes(
 	duplicate keys. */
 	innobase_rec_reset(table);
 
+	sql_print_information("InnoDB: Online DDL : Start");
+	sql_print_information("InnoDB: Online DDL : Start reading clustered "
+		"index of the table and create temporary files");
+
+	pct_cost = COST_READ_CLUSTERED_INDEX * 100 / (total_static_cost + total_dynamic_cost);
+
 	/* Read clustered index of the table and create files for
 	secondary index entries for merge sort */
 
@@ -3545,10 +3630,18 @@ row_merge_build_indexes(
 		trx, table, old_table, new_table, online, indexes,
 		fts_sort_idx, psort_info, merge_files, key_numbers,
 		n_indexes, add_cols, col_map,
-		add_autoinc, sequence, block);
+		add_autoinc, sequence, block, pct_cost);
 
-	if (error != DB_SUCCESS) {
+	pct_progress += pct_cost;
+
+	sql_print_information("InnoDB: Online DDL : End of reading "
+		"clustered index of the table and create temporary files");
 
+	for (i = 0; i < n_indexes; i++) {
+		total_index_blocks += merge_files[i].offset;
+	}
+
+	if (error != DB_SUCCESS) {
 		goto func_exit;
 	}
 
@@ -3630,14 +3723,47 @@ wait_again:
 			row_merge_dup_t	dup = {
 				sort_idx, table, col_map, 0};
 
+			pct_cost = (COST_BUILD_INDEX_STATIC +
+				(total_dynamic_cost * merge_files[i].offset /
+					total_index_blocks)) /
+				(total_static_cost + total_dynamic_cost)
+				* PCT_COST_MERGESORT_INDEX * 100;
+
+			sql_print_information("InnoDB: Online DDL : Start merge-sorting"
+				" index %s (%lu / %lu), estimated cost : %2.4f",
+				indexes[i]->name, (i+1), n_indexes, pct_cost);
+
 			error = row_merge_sort(
 				trx, &dup, &merge_files[i],
-				block, &tmpfd);
+				block, &tmpfd, true, pct_progress, pct_cost);
+
+			pct_progress += pct_cost;
+
+			sql_print_information("InnoDB: Online DDL : End of "
+				" merge-sorting index %s (%lu / %lu)",
+				indexes[i]->name, (i+1), n_indexes);
 
 			if (error == DB_SUCCESS) {
+				pct_cost = (COST_BUILD_INDEX_STATIC +
+					(total_dynamic_cost * merge_files[i].offset /
+						total_index_blocks)) /
+					(total_static_cost + total_dynamic_cost) *
+					PCT_COST_INSERT_INDEX * 100;
+
+				sql_print_information("InnoDB: Online DDL : Start "
+					"building index %s (%lu / %lu), estimated "
+					"cost : %2.4f", indexes[i]->name, (i+1),
+					n_indexes, pct_cost);
+
 				error = row_merge_insert_index_tuples(
 					trx->id, sort_idx, old_table,
-					merge_files[i].fd, block);
+					merge_files[i].fd, block,
+					merge_files[i].n_rec, pct_progress, pct_cost);
+				pct_progress += pct_cost;
+
+				sql_print_information("InnoDB: Online DDL : "
+					"End of building index %s (%lu / %lu)",
+					indexes[i]->name, (i+1), n_indexes);
 			}
 		}
 
@@ -3654,11 +3780,15 @@ wait_again:
 			ut_ad(sort_idx->online_status
 			      == ONLINE_INDEX_COMPLETE);
 		} else {
+			sql_print_information("InnoDB: Online DDL : Start applying row log");
 			DEBUG_SYNC_C("row_log_apply_before");
 			error = row_log_apply(trx, sort_idx, table);
 			DEBUG_SYNC_C("row_log_apply_after");
+			sql_print_information("InnoDB: Online DDL : End of applying row log");
 		}
 
+		sql_print_information("InnoDB: Online DDL : Completed");
+
 		if (error != DB_SUCCESS) {
 			trx->error_key_num = key_numbers[i];
 			goto func_exit;

storage/innobase/srv/srv0srv.cc

@@ -63,6 +63,7 @@ Created 10/8/1995 Heikki Tuuri
 #include "dict0stats_bg.h" /* dict_stats_event */
 #include "srv0start.h"
 #include "row0mysql.h"
+#include "row0log.h"
 #include "ha_prototypes.h"
 #include "trx0i_s.h"
 #include "os0sync.h" /* for HAVE_ATOMIC_BUILTINS */
@@ -1523,6 +1524,10 @@ srv_export_innodb_status(void)
 	export_vars.innodb_defragment_failures = btr_defragment_failures;
 	export_vars.innodb_defragment_count = btr_defragment_count;
 
+	export_vars.innodb_onlineddl_rowlog_rows = onlineddl_rowlog_rows;
+	export_vars.innodb_onlineddl_rowlog_pct_used = onlineddl_rowlog_pct_used;
+	export_vars.innodb_onlineddl_pct_progress = onlineddl_pct_progress;
+
 #ifdef UNIV_DEBUG
 	rw_lock_s_lock(&purge_sys->latch);
 	trx_id_t	done_trx_no	= purge_sys->done.trx_no;

storage/xtradb/handler/ha_innodb.cc

@@ -993,6 +993,14 @@ static SHOW_VAR innodb_status_variables[]= {
   {"defragment_count",
   (char*) &export_vars.innodb_defragment_count, SHOW_LONG},
 
+  /* Online alter table status variables */
+  {"onlineddl_rowlog_rows",
+  (char*) &export_vars.innodb_onlineddl_rowlog_rows, SHOW_LONG},
+  {"onlineddl_rowlog_pct_used",
+  (char*) &export_vars.innodb_onlineddl_rowlog_pct_used, SHOW_LONG},
+  {"onlineddl_pct_progress",
+  (char*) &export_vars.innodb_onlineddl_pct_progress, SHOW_LONG},
+
   {NullS, NullS, SHOW_LONG}
 };
 

storage/xtradb/handler/handler0alter.cc

@@ -3406,6 +3406,11 @@ ha_innobase::prepare_inplace_alter_table(
 		DBUG_RETURN(HA_ERR_WRONG_COMMAND);
 	}
 
+	/* Init online ddl status variables */
+	onlineddl_rowlog_rows = 0;
+	onlineddl_rowlog_pct_used = 0;
+	onlineddl_pct_progress = 0;
+
 	MONITOR_ATOMIC_INC(MONITOR_PENDING_ALTER_TABLE);
 
 #ifdef UNIV_DEBUG
@@ -4056,6 +4061,11 @@ oom:
 			ctx->thr, prebuilt->table, altered_table);
 	}
 
+	/* Init online ddl status variables */
+	onlineddl_rowlog_rows = 0;
+	onlineddl_rowlog_pct_used = 0;
+	onlineddl_pct_progress = 0;
+
 	DEBUG_SYNC_C("inplace_after_index_build");
 
 	DBUG_EXECUTE_IF("create_index_fail",

storage/xtradb/include/row0log.h

@@ -35,6 +35,10 @@ Created 2011-05-26 Marko Makela
 #include "trx0types.h"
 #include "que0types.h"
 
+extern ulint onlineddl_rowlog_rows;
+extern ulint onlineddl_rowlog_pct_used;
+extern ulint onlineddl_pct_progress;
+
 /******************************************************//**
 Allocate the row log for an index and flag the index
 for online creation.

storage/xtradb/include/row0merge.h

@@ -40,6 +40,18 @@ Created 13/06/2005 Jan Lindstrom
 #include "lock0types.h"
 #include "srv0srv.h"
 
+/* Cluster index read task is mandatory */
+#define COST_READ_CLUSTERED_INDEX            1.0
+
+/* Basic fixed cost to build all type of index */
+#define COST_BUILD_INDEX_STATIC              0.5
+/* Dynamic cost to build all type of index, dynamic cost will be re-distributed based on page count ratio of each index */
+#define COST_BUILD_INDEX_DYNAMIC             0.5
+
+/* Sum of below two must be 1.0 */
+#define PCT_COST_MERGESORT_INDEX                 0.4
+#define PCT_COST_INSERT_INDEX                    0.6
+
 // Forward declaration
 struct ib_sequence_t;
 
@@ -370,7 +382,10 @@ row_merge_sort(
 	merge_file_t*		file,	/*!< in/out: file containing
 					index entries */
 	row_merge_block_t*	block,	/*!< in/out: 3 buffers */
-	int*			tmpfd)	/*!< in/out: temporary file handle */
+	int*			tmpfd,	/*!< in/out: temporary file handle */
+	const bool		update_progress, /*!< in: update progress status variable or not */
+	const float		pct_progress, /*!< in: total progress percent until now */
+	const float		pct_cost) /*!< in: current progress percent */
 	__attribute__((nonnull));
 /*********************************************************************//**
 Allocate a sort buffer.

storage/xtradb/include/srv0srv.h

@@ -1112,9 +1112,22 @@ struct export_var_t{
 	ib_int64_t innodb_x_lock_os_waits;
 	ib_int64_t innodb_x_lock_spin_rounds;
 	ib_int64_t innodb_x_lock_spin_waits;
-	ulint innodb_defragment_compression_failures;
-	ulint innodb_defragment_failures;
-	ulint innodb_defragment_count;
+
+	ulint innodb_defragment_compression_failures; /*!< Number of
+						defragment re-compression
+						failures */
+
+	ulint innodb_defragment_failures;	/*!< Number of defragment
+						failures*/
+	ulint innodb_defragment_count;		/*!< Number of defragment
+						operations*/
+
+	ulint innodb_onlineddl_rowlog_rows;	/*!< Online alter rows */
+	ulint innodb_onlineddl_rowlog_pct_used; /*!< Online alter percentage
+						of used row log buffer */
+	ulint innodb_onlineddl_pct_progress;	/*!< Online alter progress
+						*/
+
 #ifdef UNIV_DEBUG
 	ulint innodb_purge_trx_id_age;		/*!< rw_max_trx_id - purged trx_id */
 	ulint innodb_purge_view_trx_id_age;	/*!< rw_max_trx_id

storage/xtradb/row/row0ftsort.cc

@@ -850,7 +850,7 @@ exit:
 
 		error = row_merge_sort(psort_info->psort_common->trx,
 				       psort_info->psort_common->dup,
-				       merge_file[i], block[i], &tmpfd[i]);
+				       merge_file[i], block[i], &tmpfd[i], false, 0.0/* pct_progress */, 0.0/* pct_cost */);
 		if (error != DB_SUCCESS) {
 			close(tmpfd[i]);
 			goto func_exit;

storage/xtradb/row/row0log.cc

@@ -40,6 +40,10 @@ Created 2011-05-26 Marko Makela
 
 #include<map>
 
+ulint onlineddl_rowlog_rows;
+ulint onlineddl_rowlog_pct_used;
+ulint onlineddl_pct_progress;
+
 /** Table row modification operations during online table rebuild.
 Delete-marked records are not copied to the rebuilt table. */
 enum row_tab_op {
@@ -471,6 +475,10 @@ write_failed:
 	log->tail.total += size;
 	UNIV_MEM_INVALID(log->tail.buf, sizeof log->tail.buf);
 	mutex_exit(&log->mutex);
+
+	os_atomic_increment_ulint(&onlineddl_rowlog_rows, 1);
+	/* 10000 means 100.00%, 4525 means 45.25% */
+	onlineddl_rowlog_pct_used = (log->tail.total * 10000) / srv_online_max_size;
 }
 
 #ifdef UNIV_DEBUG

storage/xtradb/row/row0merge.cc

@@ -23,6 +23,7 @@ New index creation routines using a merge sort
 Created 12/4/2005 Jan Lindstrom
 Completed by Sunny Bains and Marko Makela
 *******************************************************/
+#include <log.h>
 
 #include "row0merge.h"
 #include "row0ext.h"
@@ -1189,7 +1190,8 @@ row_merge_read_clustered_index(
 					AUTO_INCREMENT column, or
 					ULINT_UNDEFINED if none is added */
 	ib_sequence_t&		sequence,/*!< in/out: autoinc sequence */
-	row_merge_block_t*	block)	/*!< in/out: file buffer */
+	row_merge_block_t*	block, /*!< in/out: file buffer */
+	float pct_cost) /*!< in: percent of task weight out of total alter job */
 {
 	dict_index_t*		clust_index;	/* Clustered index */
 	mem_heap_t*		row_heap;	/* Heap memory to create
@@ -1209,11 +1211,21 @@ row_merge_read_clustered_index(
 	os_event_t		fts_parallel_sort_event = NULL;
 	ibool			fts_pll_sort = FALSE;
 	ib_int64_t		sig_count = 0;
+
+	float 			curr_progress;
+	ib_int64_t		read_rows = 0;
+	ib_int64_t		table_total_rows;
 	DBUG_ENTER("row_merge_read_clustered_index");
 
 	ut_ad((old_table == new_table) == !col_map);
 	ut_ad(!add_cols || col_map);
 
+	table_total_rows = dict_table_get_n_rows(old_table);
+	if(table_total_rows == 0) {
+		/* We don't know total row count */
+		table_total_rows = 1;
+	}
+
 	trx->op_info = "reading clustered index";
 
 #ifdef FTS_INTERNAL_DIAG_PRINT
@@ -1717,6 +1729,17 @@ write_buffers:
 		}
 
 		mem_heap_empty(row_heap);
+
+		/* Increment innodb_onlineddl_pct_progress status variable */
+		read_rows++;
+		if(read_rows % 1000 == 0) {
+			/* Update progress for each 1000 rows */
+			curr_progress = (read_rows >= table_total_rows) ?
+					pct_cost : 
+				((pct_cost * read_rows) / table_total_rows);
+			/* presenting 10.12% as 1012 integer */
+			onlineddl_pct_progress = curr_progress * 100;
+		}
 	}
 
 func_exit:
@@ -2179,18 +2202,37 @@ row_merge_sort(
 	merge_file_t*		file,	/*!< in/out: file containing
 					index entries */
 	row_merge_block_t*	block,	/*!< in/out: 3 buffers */
-	int*			tmpfd)	/*!< in/out: temporary file handle */
+	int*			tmpfd,	/*!< in/out: temporary file handle
+					*/
+	const bool		update_progress,
+					/*!< in: update progress
+					status variable or not */
+	const float 		pct_progress,
+					/*!< in: total progress percent
+					until now */
+	const float		pct_cost) /*!< in: current progress percent */
 {
 	const ulint	half	= file->offset / 2;
 	ulint		num_runs;
 	ulint		cur_run = 0;
 	ulint*		run_offset;
 	dberr_t		error	= DB_SUCCESS;
+	ulint		merge_count = 0;
+	ulint		total_merge_sort_count;
+	float		curr_progress = 0;
+
 	DBUG_ENTER("row_merge_sort");
 
 	/* Record the number of merge runs we need to perform */
 	num_runs = file->offset;
 
+	/* Find the number N which 2^N is greater or equal than num_runs */
+	/* N is merge sort running count */
+	total_merge_sort_count = ceil(log2f(num_runs));
+	if(total_merge_sort_count <= 0) {
+		total_merge_sort_count=1;
+	}
+
 	/* If num_runs are less than 1, nothing to merge */
 	if (num_runs <= 1) {
 		DBUG_RETURN(error);
@@ -2220,6 +2262,15 @@ row_merge_sort(
 		error = row_merge(trx, dup, file, block, tmpfd,
 				  &num_runs, run_offset);
 
+		if(update_progress) {
+			merge_count++;
+			curr_progress = (merge_count >= total_merge_sort_count) ?
+				pct_cost :
+				((pct_cost * merge_count) / total_merge_sort_count);
+			/* presenting 10.12% as 1012 integer */;
+			onlineddl_pct_progress = (pct_progress + curr_progress) * 100;
+		}
+
 		if (error != DB_SUCCESS) {
 			break;
 		}
@@ -2289,7 +2340,10 @@ row_merge_insert_index_tuples(
 	dict_index_t*		index,	/*!< in: index */
 	const dict_table_t*	old_table,/*!< in: old table */
 	int			fd,	/*!< in: file descriptor */
-	row_merge_block_t*	block)	/*!< in/out: file buffer */
+	row_merge_block_t*	block,	/*!< in/out: file buffer */
+	const ib_int64_t	table_total_rows, /*!< in: total rows of old table */
+	const float		pct_progress,	/*!< in: total progress percent until now */
+	const float		pct_cost) /*!< in: current progress percent */
 {
 	const byte*		b;
 	mem_heap_t*		heap;
@@ -2299,6 +2353,8 @@ row_merge_insert_index_tuples(
 	ulint			foffs = 0;
 	ulint*			offsets;
 	mrec_buf_t*		buf;
+	ib_int64_t		inserted_rows = 0;
+	float			curr_progress;
 	DBUG_ENTER("row_merge_insert_index_tuples");
 
 	ut_ad(!srv_read_only_mode);
@@ -2475,6 +2531,19 @@ row_merge_insert_index_tuples(
 
 			mem_heap_empty(tuple_heap);
 			mem_heap_empty(ins_heap);
+
+			/* Increment innodb_onlineddl_pct_progress status variable */
+			inserted_rows++;
+			if(inserted_rows % 1000 == 0) {
+				/* Update progress for each 1000 rows */
+				curr_progress = (inserted_rows >= table_total_rows ||
+					table_total_rows <= 0) ?
+						pct_cost :
+					((pct_cost * inserted_rows) / table_total_rows);
+
+				/* presenting 10.12% as 1012 integer */;
+				onlineddl_pct_progress = (pct_progress + curr_progress) * 100;
+			}
 		}
 	}
 
@@ -3470,6 +3539,13 @@ row_merge_build_indexes(
 	fts_psort_t*		merge_info = NULL;
 	ib_int64_t		sig_count = 0;
 	bool			fts_psort_initiated = false;
+
+	float total_static_cost = 0;
+	float total_dynamic_cost = 0;
+	uint total_index_blocks = 0;
+	float pct_cost=0;
+	float pct_progress=0;
+
 	DBUG_ENTER("row_merge_build_indexes");
 
 	ut_ad(!srv_read_only_mode);
@@ -3500,6 +3576,9 @@ row_merge_build_indexes(
 		merge_files[i].fd = -1;
 	}
 
+	total_static_cost = COST_BUILD_INDEX_STATIC * n_indexes + COST_READ_CLUSTERED_INDEX;
+	total_dynamic_cost = COST_BUILD_INDEX_DYNAMIC * n_indexes;
+
 	for (i = 0; i < n_indexes; i++) {
 		if (row_merge_file_create(&merge_files[i]) < 0) {
 			error = DB_OUT_OF_MEMORY;
@@ -3544,6 +3623,12 @@ row_merge_build_indexes(
 	duplicate keys. */
 	innobase_rec_reset(table);
 
+	sql_print_information("InnoDB: Online DDL : Start");
+	sql_print_information("InnoDB: Online DDL : Start reading clustered "
+		"index of the table and create temporary files");
+
+	pct_cost = COST_READ_CLUSTERED_INDEX * 100 / (total_static_cost + total_dynamic_cost);
+
 	/* Read clustered index of the table and create files for
 	secondary index entries for merge sort */
 
@@ -3551,10 +3636,18 @@ row_merge_build_indexes(
 		trx, table, old_table, new_table, online, indexes,
 		fts_sort_idx, psort_info, merge_files, key_numbers,
 		n_indexes, add_cols, col_map,
-		add_autoinc, sequence, block);
+		add_autoinc, sequence, block, pct_cost);
 
-	if (error != DB_SUCCESS) {
+	pct_progress += pct_cost;
+
+	sql_print_information("InnoDB: Online DDL : End of reading "
+		"clustered index of the table and create temporary files");
 
+	for (i = 0; i < n_indexes; i++) {
+		total_index_blocks += merge_files[i].offset;
+	}
+
+	if (error != DB_SUCCESS) {
 		goto func_exit;
 	}
 
@@ -3636,14 +3729,47 @@ wait_again:
 			row_merge_dup_t	dup = {
 				sort_idx, table, col_map, 0};
 
+			pct_cost = (COST_BUILD_INDEX_STATIC +
+				(total_dynamic_cost * merge_files[i].offset /
+					total_index_blocks)) /
+				(total_static_cost + total_dynamic_cost)
+				* PCT_COST_MERGESORT_INDEX * 100;
+
+			sql_print_information("InnoDB: Online DDL : Start merge-sorting"
+				" index %s (%lu / %lu), estimated cost : %2.4f",
+				indexes[i]->name, (i+1), n_indexes, pct_cost);
+
 			error = row_merge_sort(
 				trx, &dup, &merge_files[i],
-				block, &tmpfd);
+				block, &tmpfd, true, pct_progress, pct_cost);
+
+			pct_progress += pct_cost;
+
+			sql_print_information("InnoDB: Online DDL : End of "
+				" merge-sorting index %s (%lu / %lu)",
+				indexes[i]->name, (i+1), n_indexes);
 
 			if (error == DB_SUCCESS) {
+				pct_cost = (COST_BUILD_INDEX_STATIC +
+					(total_dynamic_cost * merge_files[i].offset /
+						total_index_blocks)) /
+					(total_static_cost + total_dynamic_cost) *
+					PCT_COST_INSERT_INDEX * 100;
+
+				sql_print_information("InnoDB: Online DDL : Start "
+					"building index %s (%lu / %lu), estimated "
+					"cost : %2.4f", indexes[i]->name, (i+1),
+					n_indexes, pct_cost);
+
 				error = row_merge_insert_index_tuples(
 					trx->id, sort_idx, old_table,
-					merge_files[i].fd, block);
+					merge_files[i].fd, block,
+					merge_files[i].n_rec, pct_progress, pct_cost);
+				pct_progress += pct_cost;
+
+				sql_print_information("InnoDB: Online DDL : "
+					"End of building index %s (%lu / %lu)",
+					indexes[i]->name, (i+1), n_indexes);
 			}
 		}
 
@@ -3660,11 +3786,15 @@ wait_again:
 			ut_ad(sort_idx->online_status
 			      == ONLINE_INDEX_COMPLETE);
 		} else {
+			sql_print_information("InnoDB: Online DDL : Start applying row log");
 			DEBUG_SYNC_C("row_log_apply_before");
 			error = row_log_apply(trx, sort_idx, table);
 			DEBUG_SYNC_C("row_log_apply_after");
+			sql_print_information("InnoDB: Online DDL : End of applying row log");
 		}
 
+		sql_print_information("InnoDB: Online DDL : Completed");
+
 		if (error != DB_SUCCESS) {
 			trx->error_key_num = key_numbers[i];
 			goto func_exit;

storage/xtradb/srv/srv0srv.cc

@@ -64,6 +64,7 @@ Created 10/8/1995 Heikki Tuuri
 #include "dict0stats_bg.h" /* dict_stats_event */
 #include "srv0start.h"
 #include "row0mysql.h"
+#include "row0log.h"
 #include "ha_prototypes.h"
 #include "trx0i_s.h"
 #include "os0sync.h" /* for HAVE_ATOMIC_BUILTINS */
@@ -1912,6 +1913,10 @@ srv_export_innodb_status(void)
 	export_vars.innodb_defragment_failures = btr_defragment_failures;
 	export_vars.innodb_defragment_count = btr_defragment_count;
 
+	export_vars.innodb_onlineddl_rowlog_rows = onlineddl_rowlog_rows;
+	export_vars.innodb_onlineddl_rowlog_pct_used = onlineddl_rowlog_pct_used;
+	export_vars.innodb_onlineddl_pct_progress = onlineddl_pct_progress;
+
 #ifdef UNIV_DEBUG
 	rw_lock_s_lock(&purge_sys->latch);
 	trx_id_t	done_trx_no	= purge_sys->done.trx_no;