The problem was when a GTID event was part of a group commit, and so contained
a commit id. The code that replaces GTID with a BEGIN event for old slaves did
not correctly handle this case.
Fix the code so that the GTID with commit id can also be properly replaced
with a BEGIN query event. The extra two bytes are in the BEGIN event replaced
with a dummy, empty time zone string.
Older master has no GTID events, so such events are not available for
deciding on scheduling of event groups and so on.
With this patch, we run such events from old masters single-threaded, in the
sql driver thread.
This seems better than trying to make the parallel code handle the data from
older masters; while possible, this would require a lot of testing (as well as
possibly some extra overhead in the scheduling of events), which hardly seems
worthwhile.
Clean up and improve the parallel implementation code, mainly related to
scheduling of work to threads and handling of stop and errors.
Fix a lot of bugs in various corner cases that could lead to crashes or
corruption.
Fix that a single replication domain could easily grab all worker threads and
stall all other domains; now a configuration variable
--slave-domain-parallel-threads allows to limit the number of
workers.
Allow next event group to start as soon as previous group begins the commit
phase (as opposed to when it ends it); this allows multiple event groups on
the slave to participate in group commit, even when no other opportunities for
parallelism are available.
Various fixes:
- Fix some races in the rpl.rpl_parallel test case.
- Fix an old incorrect assertion in Log_event iocache read.
- Fix repeated malloc/free of wait_for_commit and rpl_group_info objects.
- Simplify wait_for_commit wakeup logic.
- Fix one case in queue_for_group_commit() where killing one thread would
fail to correctly signal the error to the next, causing loss of the
transaction after slave restart.
- Fix leaking of pthreads (and their allocated stack) due to missing
PTHREAD_CREATE_DETACHED attribute.
- Fix how one batch of group-committed transactions wait for the previous
batch before starting to execute themselves. The old code had a very
complex scheduling where the first transaction was handled differently,
with subtle bugs in corner cases. Now each event group is always scheduled
for a new worker (in a round-robin fashion amongst available workers).
Keep a count of how many transactions have started to commit, and wait for
that counter to reach the appropriate value.
- Fix slave stop to wait for all workers to actually complete processing;
before, the wait was for update of last_committed_sub_id, which happens a
bit earlier, and could leave worker threads potentially accessing bits of
the replication state that is no longer valid after slave stop.
- Fix a couple of places where the test suite would kill a thread waiting
inside enter_cond() in connection with debug_sync; debug_sync + kill can
crash in rare cases due to a race with mysys_var_current_mutex in this
case.
- Fix some corner cases where we had enter_cond() but no exit_cond().
- Fix that we could get failure in wait_for_prior_commit() but forget to flag
the error with my_error().
- Fix slave stop (both for normal stop and stop due to error). Now, at stop
we pick a specific safe point (in terms of event groups executed) and make
sure that all event groups before that point are executed to completion,
and that no event group after start executing; this ensures a safe place to
restart replication, even for non-transactional stuff/DDL. In error stop,
make sure that all prior event groups are allowed to execute to completion,
and that any later event groups that have started are rolled back, if
possible. The old code could leave eg. T1 and T3 committed but T2 not, or
it could even leave half a transaction not rolled back in some random
worker, which would cause big problems when that worker was later reused
after slave restart.
- Fix the accounting of amount of events queued for one worker. Before, the
amount was reduced immediately as soon as the events were dequeued (which
happens all at once); this allowed twice the amount of events to be queued
in memory for each single worker, which is not what users would expect.
- Fix that an error set during execution of one event was sometimes not
cleared before executing the next, causing problems with the error
reporting.
- Fix incorrect handling of thd->killed in worker threads.
As part of the fix we don't anymore generate a create table statement when doing a
CREATE TABLE IF NOT EXISTS table_that_exist LiKE temporary_table
if the 'table_that_exist' existed.
This is because it's not self evident if we should generate a create statement
matching the existing table or the temporary_table.
The old code generated a table like the existing table in row based replication and like the temporary table
in statement based replication.
It's better to ensure that both cases works the same way.
mysql-test/suite/rpl/r/rpl_row_create_table.result:
Updated results
(Now we don't anymore CREATE TABLE IF NOT EXISTS LIKE if the table existed)
sql/sql_base.cc:
More DBUG_PRINT
sql/sql_error.cc:
More DBUG_PRINT
sql/sql_table.cc:
Don't generate a create table statement when doing a
CREATE TABLE IF NOT EXISTS table_that_exist like temporary_table if the table existed.
As a side-effect of purge_relay_logs(), sql_slave_skip_counter
was silently ignored in GTID mode.
But sql_slave_skip_counter in fact is not a good match with GTID.
And it is not really needed either, as users can explicitly set
@@gtid_slave_pos to skip specific GTIDs, in a way that matches
well how GTID replication works.
So with this patch, we give an error on attempts to set
sql_slave_skip_counter when using GTID, with a suggestion to use
gtid_slave_pos instead, if needed.
MDEV-4984: Implement MASTER_GTID_WAIT() and @@LAST_GTID.
MDEV-4726: Race in mysql-test/suite/rpl/t/rpl_gtid_stop_start.test
MDEV-5636: Deadlock in RESET MASTER
Rewrite the gtid_waiting::wait_for_gtid() function.
The code was rubbish (and buggy). Now the logic is
much clearer.
Also fix a missing slave sync that could cause test failure.
Some GTID test cases were using include/wait_condition.inc with a
condition like SELECT COUNT(*)=4 FROM t1 to wait for the slave to
catch up with the master. This causes races and test failures, as the
changes to the tables become visible at the COMMIT of the SQL thread
(or even before in case of MyISAM), but the changes to
@@gtid_slave_pos only become visible a little bit after the COMMIT.
Now that we have MASTER_GTID_WAIT(), just use that to sync up in a
GTID-friendly way, wrapped in nice include/save_master_gtid.inc and
include/sync_with_master_gtid.inc scripts.
MASTER_GTID_WAIT() is similar to MASTER_POS_WAIT(), but works with a
GTID position rather than an old-style filename/offset.
@@LAST_GTID gives the GTID assigned to the last transaction written
into the binlog.
Together, the two can be used by applications to obtain the GTID of
an update on the master, and then do a MASTER_GTID_WAIT() for that
position on any read slave where it is important to get results that
are caught up with the master at least to the point of the update.
The implementation of MASTER_GTID_WAIT() is implemented in a way
that tries to minimise the performance impact on the SQL threads,
even in the presense of many waiters on single GTID positions (as
from @@LAST_GTID).
mysql-test/r/lowercase_table2.result:
Updated result
(The change happend because we don't try to open the table anymore as part of create table)
mysql-test/suite/rpl/r/create_or_replace_mix.result:
Fixed result file
mysql-test/suite/rpl/r/create_or_replace_row.result:
Fixed result file
mysql-test/suite/rpl/r/create_or_replace_statement.result:
Fixed result file
mysql-test/suite/rpl/t/create_or_replace.inc:
Drop open temporary table
mysys/my_delete.c:
Added missing newline
plugin/metadata_lock_info/mysql-test/metadata_lock_info/r/user_lock.result:
Fixed result
(Lock names was before off by one. Was corrected by my previous patch)
sql/sql_select.cc:
Fixed compiler warnings by adding missing casts
storage/connect/ha_connect.cc:
Fixed compiler warnings
storage/innobase/os/os0file.cc:
Fixed compiler warnings
storage/xtradb/btr/btr0btr.cc:
Fixed compiler warnings
storage/xtradb/handler/ha_innodb.cc:
removed not used function
strings/ctype-uca.c:
Fixed compiler warnings
support-files/compiler_warnings.supp:
Added suppression for warnings that are wrong or are not serious andthat we don't plan to fix.
- CREATE TABLE is by default executed on the slave as CREATE OR REPLACE
- DROP TABLE is by default executed on the slave as DROP TABLE IF NOT EXISTS
This means that a slave will by default continue even if we try to create
a table that existed on the slave (the table will be deleted and re-created) or
if we try to drop a table that didn't exist on the slave.
This should be safe as instead of having the slave stop because of an inconsistency between
master and slave, it will fix the inconsistency.
Those that would prefer to get a stopped slave instead for the above cases can set slave_ddl_exec_mode to STRICT.
- Ensure that a CREATE OR REPLACE TABLE which dropped a table is replicated
- DROP TABLE that generated an error on master is handled as an identical DROP TABLE on the slave (IF NOT EXISTS is not added in this case)
- Added slave_ddl_exec_mode variable to decide how DDL's are replicated
New logic for handling BEGIN GTID ... COMMIT from the binary log:
- When we find a BEGIN GTID, we start a transaction and set OPTION_GTID_BEGIN
- When we find COMMIT, we reset OPTION_GTID_BEGIN and execute the normal COMMIT code.
- While OPTION_GTID_BEGIN is set:
- We don't generate implict commits before or after statements
- All tables are regarded as transactional tables in the binary log (to ensure things are executed exactly as on the master)
- We reset OPTION_GTID_BEGIN also on rollback
This will help ensuring that we don't get any sporadic commits (and thus new GTID's) on the slave and will help keep the GTID's between master and slave in sync.
mysql-test/extra/rpl_tests/rpl_log.test:
Added testing of mode slave_ddl_exec_mode=STRICT
mysql-test/r/mysqld--help.result:
New help messages
mysql-test/suite/rpl/r/create_or_replace_mix.result:
Testing of CREATE OR REPLACE TABLE with replication
mysql-test/suite/rpl/r/create_or_replace_row.result:
Testing of CREATE OR REPLACE TABLE with replication
mysql-test/suite/rpl/r/create_or_replace_statement.result:
Testing replication of create or replace
mysql-test/suite/rpl/r/rpl_gtid_startpos.result:
Test must be run in slave_ddl_exec_mode=STRICT as part of the test depends on that DROP TABLE should fail on slave.
mysql-test/suite/rpl/r/rpl_row_log.result:
Updated result
mysql-test/suite/rpl/r/rpl_row_log_innodb.result:
Updated result
mysql-test/suite/rpl/r/rpl_row_show_relaylog_events.result:
Updated result
mysql-test/suite/rpl/r/rpl_stm_log.result:
Updated result
mysql-test/suite/rpl/r/rpl_stm_mix_show_relaylog_events.result:
Updated result
mysql-test/suite/rpl/r/rpl_temp_table_mix_row.result:
Updated result
mysql-test/suite/rpl/t/create_or_replace.inc:
Testing of CREATE OR REPLACE TABLE with replication
mysql-test/suite/rpl/t/create_or_replace_mix.cnf:
Testing of CREATE OR REPLACE TABLE with replication
mysql-test/suite/rpl/t/create_or_replace_mix.test:
Testing of CREATE OR REPLACE TABLE with replication
mysql-test/suite/rpl/t/create_or_replace_row.cnf:
Testing of CREATE OR REPLACE TABLE with replication
mysql-test/suite/rpl/t/create_or_replace_row.test:
Testing of CREATE OR REPLACE TABLE with replication
mysql-test/suite/rpl/t/create_or_replace_statement.cnf:
Testing of CREATE OR REPLACE TABLE with replication
mysql-test/suite/rpl/t/create_or_replace_statement.test:
Testing of CREATE OR REPLACE TABLE with replication
mysql-test/suite/rpl/t/rpl_gtid_startpos.test:
Test must be run in slave_ddl_exec_mode=STRICT as part of the test depends on that DROP TABLE should fail on slave.
mysql-test/suite/rpl/t/rpl_stm_log.test:
Removed some lines
mysql-test/suite/sys_vars/r/slave_ddl_exec_mode_basic.result:
Testing of slave_ddl_exec_mode
mysql-test/suite/sys_vars/t/slave_ddl_exec_mode_basic.test:
Testing of slave_ddl_exec_mode
sql/handler.cc:
Regard all tables as transactional in commit if OPTION_GTID_BEGIN is set.
This is to ensure that statments are not commited too early if non transactional tables are used.
sql/log.cc:
Regard all tables as transactional in commit if OPTION_GTID_BEGIN is set.
Also treat 'direct' log events as transactional (to get them logged as they where on the master)
sql/log_event.cc:
Ensure that the new error from DROP TABLE when trying to drop a view is treated same as the old one.
Store error code that slave expects in THD.
Set OPTION_GTID_BEGIN if we find a BEGIN.
Reset OPTION_GTID_BEGIN if we find a COMMIT.
sql/mysqld.cc:
Added slave_ddl_exec_mode_options
sql/mysqld.h:
Added slave_ddl_exec_mode_options
sql/rpl_gtid.cc:
Reset OPTION_GTID_BEGIN if we record a gtid (safety)
sql/sql_class.cc:
Regard all tables as transactional in commit if OPTION_GTID_BEGIN is set.
sql/sql_class.h:
Added to THD: log_current_statement and slave_expected_error
sql/sql_insert.cc:
Ensure that CREATE OR REPLACE is logged if table was deleted.
Don't do implicit commit for CREATE if we are under OPTION_GTID_BEGIN
sql/sql_parse.cc:
Change CREATE TABLE -> CREATE OR REPLACE TABLE for slaves
Change DROP TABLE -> DROP TABLE IF EXISTS for slaves
CREATE TABLE doesn't force implicit commit in case of OPTION_GTID_BEGIN
Don't do commits before or after any statement if OPTION_GTID_BEGIN was set.
sql/sql_priv.h:
Added OPTION_GTID_BEGIN
sql/sql_show.cc:
Enhanced store_create_info() to also be able to handle CREATE OR REPLACE
sql/sql_show.h:
Updated prototype
sql/sql_table.cc:
Ensure that CREATE OR REPLACE is logged if table was deleted.
sql/sys_vars.cc:
Added slave_ddl_exec_mode
sql/transaction.cc:
Added warning if we got a GTID under OPTION_GTID_BEGIN
Using CREATE OR REPLACE TABLE is be identical to
DROP TABLE IF EXISTS table_name;
CREATE TABLE ...;
Except that:
* CREATE OR REPLACE is be atomic (now one can create the same table between drop and create).
* Temporary tables will not shadow the table name for the DROP as the CREATE TABLE tells us already if we are using a temporary table or not.
* If the table was locked with LOCK TABLES, the new table will be locked with the same lock after it's created.
Implementation details:
- We don't anymore open the to-be-created table during CREATE TABLE, which the original code did.
- There is no need to open a table we are planning to create. It's enough to check if the table exists or not.
- Removed some of duplicated code for CREATE IF NOT EXISTS.
- Give an error when using CREATE OR REPLACE with IF NOT EXISTS (conflicting options).
- As a side effect of the code changes, we don't anymore have to internally re-prepare prepared statements with CREATE TABLE if the table exists.
- Made one code path for all testing if log table are in use.
- Better error message if one tries to create/drop/alter a log table in use
- Added back disabled rpl_row_create_table test as it now seams to work and includes a lot of interesting tests.
- Added HA_LEX_CREATE_REPLACE to mark if we are using CREATE OR REPLACE
- Aligned CREATE OR REPLACE parsing code in sql_yacc.yy for TABLE and VIEW
- Changed interface for drop_temporary_table() to make it more reusable
- Changed Locked_tables_list::init_locked_tables() to work on the table object instead of the table list object. Before this it used a mix of both, which was not good.
- Locked_tables_list::unlock_locked_tables(THD *thd) now requires a valid thd argument. Old usage of calling this with 0 i changed to instead call Locked_tables_list::reset()
- Added functions Locked_tables_list:restore_lock() and Locked_tables_list::add_back_last_deleted_lock() to be able to easily add back a locked table to the lock list.
- Added restart_trans_for_tables() to be able to restart a transaction.
- DROP_ACL is required if one uses CREATE TABLE OR REPLACE.
- Added drop of normal and temporary tables in create_table_imp() if CREATE OR REPLACE was used.
- Added reacquiring of table locks in mysql_create_table() and mysql_create_like_table()
mysql-test/include/commit.inc:
With new code we get fewer status increments
mysql-test/r/commit_1innodb.result:
With new code we get fewer status increments
mysql-test/r/create.result:
Added testing of create or replace with timeout
mysql-test/r/create_or_replace.result:
Basic testing of CREATE OR REPLACE TABLE
mysql-test/r/partition_exchange.result:
New error message
mysql-test/r/ps_ddl.result:
Fewer reprepares with new code
mysql-test/suite/archive/discover.result:
Don't rediscover archive tables if the .frm file exists
(Sergei will look at this if there is a better way...)
mysql-test/suite/archive/discover.test:
Don't rediscover archive tables if the .frm file exists
(Sergei will look at this if there is a better way...)
mysql-test/suite/funcs_1/r/innodb_views.result:
New error message
mysql-test/suite/funcs_1/r/memory_views.result:
New error message
mysql-test/suite/rpl/disabled.def:
rpl_row_create_table should now be safe to use
mysql-test/suite/rpl/r/rpl_row_create_table.result:
Updated results after adding back disabled test
mysql-test/suite/rpl/t/rpl_create_if_not_exists.test:
Added comment
mysql-test/suite/rpl/t/rpl_row_create_table.test:
Added CREATE OR REPLACE TABLE test
mysql-test/t/create.test:
Added CREATE OR REPLACE TABLE test
mysql-test/t/create_or_replace-master.opt:
Create logs
mysql-test/t/create_or_replace.test:
Basic testing of CREATE OR REPLACE TABLE
mysql-test/t/partition_exchange.test:
Error number changed as we are now using same code for all log table change issues
mysql-test/t/ps_ddl.test:
Fewer reprepares with new code
sql/handler.h:
Moved things around a bit in a structure to get better alignment.
Added HA_LEX_CREATE_REPLACE to mark if we are using CREATE OR REPLACE
Added 3 elements to end of HA_CREATE_INFO to be able to store state to add backs locks in case of LOCK TABLES.
sql/log.cc:
Reimplemented check_if_log_table():
- Simpler and faster usage
- Can give error messages
This gives us one code path for allmost all error messages if log tables are in use
sql/log.h:
New interface for check_if_log_table()
sql/slave.cc:
More logging
sql/sql_alter.cc:
New interface for check_if_log_table()
sql/sql_base.cc:
More documentation
Changed interface for drop_temporary_table() to make it more reusable
Changed Locked_tables_list::init_locked_tables() to work on the table object instead of the table list object. Before this it used a mix of both, which was not good.
Locked_tables_list::unlock_locked_tables(THD *thd) now requires a valid thd argument. Old usage of calling this with 0 i changed to instead call Locked_tables_list::reset()
Added functions Locked_tables_list:restore_lock() and Locked_tables_list::add_back_last_deleted_lock() to be able to easily add back a locked table to the lock list.
Check for command number instead of open_strategy of CREATE TABLE was used.
Added restart_trans_for_tables() to be able to restart a transaction. This was needed in "create or replace ... select" between the drop table and the select.
sql/sql_base.h:
Added and updated function prototypes
sql/sql_class.h:
Added new prototypes to Locked_tables_list class
Added extra argument to select_create to avoid double call to eof() or send_error()
- I needed this in some edge case where the table was not created against expections.
sql/sql_db.cc:
New interface for check_if_log_table()
sql/sql_insert.cc:
Remember position to lock information so that we can reaquire table lock for LOCK TABLES + CREATE OR REPLACE TABLE SELECT. Later add back the lock by calling restore_lock().
Removed one not needed indentation level in create_table_from_items()
Ensure we don't call send_eof() or abort_result_set() twice.
sql/sql_lex.h:
Removed variable that I temporarly added in an earlier changeset
sql/sql_parse.cc:
Removed old test code (marked with QQ)
Ensure that we have open_strategy set as TABLE_LIST::OPEN_STUB in CREATE TABLE
Removed some IF NOT EXISTS code as this is now handled in create_table_table_impl().
Set OPTION_KEEP_LOGS later. This code had to be moved as the test for IF EXISTS has changed place.
DROP_ACL is required if one uses CREATE TABLE OR REPLACE.
sql/sql_partition_admin.cc:
New interface for check_if_log_table()
sql/sql_rename.cc:
New interface for check_if_log_table()
sql/sql_table.cc:
New interface for check_if_log_table()
Moved some code in mysql_rm_table() under a common test.
- Safe as temporary tables doesn't have statistics.
- !is_temporary_table(table) test was moved out from drop_temporary_table() and merged with upper level code.
- Added drop of normal and temporary tables in create_table_imp() if CREATE OR REPLACE was used.
- Added reacquiring of table locks in mysql_create_table() and mysql_create_like_table()
- In mysql_create_like_table(), restore table->open_strategy() if it was changed.
- Re-test if table was a view after opening it.
sql/sql_table.h:
New prototype for mysql_create_table_no_lock()
sql/sql_yacc.yy:
Added syntax for CREATE OR REPLACE TABLE
Reuse new code for CREATE OR REPLACE VIEW
sql/table.h:
Added name for enum type
sql/table_cache.cc:
More DBUG
The problem was a race between the SQL driver thread and the worker threads.
The SQL driver thread would set rli->last_master_timestamp to zero to
mark that it has caught up with the master, while the worker threads would
set it to the timestamp of the executed event. This can happen out-of-order
in parallel replication, causing the "caught up" status to be overwritten
and Seconds_Behind_Master to wrongly grow when the slave is idle.
To fix, introduce a separate flag rli->sql_thread_caught_up to mark that the
SQL driver thread is caught up. This avoids issues with worker threads
overwriting the SQL driver thread status. In parallel replication, we then
make SHOW SLAVE STATUS check in addition that all worker threads are idle
before showing Seconds_Behind_Master as 0 due to slave idle.
Add another test case. This one for killing a query that is waiting
for a prior commit, when --log-slave-updates=0 (in this case the
wait happens in different code from --log-slave-updates=1).
Add another test case. This one for killing the SQL driver thread while it is
waiting for room in the list of events queued for a worker thread.
Fix bugs found:
- Several memory leaks in various error cases.
- SQL error code was not set (for SHOW SLAVE STATUS etc.) when killed.
support ha_innodb.so as a dynamic plugin.
* remove obsolete *,innodb_plugin.rdiff files
* s/--plugin-load=/--plugin-load-add=/
* MYSQL_PLUGIN_IMPORT glob_hostname[]
* use my_error instead of push_warning_printf(ER_DEFAULT)
* don't use tdc_size and tc_size in a module
update test cases (XtraDB is 5.6.14, InnoDB is 5.6.10)
* copy new tests over
* disable some tests for (old) InnoDB
* delete XtraDB tests that no longer apply
small compatibility changes:
* s/HTON_EXTENDED_KEYS/HTON_SUPPORTS_EXTENDED_KEYS/
* revert unnecessary InnoDB changes to make it a bit closer to the upstream
fix XtraDB to compile on Windows (both as a static and a dynamic plugin)
disable XtraDB on Windows (deadlocks) and where no atomic ops are available (e.g. CentOS 5)
storage/innobase/handler/ha_innodb.cc:
revert few unnecessary changes to make it a bit closer to the original InnoDB
storage/innobase/include/univ.i:
correct the version to match what it was merged from
Add another test case. This one for killing a worker while its transaction is
waiting to start until the previous transaction has committed.
Fix setting reading_or_writing to 0 in worker threads so SHOW SLAVE STATUS can
show something more useful than "Reading from net".
The fix is to not change @relay_log_purge as part of the CHANGE MASTER.
(There is no logical reason why this is done in the current source)
mysql-test/suite/rpl/r/rpl_slave_status.result:
Ensure that CHANGE MASTER doesn't change relay_log_purge
mysql-test/suite/rpl/t/rpl_slave_status.test:
Ensure that CHANGE MASTER doesn't change relay_log_purge
sql/sql_repl.cc:
Don't change relay_log_purge in CHANGE MASTER
Add another test case.
Fix bug found: When one thread aborts, another thread might
wrongly advance the relay log position too far, causing the
fauling transaction to be skipped and thus lost upon
restarting the SQL thread after the failure.
Add a test case for killing a waiting query in parallel replication.
Fix several bugs found:
- We should not wakeup_subsequent_commits() in ha_rollback_trans(), since we
do not know the right wakeup_error() to give.
- When a wait_for_prior_commit() is killed, we must unregister from the
waitee so we do not race and get an extra (non-kill) wakeup.
- We need to deal with error propagation correctly in queue_for_group_commit
when one thread is killed.
- Fix one locking issue in queue_for_group_commit(), we could unlock the
waitee lock too early and this end up processing wakeup() with insufficient
locking.
- Fix Xid_log_event::do_apply_event; if commit fails it must not update the
in-memory @@gtid_slave_pos state.
- Fix and cleanup some things in the rpl_parallel.cc error handling.
- Add a missing check for killed in the slave sql driver thread, to avoid a
race.
MDEV-4725: Incorrect binlog state recovery if crash while writing event group
The binlog state was not recovered correctly if XA is not used (eg. InnoDB
disabled), or if server crashed in the middle of writing an event group to the
binlog.
With this patch, we ensure that recovery of binlog state is done even if we do
not do the full XA binlog recovery, and we ensure that we only recover fully
written event groups into the binlog state.
