Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-11628

mysql.slow_log reports incorrect start time

Details

    Description

      MariaDB [test]> truncate mysql.slow_log;
      Query OK, 0 rows affected (0.00 sec)
       
      MariaDB [test]> select current_time(); select sleep(10); select current_time();
      +----------------+
      | current_time() |
      +----------------+
      | 17:24:37       |
      +----------------+
      1 row in set (0.00 sec)
       
      +-----------+
      | sleep(10) |
      +-----------+
      |         0 |
      +-----------+
      1 row in set (10.00 sec)
       
      +----------------+
      | current_time() |
      +----------------+
      | 17:24:47       |
      +----------------+
      1 row in set (0.00 sec)
       
      MariaDB [test]> select start_time, sql_text from mysql.slow_log;
      +----------------------------+-------------------------+
      | start_time                 | sql_text                |
      +----------------------------+-------------------------+
      | 2016-12-21 17:24:15.320518 | truncate mysql.slow_log |
      | 2016-12-21 17:24:37.593565 | select current_time()   |
      | 2016-12-21 17:24:47.595008 | select sleep(10)        | <-- Start time is ~10sec after previous command
      | 2016-12-21 17:24:47.596239 | select current_time()   |
      +----------------------------+-------------------------+
      4 rows in set (0.00 sec)
      
      

      Attachments

        Issue Links

          Activity

            diff --git a/sql/log.cc b/sql/log.cc
            index 569942a..b46d6d6 100644
            --- a/sql/log.cc
            +++ b/sql/log.cc
            @@ -1317,8 +1317,8 @@ bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length,
                 DBUG_ASSERT(thd->start_time);
                 query_utime= (current_utime - thd->start_utime);
                 lock_utime=  (thd->utime_after_lock - thd->start_utime);
            -    my_hrtime_t current_time= { hrtime_from_time(thd->start_time) +
            -                                thd->start_time_sec_part + query_utime };
            +    my_hrtime_t start_time= { hrtime_from_time(thd->start_time) +
            +                              thd->start_time_sec_part };
             
                 if (!query)
                 {
            @@ -1328,7 +1328,7 @@ bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length,
                 }
             
                 for (current_handler= slow_log_handler_list; *current_handler ;)
            -      error= (*current_handler++)->log_slow(thd, current_time,
            +      error= (*current_handler++)->log_slow(thd, start_time,
                                                         user_host_buff, user_host_len,
                                                         query_utime, lock_utime, is_command,
                                                         query, query_length) || error;
            

            nirbhay_c Nirbhay Choubey (Inactive) added a comment - diff --git a/sql/log.cc b/sql/log.cc index 569942a..b46d6d6 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -1317,8 +1317,8 @@ bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length, DBUG_ASSERT(thd->start_time); query_utime= (current_utime - thd->start_utime); lock_utime= (thd->utime_after_lock - thd->start_utime); - my_hrtime_t current_time= { hrtime_from_time(thd->start_time) + - thd->start_time_sec_part + query_utime }; + my_hrtime_t start_time= { hrtime_from_time(thd->start_time) + + thd->start_time_sec_part }; if (!query) { @@ -1328,7 +1328,7 @@ bool LOGGER::slow_log_print(THD *thd, const char *query, uint query_length, } for (current_handler= slow_log_handler_list; *current_handler ;) - error= (*current_handler++)->log_slow(thd, current_time, + error= (*current_handler++)->log_slow(thd, start_time, user_host_buff, user_host_len, query_utime, lock_utime, is_command, query, query_length) || error;

            People

              serg Sergei Golubchik
              nirbhay_c Nirbhay Choubey (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.