MySQL Bugs: #69351: wrong process id shown when reporting loading or saving buffer pool ?

Bug #69351	wrong process id shown when reporting loading or saving buffer pool ?
Submitted:	30 May 2013 8:19	Modified:	30 May 2013 14:48
Reporter:	Simon Mudd (OCA)	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Logging	Severity:	S4 (Feature request)
Version:	5.6.11	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
I use this setting in /etc/my.cnf:

[root@myserver ~]# grep pool /etc/my.cnf
innodb_buffer_pool_load_at_startup  = 1
innodb_buffer_pool_dump_at_shutdown = 1

When shutting down the server I see:

...
2013-05-30 10:10:58 31448 [Note] InnoDB: FTS optimize thread exiting.
2013-05-30 10:10:58 31448 [Note] InnoDB: Starting shutdown...
2013-05-30 10:10:58 7fe6d9dca700 InnoDB: Dumping buffer pool(s) to .//ib_buffer_pool
2013-05-30 10:10:59 7fe6d9dca700 InnoDB: Buffer pool(s) dump completed at 130530 10:10:59
2013-05-30 10:11:05 31448 [Note] InnoDB: Shutdown completed; log sequence number 10000076700822
...

When I see mysql start up ( /etc/init.d/mysql start) I see:

2013-05-30 10:11:48 12580 [Note] InnoDB: 128 rollback segment(s) are active.
2013-05-30 10:11:48 12580 [Note] InnoDB: Waiting for purge to start
2013-05-30 10:11:48 12580 [Note] InnoDB: 5.6.11 started; log sequence number 10000076700822
2013-05-30 10:11:48 7f510a478700 InnoDB: Loading buffer pool(s) from .//ib_buffer_pool
2013-05-30 10:11:48 12580 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
2013-05-30 10:11:48 12580 [Note]   - '0.0.0.0' resolves to '0.0.0.0';
2013-05-30 10:11:48 12580 [Note] Server socket created on IP: '0.0.0.0'.

12580 is the mysqld process id.
yet the "id" value which I'd expect to be a thread or process id shown " 7f510a478700 " appears to be something else. Is this value correct?

How to repeat:
See above.

Suggested fix:
This may not be a bug but looks a bit weird to me. AFAIK the linux thread ids are the same as the process ids and therefore are not normally shown as hex type numbers or generally that large.

Background:
http://bugs.mysql.com/bug.php?id=56240
http://bazaar.launchpad.net/~mysql/mysql-server/5.6/revision/4461

The function ut_print_timestamp prints that information.
It uses the thread id instead of the process id.

Buffer pool dump and load is done in its own thread, buf_dump_thread,
so it has a different id.

Yes, that I understand but look at the formatting of the thread id. It should be as far as I can see a 64-bit unsigned number, yet is shown in hex not decimal as other "process ids". That strikes me as being inconsistent:

sql/log.cc uses: fprintf(stderr, "%d-%02d-%02d %02d:%02d:%02d %lu [%s] %.*s\n",
whereas storage/innobase/ut/ut0ut.cc uses: fprintf(file, "%d-%02d-%02d %02d:%02d:%02d %lx",

%lu (long unsigned) vs %lx (hex)

That's a trivial difference but just stands out as being "weird".