Bug #8653 5.0.3 leaves an InnoDB trx open after connection ends; InnoDB shutdown hangs
Submitted: 21 Feb 2005 16:33 Modified: 6 Apr 2005 15:09
Reporter: Heikki Tuuri Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version: OS:
Assigned to: Bugs System CPU Architecture:Any

[21 Feb 2005 16:33] Heikki Tuuri 
Description:
Hi!

I ran ibtest5 for a few seconds. After I break the Perl program, the last (?) transaction remains active inside InnoDB.

InnoDB cannot shut down because  UT_LIST_GET_LEN(trx_sys->trx_list) > 0. mysqld hangs in shutdown.

A normal COMMIT or ROLLBACK in the interactive SQL client does not leave this phantom trx object behind.

Regards,

Heikki

------------
TRANSACTIONS
------------
Trx id counter 0 99022
Purge done for trx's n:o < 0 90658 undo n:o < 0 0
History list length 8
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 5671, OS thread id 163851
MySQL thread id 2, query id 6370 localhost heikki
show innodb status
---TRANSACTION 0 42258, ACTIVE 64 sec, process no 0, OS thread id 0
, undo log entries 1000
--------
FILE I/O
--------

############################################################################
#     Stress test for MySQL/Innobase combined database
#     (c) 2000 Innobase Oy & MySQL AB
#
############################################################################

use DBI;
use Benchmark;

$opt_loop_count = 100000;
$opt_loop_count2 = 10000;

chomp($pwd = `pwd`); $pwd = "." if ($pwd eq '');
require "$pwd/bench-init.pl" || die "Can't read Configuration file: $!\n";

print "Generating random keys\n";
$random[$opt_loop_count] = 0;
$rnd_str[$opt_loop_count] = "a";

for ($i = 0; $i < $opt_loop_count; $i++) {

        $random[$i] = ($i * 63857) % $opt_loop_count;

        if (0 == ($random[$i] % 3)) {
                $rnd_str[$i] = "khdclgrtfuylfyufuyfyufyufyyufujhfghd";
        } else { if (1 == ($random[$i] % 3)) {
                $rnd_str[$i] = "khd";
        } else { if (2 == ($random[$i] % 3)) {
                $rnd_str[$i] = "kh";
        }}}

        for ($j = 0; $j < (($i * 768653) % 20); $j++) {
                $rnd_str[$i] = $rnd_str[$i]."k";
        }
}

####
####  Connect
####

$dbh = $server->connect();

$dbh->do("set autocommit = 1");

$dbh->do("drop table ibstest0");
$dbh->do("drop table ibstest1");

for ($i = 0; $i < $opt_loop_count2; $i++) {
        for ($j = 0; $j < $opt_loop_count; $j++) {
                $rnd_str[$j] = $rnd_str[$j]."k";
        }

        print "loop $i\n";
        $s = $dbh->do(
        "create table ibstest0 (A INT NOT NULL, B VARCHAR(200) NOT NULL, C INT,
D INT NOT NULL, PRIMARY KEY (A, D), INDEX (B), UNIQUE INDEX (C)) TYPE = INNODB")
;
        print $s;
        print "\n";

        for ($j = 0; $j < $opt_loop_count - 1; $j++) {
                if (($j % 100) == 0) {
                        print $j;
                        print "\n";
                }
                $dbh->do("insert into ibstest0 values (".(2 * $j).", '".$rnd_str
[$j]."', ".(2 * $random[$j]).", ".(2 * $j).")");
        }

        $dbh->do("show create table ibstest0");

        $j = $opt_loop_count - 1;
        $dbh->do("insert into ibstest0 values (".(2 * $j).", '".$rnd_str[$j]."',
 NULL, ".(2 * $j).")");

        $sth = $dbh->prepare("select count(*) from ibstest0 at1, ibstest0 at2 wh
ere at1.a = at2.c");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        if ($n != $opt_loop_count - 1) {
                print "ERROR!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n";
                die;
        }
        $sth->finish;

        $sth = $dbh->prepare("select * from ibstest0 at1, ibstest0 at2 where at1
.a = at2.c group by at2.d order by 2 desc");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        $sth->finish;

        $dbh->do("commit");

        $sth = $dbh->prepare("select at1.a, at2.d from ibstest0 at1, ibstest0 at
2 where at1.d = at2.c group by at1.a order by at2.d desc");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        $sth->finish;

        $sth = $dbh->prepare("select count(*) from ibstest0 at1, ibstest0 at2 wh
ere at1.a = at2.d");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        if ($n != $opt_loop_count) {
                print "ERROR!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n";
                die;
        }
        $sth->finish;

        $dbh->do("commit");

        $sth = $dbh->prepare("select count(*) from ibstest0 at1, ibstest0 at2 wh
ere at1.d = at2.c");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        if ($n != $opt_loop_count - 1) {
                print "ERROR!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n";
                die;
        }
        $sth->finish;

        $sth = $dbh->prepare("select count(*) from ibstest0 at1, ibstest0 at2 wh
ere at1.a = at2.d");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        if ($n != $opt_loop_count) {
                print "ERROR!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n";
                die;
        }
        $sth->finish;

        $sth = $dbh->prepare("select count(*) from ibstest0 at1, ibstest0 at2 wh
ere at1.a = 1 + at2.d");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        if ($n != 0) {
                print "ERROR!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n";
                die;
        }
        $sth->finish;

        $dbh->do("show create table ibstest0");

        $sth = $dbh->prepare("select count(*) from ibstest0 at1, ibstest0 at2 wh
ere at1.d + 1 = at2.c");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        if ($n != 0) {
                print "ERROR!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n";
                die;
        }
        $sth->finish;

        $s = $dbh->do(
        "create table ibstest1 (A INT NOT NULL, B VARCHAR(200) NOT NULL, C INT,
D INT NOT NULL, PRIMARY KEY (A, D), INDEX (B), UNIQUE INDEX (C)) TYPE = INNODB")
;
        print $s;
        print "\n";

        $dbh->do("insert into ibstest1 select * from ibstest0");

        $dbh->do("commit");

        $sth = $dbh->prepare("select count(*) from ibstest0, ibstest1 where ibst
est0.a = ibstest1.d");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        if ($n != $opt_loop_count) {
                print "ERROR!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n";
                die;
        }
        $sth->finish;

        $sth = $dbh->prepare("select count(*) from ibstest0, ibstest1 where ibst
est0.c = ibstest1.d");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        if ($n != $opt_loop_count - 1) {
                print "ERROR!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n";
                die;
        }
        $sth->finish;

        $dbh->do("commit");

        for ($j = 0; $j < $opt_loop_count / 16 - 1; $j++) {
                $dbh->do("insert into ibstest0 values (".(2 * $random[$j] + 1)."
, '".$rnd_str[$j]."', ".(2 * $random[$j] + 1).", ".(2 * $random[$j] + 1).")");
        }

        $dbh->do("show create table ibstest0");

        $dbh->do("commit");

        $dbh->do("show create table ibstest0");

        $sth = $dbh->prepare("select count(*) from ibstest0, ibstest1 where ibst
est0.a = ibstest1.d");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        if ($n != $opt_loop_count) {
                print "ERROR!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n";
                die;
        }
        $sth->finish;

        $sth = $dbh->prepare("select count(*) from ibstest0, ibstest1 where ibst
est0.c = ibstest1.d");
        $sth->execute;
        $n = (($sth->fetchrow_array)[0]);
        print $n;
        print "\n";
        if ($n != $opt_loop_count - 1) {
                print "ERROR!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!\n";
                die;
        }
        $sth->finish;

        $dbh->do("commit");

        $dbh->do("drop table ibstest0");
        $dbh->do("drop table ibstest1");
}

$dbh->disconnect;                               # close connection

............

This works:

mysql> set autocommit = 0;
Query OK, 0 rows affected (0.00 sec)

mysql> create table t(a int) type =innodb;
Query OK, 0 rows affected, 1 warning (0.01 sec)

mysql> insert into t values (10);
Query OK, 1 row affected (0.00 sec)

mysql> commit;
Query OK, 0 rows affected (0.01 sec)

mysql> show innodb status\G
*************************** 1. row ***************************
Status:
=====================================
050221 17:50:00 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 11 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 10, signal count 10
Mutex spin waits 0, rounds 0, OS waits 0
RW-shared spins 20, OS waits 10; RW-excl spins 0, OS waits 0
------------
TRANSACTIONS
------------
Trx id counter 0 99025
Purge done for trx's n:o < 0 90658 undo n:o < 0 0
History list length 8
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 99024, not started, process no 5671, OS thread id 163851
MySQL thread id 2, query id 6378 localhost heikki
show innodb status
---TRANSACTION 0 42258, ACTIVE 373 sec, process no 0, OS thread id 0
, undo log entries 1000
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (write thread)
Pending normal aio reads: 0, aio writes: 0,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
411 OS file reads, 6390 OS file writes, 6379 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.73 writes/s, 0.55 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf for space 0: size 1, free list len 5, seg size 7, is empty
Ibuf for space 0: size 1, free list len 5, seg size 7,
0 inserts, 0 merged recs, 0 merges
Hash table size 1245217, used cells 61, node heap has 1 buffer(s)
0.00 hash searches/s, 0.09 non-hash searches/s
---
LOG
---
Log sequence number 0 255163125
Log flushed up to   0 255163125
Last checkpoint at  0 255163103
0 pending log writes, 0 pending chkp writes
6374 log i/o's done, 0.36 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 357794834; in additional pool allocated 1445504
Buffer pool size   19200
Free buffers       18635
Database pages     564
Modified db pages  1
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 502, created 62, written 88
0.00 reads/s, 0.00 creates/s, 0.27 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
Main thread process no. 5666, id 131081, state: sleeping
Number of rows inserted 6350, updated 0, deleted 0, read 295772
0.09 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set, 1 warning (0.08 sec)

mysql> insert into t values (20);
Query OK, 1 row affected (0.00 sec)

mysql> rollback;
Query OK, 0 rows affected (0.00 sec)

mysql> show innodb status\G
*************************** 1. row ***************************
Status:
=====================================
050221 17:50:15 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 15 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 12, signal count 12
Mutex spin waits 0, rounds 0, OS waits 0
RW-shared spins 24, OS waits 12; RW-excl spins 0, OS waits 0
------------
TRANSACTIONS
------------
Trx id counter 0 99026
Purge done for trx's n:o < 0 90658 undo n:o < 0 0
History list length 8
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 99025, not started, process no 5671, OS thread id 163851
MySQL thread id 2, query id 6381 localhost heikki
show innodb status
---TRANSACTION 0 42258, ACTIVE 388 sec, process no 0, OS thread id 0
, undo log entries 1000
--------

How to repeat:
See above.
[22 Feb 2005 0:14] Sergei Golubchik 
Heikki, I cannot repeat it :(

Any ideas what I can do besides running ibtest5 and interrupting it ?
(tried this many times with no success)
[22 Feb 2005 0:16] Sergei Golubchik 
also tried starting a transaction from mysql (command-line client) and hard-killing it
(with kill -9, to be sure client itself does no cleanup) - no way, both read and write transactions
are terminated correctly on the server
[22 Feb 2005 6:50] Jan Lindström 
I could repeat this problem with fresh bk pull today using following test scripts:

perl ibtest3 >out3 &
perl ibtest3a >out3a &
perl ibtest5 >out5 &
perl ibtest5a >out5a &
perl ibtest7 >out7 &
perl ibtest7a >out7a &
perl ibtest8 >out8 &
perl ibtest8a >out8a &
perl ibtest9 >out 9 &
perl ibtest9a >out9a &
perl ibtest12 >out12 &
perl ibtest12a >out12a &
perl ibtest13 >out13 &
perl ibtest13a >out13a &
perl ibtest15 >out15 &
perl ibtest15a >out15a &

After few minutes I issued ./mysqladmin shutdown command and still mysqld
has not done the shutdown (after 10 minutes). But if I do killall -9 mysqld and start again recovery succees and no errors are printed. And after second try I get this:

InnoDB: Transaction 0 86152 in prepared state after recovery
InnoDB: Transaction contains changes to 1 rows
InnoDB: 1 transactions in prepare state after recovery
mysqld got signal 11;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=0
read_buffer_size=131072
max_used_connections=0
max_connections=100
threads_connected=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 217596 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=(nil)
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
Cannot determine thread, fp=0xbfffbc88, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x819722d
0x4006896c
0x826bcaa
0x827420f
0x825ebc0
0x8220d02
0x8220989
0x8198cb7
0x81991b4
0x4012ed17
0x80fcb81
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/mysql/en/Using_stack_trace.html and follow instructions on how to resolve the stack trace. Resolved
stack trace is much more helpful in diagnosing the problem, so please do
resolve it
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.
[22 Feb 2005 7:01] Jan Lindström 
Using gdb I can pinpoint the place:

InnoDB: Starting recovery for XA transactions...
InnoDB: Transaction 0 86152 in prepared state after recovery
InnoDB: Transaction contains changes to 1 rows
InnoDB: 1 transactions in prepare state after recovery

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 16384 (LWP 1199)]
0x0826bcaa in innobase_commit_low(trx_struct*) (trx=0x402d3c68)
    at ha_innodb.cc:1350
1350            if (current_thd->slave_thread) {
(gdb) p HAVE_REPLICATION
No symbol "HAVE_REPLICATION" in current context.
(gdb) list 1336
1336    /*********************************************************************
1337    Commits a transaction in an InnoDB database. */
1338
1339    void
1340    innobase_commit_low(
1341    /*================*/
1342            trx_t*  trx)    /* in: transaction handle */
1343    {
1344            if (trx->conc_state == TRX_NOT_STARTED) {
(gdb)
1345
1346                    return;
1347            }
1348
1349    #ifdef HAVE_REPLICATION
1350            if (current_thd->slave_thread) {
1351                    /* Update the replication position info inside InnoDB*/
1352
1353                    trx->mysql_master_log_file_name
1354                                            = active_mi->rli.group_master_log_name;
(gdb) p current_thd
No symbol "current_thd" in current context.

I don't know how to access that variable (I have compiled with ./BUILD/compile-pentium-debug). I will try compile with -g3 -O0.

And where gives:

#0  0x0826bcaa in innobase_commit_low(trx_struct*) (trx=0x402d3c68)
    at ha_innodb.cc:1350
#1  0x0827420f in innobase_commit_by_xid(xid_t*) (xid=0x42c30020)
    at ha_innodb.cc:6375
#2  0x0825ebc0 in ha_recover(st_hash*) (commit_list=0xbfffc100)
    at handler.cc:766
#3  0x08220d02 in MYSQL_LOG::recover(st_io_cache*, Format_description_log_event*) (this=0x8623de0, log=0xbfffd200, fdle=0x8c7b4f0) at log.cc:3025
#4  0x08220989 in MYSQL_LOG::open(char const*) (this=0x8623de0,
    opt_name=0x8483a78 "tc.log") at log.cc:2949
#5  0x08198cb7 in init_server_components () at mysqld.cc:2741
#6  0x081991b4 in main (argc=1, argv=0xbffff414) at mysqld.cc:3031
[22 Feb 2005 14:42] Heikki Tuuri 
Sergei, Jan,

with a 5.0 built 10 minutes ago, I still get the phantom trx object, after killing -9 mysqld.

Regards,

Heikki

heikki@hundin:~/test> perl ibtest7 > out7 &
[1] 24275
heikki@hundin:~/test> perl ibtest7a > out7a &
[2] 24279
heikki@hundin:~/test> perl ibtest12 > out12 &
[3] 24283
heikki@hundin:~/test> perl ibtest12a > out12a &
[4] 24287
heikki@hundin:~/test>
heikki@hundin:~/test>
heikki@hundin:~/test>
heikki@hundin:~/test>
heikki@hundin:~/test>
heikki@hundin:~/test> killall -9 mysqld
heikki@hundin:~/test>
heikki@hundin:~/test>
heikki@hundin:~/test> killall -9 perl

heikki@hundin:~/mysql-5.0/sql> ./mysqld
InnoDB: The first specified data file /home/heikki/data/ibdata1 did not exist:
InnoDB: a new database to be created!
050222 15:52:27  InnoDB: Setting file /home/heikki/data/ibdata1 size to 50 MB
InnoDB: Database physically writes the file full: wait...
050222 15:52:46  InnoDB: Log file /home/heikki/data/ib_logfile0 did not exist: n
ew to be created
InnoDB: Setting log file /home/heikki/data/ib_logfile0 size to 15 MB
InnoDB: Database physically writes the file full: wait...
050222 15:52:52  InnoDB: Log file /home/heikki/data/ib_logfile1 did not exist: n
ew to be created
InnoDB: Setting log file /home/heikki/data/ib_logfile1 size to 15 MB
InnoDB: Database physically writes the file full: wait...
050222 15:52:57  InnoDB: Log file /home/heikki/data/ib_logfile2 did not exist: n
ew to be created
InnoDB: Setting log file /home/heikki/data/ib_logfile2 size to 15 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Doublewrite buffer not found: creating new
InnoDB: Doublewrite buffer created
InnoDB: Creating foreign key constraint system tables
InnoDB: Foreign key constraint system tables created
050222 15:53:05  InnoDB: Started; log sequence number 0 0
050222 15:53:05 [Warning] mysql.user table is not updated to new password format
; Disabling new password usage until mysql_fix_privilege_tables is run
./mysqld: ready for connections.
Version: '5.0.3-alpha-debug-log'  socket: '/home/heikki/bugsocket'  port: 3307
Source distribution
Killed
heikki@hundin:~/mysql-5.0/sql> ./mysqld
050222 15:55:04  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
050222 15:55:04  InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 0 3107387.
InnoDB: Doing recovery: scanned up to log sequence number 0 8350208
InnoDB: Doing recovery: scanned up to log sequence number 0 13593088
InnoDB: Doing recovery: scanned up to log sequence number 0 18835968
InnoDB: Doing recovery: scanned up to log sequence number 0 24078848
InnoDB: Doing recovery: scanned up to log sequence number 0 29321728
InnoDB: Doing recovery: scanned up to log sequence number 0 30573667
InnoDB: 3 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 825 row operations to undo
InnoDB: Trx id counter is 0 14336
050222 15:55:34  InnoDB: Starting an apply batch of log records to the database.
..
InnoDB: Progress in percents: 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 2
1 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47
48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74
 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Starting in background the rollback of uncommitted transactions
050222 15:56:07  InnoDB: Rolling back trx with id 0 13592, 436 rows to undo
050222 15:56:07  InnoDB: Started; log sequence number 0 30573667

InnoDB: Rolling back of trx id 0 13592 completed
050222 15:56:08  InnoDB: Rolling back trx with id 0 13590, 389 rows to undo

InnoDB: Rolling back of trx id 0 13590 completed
050222 15:56:08  InnoDB: Rollback of uncommitted transactions completed
050222 15:56:11  InnoDB: Starting recovery for XA transactions...
050222 15:56:11  InnoDB: Transaction 0 13852 in prepared state after recovery
050222 15:56:11  InnoDB: Transaction contains changes to 1 rows
050222 15:56:11  InnoDB: 1 transactions in prepare state after recovery
050222 15:56:12 [Warning] mysql.user table is not updated to new password format
; Disabling new password usage until mysql_fix_privilege_tables is run
./mysqld: ready for connections.
Version: '5.0.3-alpha-debug-log'  socket: '/home/heikki/bugsocket'  port: 3307
Source distribution

mysql> show innodb status\G
*************************** 1. row ***************************
Status:
=====================================
050222 15:59:13 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 62 seconds
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 14, signal count 14
Mutex spin waits 0, rounds 0, OS waits 0
RW-shared spins 26, OS waits 13; RW-excl spins 1, OS waits 1
------------
TRANSACTIONS
------------
Trx id counter 0 14338
Purge done for trx's n:o < 0 14336 undo n:o < 0 0
History list length 2
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 24362, OS thread id 163851
MySQL thread id 1, query id 1 localhost heikki
show innodb status
---TRANSACTION 0 13852, ACTIVE 219 sec, process no 0, OS thread id 0
, undo log entries 1
[22 Feb 2005 19:57] Sergei Golubchik 
The problem is that InnoDB somehow loses the XID and it's not stored on disk.
So, on recovery MySQL cannot recognize thetransaction and commit or rollback it.
[11 Mar 2005 11:19] Bugs System 
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/internals/22933
[6 Apr 2005 15:09] Heikki Tuuri 
This was fixed with many other XA bugs before 5.0.3 was released.