MySQL Lists are EOL. Please join:

List:Commits« Previous MessageNext Message »
From:Alfranio Correia Date:September 22 2009 6:45am
Subject:Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)
Bug#37148
View as plain text  
Let's have a call today and discuss this.
Or we can wait for the meeting tomorrow.

Cheers.

Andrei Elkin wrote:
> Zhen Xing, hello.
>
> I have some concerns, questions, comments and remarks.
> Besides, I believe this work rather big patch would have less chances
> to break anything if we had a test. I suggest to add one an error
> simulation inside MYSQL_BIN_LOG::write() and activate it in the test.
>
>   
>> Andrei Elkin wrote:
>>     
>>> Zhen Xing, hello.
>>>
>>>       
>>>> #At file:///media/sdb2/hezx/work/mysql/bzrwork/b37148/5.1-bugteam/ based
> on revid:aelkin@stripped
>>>>
>>>>  2973 He Zhenxing	2009-08-20
>>>>       BUG#37148 Most callers of mysql_bin_log.write ignore the return
> result
>>>>       
>>>>       The return value of mysql_bin_log.write was ignored by most
> callers,
>>>>       which may lead to inconsistent on master and slave if the
> transaction
>>>>       was committed while the binlog was not correctly written.
>>>>         
>>> I think it's important either to provide a test case proving the
>>> complaining lines are not longer valid after your patch, or to
>>> describe specifically how incorectness can be gained.
>>>
>>>       
>> I think we already have decided on this in the conference meeting that a
>> test case is not needed for this.
>>
>> Please check this:
>>  
> https://intranet.mysql.com/~lthalmann/ltplan.pl?file=mom-rpl.org&section=MOM-RPL-090902
>>
>>     
>
> My question carried two alternatives. If one doesn't like the testing
> idea he has to compensate that by description what is the bug, what
> is fixed and what is not.
> Previously I thought testing would be difficult while the problem does
> not match to that. Now I am inclined to reconsider it.
> Considering rather big volume of changes I think we need at least a simple error
> simulation test that would verify affected code branches.
>
>   
>>> As it stands the whole idea of the bug complaint is to optimize the error
>>> path in that to react on an error condition sooner and not to do some
>>> extra work.
>>>       
>> Yes, I think it's good to react on the error sooner, for example if we
>> are doing a LOAD DATA statement to load a big hunk of data and if
>> binlogging fails at the beginning, it would be much better to check for
>> this error and quit the statement early then wait until the end of the
>> statement. And I also think it would make the code clearer and less
>> error prone.
>>
>>     
>
> Your comments confirm the bug is rather about optimization.
> The existing logics of examining thd->main_da->is_error() at the end
> of query execution does not seem to be compromised.
> Correct me if it is said wrong.
>
> Considering the current patch, I have some concerns, comments and
> idea, please read on.
>
> CONCERNS:
>
> I have noticed some dangerous places.
> Your patch forces early return from some functions like
>
> @@ -2029,8 +2030,9 @@ ndb_binlog_thread_handle_schema_event(TH
>          case SOT_CLEAR_SLOCK:
>            abort();
>          }
> -        if (log_query && ndb_binlog_running)
> -          ndb_binlog_query(thd, schema);
> +        if (log_query && ndb_binlog_running &&
> +            ndb_binlog_query(thd, schema))
> +          DBUG_RETURN(1);
>
> but I wonder if the early return does not leave out
> the functions' epilogs. The qouted
> ndb_binlog_thread_handle_schema_event()
>
>         if (log_query && ndb_binlog_running)
>           ndb_binlog_query(thd, schema);
>
> follows with
>         
>         if (bitmap_is_set(&slock, node_id))
>         {
>           if (post_epoch_unlock)
>             post_epoch_unlock_list->push_back(schema, mem_root);
>           else
>             ndbcluster_update_slock(thd, schema->db, schema->name);
>         }
>       }
>       DBUG_RETURN(0);
>
>
> It's evident your patch eliminates the `if (bitmap_is_set...)'.
> I would not do that unless ha_ndbcluster_binlog.cc maintainers are
> okay.
>
>
> Similarly here
>
> @@ -2288,14 +2290,15 @@ ndb_binlog_thread_handle_schema_event_po
>          share= 0;
>        }
>      }
> -    if (ndb_binlog_running && log_query)
> -      ndb_binlog_query(thd, schema);
> +    if (ndb_binlog_running && log_query &&
> +        ndb_binlog_query(thd, schema))
> +      DBUG_RETURN(1);
>
> Similarly here
>
> === modified file 'sql/sql_insert.cc'
> --- a/sql/sql_insert.cc	2009-06-22 14:01:42 +0000
> +++ b/sql/sql_insert.cc	2009-08-20 09:53:53 +0000
> @@ -2683,10 +2683,11 @@ bool Delayed_insert::handle_inserts(void
>          will be binlogged together as one single Table_map event and one
>          single Rows event.
>        */
> -      thd.binlog_query(THD::ROW_QUERY_TYPE,
> -                       row->query.str, row->query.length,
> -                       FALSE, FALSE, errcode);
> -
> +      if (thd.binlog_query(THD::ROW_QUERY_TYPE,
> +                           row->query.str, row->query.length,
> +                           FALSE, FALSE, errcode))
> +        goto err;
> +      
>
> where `goto err' bypasses
>
>     if (table->s->blob_fields)
>       free_delayed_insert_blobs(table);
>
> that could be a part of a cleanup, as I read it.
>
> You took care of a cleanup, good, 
>
>    table->file->ha_release_auto_increment();
>
> in the following hunk
>
> @@ -3207,16 +3209,21 @@ bool select_insert::send_eof()
>      events are in the transaction cache and will be written when
>      ha_autocommit_or_rollback() is issued below.
>    */
> -  if (mysql_bin_log.is_open())
> +  if (mysql_bin_log.is_open() &&
> +      (!error || thd->transaction.stmt.modified_non_trans_table))
>    {
>      int errcode= 0;
>      if (!error)
>        thd->clear_error();
>      else
>        errcode= query_error_code(thd, killed_status == THD::NOT_KILLED);
> -    thd->binlog_query(THD::ROW_QUERY_TYPE,
> -                      thd->query, thd->query_length,
> -                      trans_table, FALSE, errcode);
> +    if (thd->binlog_query(THD::ROW_QUERY_TYPE,
> +                          thd->query, thd->query_length,
> +                          trans_table, FALSE, errcode))
> +    {
> +      table->file->ha_release_auto_increment();
> +      DBUG_RETURN(1);
> +    }
>
> But the resulting new code does not look pretty:
>
> if (thd->binlog_query(..)
> {
>      table->file->ha_release_auto_increment();
>      DBUG_RETURN(1);
> }
> table->file->ha_release_auto_increment();
>
>
> Some more findings.
>
>    @@ -6004,15 +6005,17 @@ bool mysql_revoke_all(THD *thd,  List <L
>
>    VOID(pthread_mutex_unlock(&acl_cache->lock));
>
>    -  write_bin_log(thd, FALSE, thd->query, thd->query_length);
>    +  int binlog_error=
>    +    write_bin_log(thd, FALSE, thd->query, thd->query_length);
>
>    rw_unlock(&LOCK_grant);
>    close_thread_tables(thd);
>
>    -  if (result)
>    +  /* error for writing binary log has already been reported */
>    +  if (result && !binlog_error)
>    my_message(ER_REVOKE_GRANTS, ER(ER_REVOKE_GRANTS), MYF(0));
>
>    -  DBUG_RETURN(result);
>    +  DBUG_RETURN(result || binlog_error);
>    }
>  
>
> Obviously, the old code is okay:
>
>    if (result)
>       my_message()
>
> because the returned combined result
>    +  DBUG_RETURN(result || binlog_error);
> is not yet merged at that point.
>
>
> === modified file 'sql/sql_base.cc'
> --- a/sql/sql_base.cc	2009-06-19 08:24:43 +0000
> +++ b/sql/sql_base.cc	2009-08-20 09:53:53 +0000
> @@ -1333,7 +1333,8 @@ void close_thread_tables(THD *thd)
>        handled either before writing a query log event (inside
>        binlog_query()) or when preparing a pending event.
>       */
> -    thd->binlog_flush_pending_rows_event(TRUE);
> +    /* TODO: I (hezx) think the error here should not be ignored */
> +    (void)thd->binlog_flush_pending_rows_event(TRUE);
>      mysql_unlock_tables(thd, thd->lock);
>      thd->lock=0;
>    }
>
> I don't think you need such TODO here. The error is not ignored but
> rather its check-out delayed till net_end_statement().
>
> Similar hunk follows:
>
> === modified file 'sql/sql_delete.cc'
> --- a/sql/sql_delete.cc	2009-06-19 08:24:43 +0000
> +++ b/sql/sql_delete.cc	2009-08-20 09:53:53 +0000
> @@ -841,9 +841,10 @@ void multi_delete::abort()
>      if (mysql_bin_log.is_open())
>      {
>        int errcode= query_error_code(thd, thd->killed == THD::NOT_KILLED);
> -      thd->binlog_query(THD::ROW_QUERY_TYPE,
> -                        thd->query, thd->query_length,
> -                        transactional_tables, FALSE, errcode);
> +      /* possible error of writing binary log is ignored deliberately */
> +      (void) thd->binlog_query(THD::ROW_QUERY_TYPE,
> +                               thd->query, thd->query_length,
> +                               transactional_tables, FALSE, errcode);
>
> Yet another with the same comment:
>
> @@ -3784,7 +3794,8 @@ void select_create::abort()
>    select_insert::abort();
>    thd->transaction.stmt.modified_non_trans_table= FALSE;
>    reenable_binlog(thd);
> -  thd->binlog_flush_pending_rows_event(TRUE);
> +  /* possible error of writing binary log is ignored deliberately */
> +  (void)thd->binlog_flush_pending_rows_event(TRUE);
>
> And this one:
>
>
> === modified file 'sql/sql_update.cc'
> --- a/sql/sql_update.cc	2009-06-18 14:16:14 +0000
> +++ b/sql/sql_update.cc	2009-08-20 09:53:53 +0000
> @@ -1851,9 +1851,10 @@ void multi_update::abort()
>          into repl event.
>        */
>        int errcode= query_error_code(thd, thd->killed == THD::NOT_KILLED);
> -      thd->binlog_query(THD::ROW_QUERY_TYPE,
> -                        thd->query, thd->query_length,
> -                        transactional_tables, FALSE, errcode);
> +      /* the error of binary logging is ignored */
> +      (void)thd->binlog_query(THD::ROW_QUERY_TYPE,
>
>
> ===============================================================================
> COMMENTS:
>
> This hunk seems to be okay
>
> @@ -1543,7 +1544,11 @@ void close_temporary_tables(THD *thd)
>                              s_query.length() - 1 /* to remove trailing ',' */,
>                              0, FALSE, 0);
>        thd->variables.character_set_client= cs_save;
> -      mysql_bin_log.write(&qinfo);
> +      if (mysql_bin_log.write(&qinfo))
> +      {
> +        push_warning(thd, MYSQL_ERROR::WARN_LEVEL_ERROR, MYF(0),
> +                     "Failed to write the DROP statement for temporary tables to
> binary log");
> +      }
>        thd->variables.pseudo_thread_id= save_pseudo_thread_id;
>      }
>      else
>
> though my_error() must have been done inside mysql_bin_log.write().
> I wonder if the warning is really necessary.
>
> ============================================================================
> QUESTIONS:
>
> === modified file 'sql/sql_repl.cc'
> --- a/sql/sql_repl.cc	2009-05-15 12:57:51 +0000
> +++ b/sql/sql_repl.cc	2009-08-20 09:53:53 +0000
> @@ -1007,8 +1007,8 @@ int reset_slave(THD *thd, Master_info* m
>    MY_STAT stat_area;
>    char fname[FN_REFLEN];
>    int thread_mask= 0, error= 0;
> -  uint sql_errno=0;
> -  const char* errmsg=0;
> +  uint sql_errno=ER_UNKNOWN_ERROR;
> +  const char* errmsg= "Unknown error occured while reseting slave";
>    DBUG_ENTER("reset_slave");
>
> why these changes?
>
> =========================================================================
> REMARKS
>
> The base code mysql_grant() calls
>
>   if (!result)
>   {
>     write_bin_log(thd, TRUE, thd->query, thd->query_length);
>   }
>
>   rw_unlock(&LOCK_grant);
>   close_thread_tables(thd);
>
>   if (!result)
>     my_ok(thd);
>
> my_ok() not after examining main_da->is_error(). Sounds like an issue.
>
> Similarly in mysql_create_db() and some more places.
>
>
>
> cheers,
>
> Andrei
>   

Thread
bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973) Bug#37148He Zhenxing20 Aug
  • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148Andrei Elkin17 Sep
    • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148He Zhenxing19 Sep
      • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148Alfranio Correia20 Sep
        • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148He Zhenxing21 Sep
      • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148Andrei Elkin21 Sep
        • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148He Zhenxing22 Sep
          • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148Andrei Elkin22 Sep
            • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148He Zhenxing23 Sep
              • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148Andrei Elkin23 Sep
                • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148Andrei Elkin23 Sep
                  • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148He Zhenxing24 Sep
        • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148Alfranio Correia22 Sep
          • Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)Bug#37148He Zhenxing22 Sep