Uploaded image for project: 'Percona Server'
  1. Percona Server
  2. PS-468

LP #719386: Query_time is increasing for every query a stored procedure logs to the slow log

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Done
    • Priority: High
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: None

      Description

      **Reported in Launchpad by Aleksandr Kuzminsky last update 16-11-2012 05:53:42

      Percona-Server 12.5 on Centos 5, 64 bit.

      When logging all queries a stored procedure executes, mysqld logs incrorrect Query_time:.

      Query execution time is not reset and every next Query_time: is logged as accumulated value:

      cat slow.log
      ...

      1. Query_time: 0.000530 Lock_time: 0.000000 Rows_sent: 0 Rows_examined: 0 Rows_affected: 0 Rows_read: 1
      2. Query_time: 0.595670 Lock_time: 0.000621 Rows_sent: 0 Rows_examined: 233664 Rows_affected: 0 Rows_read: 0
        ...
      3. Query_time: 128.371195 Lock_time: 128.371085 Rows_sent: 0 Rows_examined: 0 Rows_affected: 0 Rows_read: 1
        ...
      4. User@Host: [root] @ localhost []
      5. Thread_id: 1 Schema: xxx Last_errno: 0 Killed: 0
      6. Query_time: 128.371250 Lock_time: 128.371085 Rows_sent: 0 Rows_examined: 0 Rows_affected: 0 Rows_read: 1
      7. Bytes_sent: 11 Tmp_tables: 9 Tmp_disk_tables: 0 Tmp_table_sizes: 1023104
      8. InnoDB_trx_id: 222F
      9. QC_Hit: No Full_scan: Yes Full_join: No Tmp_table: Yes Tmp_table_on_disk: No
      10. Filesort: Yes Filesort_on_disk: No Merge_passes: 0
      11. InnoDB_IO_r_ops: 0 InnoDB_IO_r_bytes: 0 InnoDB_IO_r_wait: 0.000000
      12. InnoDB_rec_lock_wait: 0.000000 InnoDB_queue_wait: 0.000000
      13. InnoDB_pages_distinct: 30497
        SET timestamp=1297780057;
        CALL XXX();

      mysql> show variables like '%slow%';
      ---------------------------------------------------------------------+

      Variable_name Value

      ---------------------------------------------------------------------+

      log_slow_filter  
      log_slow_queries OFF
      log_slow_rate_limit 1
      log_slow_slave_statements OFF
      log_slow_sp_statements ON
      log_slow_timestamp_every OFF
      log_slow_verbosity microtime,query_plan,innodb
      slow_launch_time 2
      slow_query_log OFF
      slow_query_log_file /var/lib/mysql/sm1u02-slow.log
      slow_query_log_microseconds_timestamp OFF
      use_global_log_slow_control none

      ---------------------------------------------------------------------+
      12 rows in set (0.00 sec)

      mysql>

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              lpjirasync lpjirasync (Inactive)
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: