Bug #19825 'SHOW INNODB STATUS' output filled by deadlock output
Submitted: 15 May 2006 17:57 Modified: 28 Jul 2009 20:07
Reporter: Douglas Fischer Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S4 (Feature request)
Version:5.0.21 OS:Linux (Linux)
Assigned to: Heikki Tuuri CPU Architecture:Any
Triage: Triaged: D5 (Feature request)

[15 May 2006 17:57] Douglas Fischer
Description:
This may or may not be considered a bug, though I would be inclined to consider it as such. In the event of a sizeable output of 'LATEST DETECTED DEADLOCK' (i.e. 60k+), the output of 'SHOW INNODB STATUS' will consist only of those sections prior to 'LATEST DETECTED DEADLOCK' and the possibly-truncated deadlock output. This causes scripts that parse the output of 'SHOW INNODB STATUS' to fail in the parsing and, more importantly, prevents any of the latter sections normally included in the output from being present in the output until another, less verbose deadlock occurs or the server is restarted.

How to repeat:
Create a deadlock condition with a sufficient number of locks such that the contents of the 'lock_latest_err_file' approaches 64k in size.

Suggested fix:
innodb_show_status() is nice enough to truncate the list of active transactions if outputting the entire list exceeds the 64k output size. It would be useful if either the contents of the "LATEST DETECTED DEADLOCK" section were similarly truncated, or in the least if the section was properly terminated.

Alternatively, perhaps it would be possible to make the maximum output size of 'SHOW INNODB STATUS' a variable instead of being hard-coded, to allow user control over the output size.
[16 May 2006 12:41] Heikki Tuuri
Douglas,

the 64 kB limit comes from the mysql interactive client that does not print longer output.

A workaround is to use:

innodb_monitor

which prints the output to the .err file. That output is not truncated.

I am making this as a feature request. In the future, we could lift the limit in the mysql interactive client.

Regards,

Heikki
[13 Dec 2006 18:45] Baron Schwartz
I think a better workaround would be to have the LAST DETECTED DEADLOCK section come last, and the TRANSACTIONS section next to last.  I think this will be much more useful for general purposes.  Most people do not want to read through all the records locked by a deadlock, but current transactions is very interesting, as are all the other (smaller) sections.  My personal interest is to enable innotop to more reliably have something to display.  (A Google employee told me they made an internal patch for this purpose too, so I know I'm not the only one who wants it).
[20 Mar 2007 15:14] Morgan Tocker
It seems some of the information can be repetitive:

\n=====================================\n070320  0:09:18 INNODB MONITOR OUTPUT\n=====================================\nPer second averages calculated from the last 16 seconds\n----------\nSEMAPHORES\n----------\nOS WAIT ARRAY INFO: reservation count 12585160, signal count 7937862\nMutex spin waits 1763705058, rounds 3201915088, OS waits 6167286\nRW-shared spins 14218754, OS waits 2883359; RW-excl spins 15739879, OS waits 2030913\n------------------------\nLATEST DETECTED DEADLOCK\n------------------------\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*!
 ** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n***!
  WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2!
 )\n*** W
E ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE R!
 OLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** WE ROL!
 L BACK TRANSACTION (2)\n*** WE ROLL BACK TRANSACTION (2)\n*** !
 WE ROLL  [..]
[20 Mar 2007 15:22] Heikki Tuuri
Morgan,

what you are seeing might be a result of:
http://bugs.mysql.com/bug.php?id=25494

?

Regards,

Heikki
[22 Mar 2007 20:08] Morgan Tocker
Looks that way.  Thanks Heikki.
[18 Aug 2008 4:45] Valeriy Kravchuk
Bug #38835 was marked as a duplicate of this one.
[28 Jul 2009 20:07] Matthew Lord
This has been addressed in 5.4 by merging the following google patch:
http://code.google.com/p/google-mysql-tools/wiki/NewShowInnodbStatus
[19 Feb 2010 4:56] Shane Bester
For 5.1/5.0

Easiest way is to manually create a deadlock that is much smaller in size.
For example:

Connection1:
create table t1(a int)engine=innodb;
start transaction;
insert into t1 values (1),(2),(3);

Connection2:
start transaction;
delete from t1 where a=1; #will hang

Connection1:
update t1 set a=2 where a=1;

At this point Connection2 will deadlock, and the SHOW ENGINE INNODB STATUS should be visible again.
[17 Dec 2012 16:40] Jay Yuan
Thnaks, Shane Bester.  The workaround by creating an deadlock works for me (using 5.0). Now I can see more important info at the bottom from "show innodb db".