MySQL Lists are EOL. Please join:

List:Commits« Previous MessageNext Message »
From:He Zhenxing Date:September 24 2009 3:24am
Subject:Re: bzr commit into mysql-5.1-bugteam branch (zhenxing.he:2973)
Bug#37148
View as plain text  
Hi Andrei,

Thank you for the review and nice discussion!

Andrei Elkin wrote:
> Zhen Xing, hello.
> 
> As we have talked today the whole problem of the bug is proven to be
> serious indeed.
> 
> The reporter did not mean it but eventually you showed a good way to 
> "reproduce" the problem.
> 
> >> CREATE USER test_user;
> >> SET GLOBAL debug="d,injecting_fault_writing";
> >> REVOKE ALL PRIVILEGES, GRANT OPTION FROM test_user;
> >>
> >> And there is still assertion in Diagnostics_area::set_error_status():
> >>  DBUG_ASSERT(! is_set() || can_overwrite_status);
> 
> So that happens without your patch.
> The assert issue is in that my_ok() is called after my_error().
> And my_ok() in this particual execution branch is called because the caller
> does not have any clue that `injecting_fault_writing' error has happened.
> Your patch actually corrects all binlog-error-prone invocations of my_ok().
> And that is good.
> 
> I have one proposal. Why not assert 
>  
>     DBUG_ASSERT(! is_error() ) 
> 
> in my_ok()? After all my_ok() does not mean error-to-ok state transition.
> 

I think we do not allow my_oK() after my_ok() either. So the assertion
is (! is_set()) instead of (! is_error()).

> More radical suggestion, that I would like to hear opinion from Kostja, maybe
> we can remove my_ok() altogether but rather to check is_error(), as it happens anyway
> in net_end_statement(), to decide how to terminate the current statement?
> 

I'm not quite sure whether this is good or not. probably can simplify
the logic and code.

> cheers,
> 
> Andrei
> 
> 
> >
> >>> 
> >>> 1. as said above, to simulate an error
> >>
> >> This is easy. and there is already such a mechanism.
> >>
> >>> 2. to execute one by one all or most or even some affected query cases
> >>>    that easy to identify 
> >>> 
> >>
> >> Actually this is the part that I think difficult to do. I think it's
> >> hard (and implementation dependent) to check if the return value of
> >> mysql_bin_log.write() is correctly propagated or not. Could you please
> >> provide an example on how to test this?
> >
> > As suggested let's not aim at the most comprehensive testing now.
> > So cases we could check could include (some) DDL:s and some DML "failing"
> inside
> > mysql_bin_log.write().
> >
> > The client shall expect a corresponding error code.
> >
> >
> >>> > I don't agree it's only about optimization, fail to check the
> return
> >>> > value early can result in problem. For example, if we got an error
> in
> >>> > mysql_bin_log.write(), it will set thd->main_da->is_error(),
> and if we
> >>> > continue the execution and then encounter another error and try to
> call
> >>> > my_error() to report it, this will cause the assertion in
> >>> > Diagnostics_area::set_error_status() to fail because the error
> status
> >>> > has already been set. This problem can be avoided by checking the
> error
> >>> > and quite early.
> >>> 
> >>> I must confess some of my standing points have been connected to 5.4
> >>> code features.
> >>> What you have written is actually exclusive 5.1 issue, not 5.4. 
> >>> Multiple my_error() per query is okay in the latter version.
> >>> So more to the optimization the patch is trying to circumevent this
> >>> 5.1 limitation as well.
> >>> 
> >>
> >> I don't think so, I run the following test and it crashes on 5.4 too:
> >
> > First, I really meant the multiple error per query feature is certainly in 6.0.
> > I am not sure if it in azalea, needs investigating.
> >
> >
> >>
> >> CREATE USER test_user;
> >> SET GLOBAL debug="d,injecting_fault_writing";
> >> REVOKE ALL PRIVILEGES, GRANT OPTION FROM test_user;
> >>
> >> And there is still assertion in Diagnostics_area::set_error_status():
> >>  DBUG_ASSERT(! is_set() || can_overwrite_status);
> >>
> >
> > The same assertion happens to me on the vanilla mysql-azalea. It seems to be a
> separate bug
> > because along the execution patch there is just one call to my_error().
> >

there is one in MYSQL_BIN_LOG::set_write_error() too.

> >
> >>> 
> >>> Why not to make it 
> >>> 
> >>> >
> >>> >> if (thd->binlog_query(..)
> >>> >> {
> >>> >>      table->file->ha_release_auto_increment();
> >>> >>      DBUG_RETURN(1);
> >>> >> }
> >>> >> table->file->ha_release_auto_increment();
> >>> >> 
> >>> 
> >>
> >> The above should be:
> >>
> >> error= <possible handler errors>
> >>
> >> if (!error && mysql_bin_log.is_open())
> >> {
> >>    if (thd->binlog_query())
> >>    {
> >>       table->file->ha_release_auto_increment();
> >>       DBUG_RETURN(1);
> >>    }
> >> }
> >> table->file->ha_release_auto_increment();
> >>
> >> if (error)
> >> {
> >>   table->file->print_error(error,MYF(0));
> >>   DBUG_RETURN(1);
> >> }
> >>
> >>> error= thd->binlog_query(..)
> >>> table->file->ha_release_auto_increment();
> >>> if (error)
> >>>    DBUG_RETURN(error)
> >>> 
> >>> one line less then?
> >>> 
> >>
> >> I'm afraid this is not correct, please check the code above.
> >>
> >
> > I did not mean a copy-paste ready code, that was just a concept.
> >
> >> If we want to only have one ha_release_auto_increment() here, then we
> >> need a new variable like 'binlog_error', and change the code like this:
> >>
> >> error= <possible handler errors>
> >>
> >> int binlog_error= 0;
> >> if (!error && mysql_bin_log.is_open())
> >> {
> >>    ...
> >>    binlog_error= thd->binlog_query();
> >> }
> >> table->file->ha_release_auto_increment();
> >>
> >> if (binlog_error)
> >>   DBUG_RETURN(1);
> >>
> >> if (error)
> >> {
> >>   table->file->print_error(error,MYF(0));
> >>   DBUG_RETURN(1);
> >> }
> >
> >
> > I see. print_error() should be called solely for engine related 
> > not for binlog related error. 
> >
> > However, 
> >
> > error= binlog_error= thd->binlog_query();
> > table->file->ha_release_auto_increment();
> > ...
> >
> > if (error)
> >    if (error != binlog_error)
> >      table->file->print_error(error,MYF(0));
> >     DBUG_RETURN(1);
> >
> > does not have the repeating pattern. That's for your deliberation.
> >

OK

> >
> >>> >> 
> >>> >> Obviously, the old code is okay:
> >>> >> 
> >>> >
> >>> > No, actually the old code will cause problem, because if there is
> >>> > already error in write_bin_log, then try to report another error
> by
> >>> > my_message will cause assertion failure.
> >>> 
> >>> well, in 5.1 only.
> >>> 
> >>
> >> See above comments.
> >>
> >>> >
> >>> >>    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().
> >>> >> 
> >>> >
> >>> > I mean the code should check the error and return early.
> >>> >
> >>> 
> >>> We can say should in 5.1. But you want leave these lines in 5.4.
> >>> 
> >>> 
> >>> 
> >>> >> 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:
> >>> >> 
> >>> >
> >>> > This error is ignored deliberately, and is OK.
> >>> >
> >>> >> @@ -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:
> >>> >> 
> >>> >
> >>> > here too.
> >>> >
> >>> >> 
> >>> >> === 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,
> >>> 
> >>> ok
> >>> 
> >>> >> 
> >>> >> 
> >>> >>
> ===============================================================================
> >>> >> 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.
> >>> >> 
> >>> >
> >>> > Agree, and since close_temporary_tables() is called when closing
> the
> >>> > current connection, so I think the warning is no necessary, will
> be
> >>> > removed.
> >>> >
> >>> 
> >>> And moreover, this subsequent to the write's  my_error()
> >>> push_warning() should lead to the assertion, should it not?
> >>> 
> >>
> >> No, because push_warning will not set error status if it's already set.
> >> The check is done in THD::raise_condition().
> >>
> >>> 
> >>> >>
> ============================================================================
> >>> >> QUESTIONS:
> >>> >> 
> >
> >
> >>> >
> >>> >>
> =========================================================================
> >>> >> 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.
> >>> >> 
> >>> >
> >>> > if (!result) means there is no error, and main_da->is_error()
> must be
> >>> > false in this case.
> >>> 
> >
> >>> It's just a hope. net_end_statement() does it right to separate
> >>> failure from ok via testing main_da.
> >>> Just one little argument about the error propagation via integer
> >>> return value. It just can't work with functions that return an integer
> >>> informal results. Like random(). if that could call my_error() inside
> >>> we would have to examine main_da not -1 of the return value.
> >>> 
> >
> >> I think there is a difference between the return value of a function and
> >> the error in main_da, main_da->is_error() means there is an error that
> >> causes current statement to fail, while the return value of a function
> >> (if the return value indicates success or failure) only means if there
> >> is a problem when executing that function or not. it may or may not set
> >> main_da->is_error() when the function fails.
> >
> > I would agree, but only in principle. In practice if our code's function fail to
> read
> > it does not supply a valid result to the caller we need to issue my_error() or
> smth.
> > And my point is you can't delegate that to the caller. Therefore practically 
> > it's inevitable to have a stack of errors reported. 
> >
> >> But on the other hand, if
> >> the function succeeded, it should never set main_da->is_error().
> >
> > agreed.
> >
> >> I think
> >> this must be followed, otherwise a lot of the code would be break on
> >> this.
> >>
> >> And I think check the return value of the function and do error handling
> >> as early as possible should be a coding style that we should follow.
> >>
> >
> > Yes, callers have to examine main_da at their critical execution points.
> > And I agree with `as early as possible'. However, `possible' 
> > implies subjective thinking. Most of error can be tolerated until
> > deciding whether to commit or what send back to the user: net_end_statement().
> >
> >
> >> For functions like random(), the return value does not indicate failure
> >> or success, I think this is another issue.
> >>
> >> And let's suppose random() would call set is_error() when it failed,
> >> then I think you should check is_error() **immediately** after calling
> >> random(), not postpone the check to the end of the execution.
> >>
> >> ------- I think this is correct ----------------
> >> val= random();
> >> if (is_error())
> >>   // do error handling
> >> else
> >>   // use the 'val' to continue
> >> ----------------------------------------------------
> >>
> >> --------- I think this is not ----------------------
> >> val= random();
> >> // use the 'val' to continue
> >> ....
> >> if (is_error())
> >>   // do error handling
> >>
> >
> > Immediately is too strong. Checking is enough to do at critical points.
> 

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