Bug #49128 Status variable for delayed insert queue waits is missing

• Submitted: 26 Nov 2009 9:35
• Modified: 17 Aug 2011 14:51
• Reporter: Oli Sennhauser
• Status: Won't fix
• Category: MySQL Server
• Severity: S4 (Feature request)
• Version: all
• OS: Any
• Assigned to: Marc ALFF
• CPU Architecture: Any

[26 Nov 2009 9:35] Oli Sennhauser

Description:
When there is a heavy use of DELAYED INSERTS and the delayed_queue_size is too small I can see in SHOW FULL PROCESSLIST:

1931677,DELAYED,localhost,adtiger,Delayed insert,0,Waiting for INSERT,,

but not during system analysis with SHOW GLOBAL STATUS;

How to repeat:
Do heavy DELAYED INSERTS on a table.

Suggested fix:
report in a status VARIABLE how often the delayed insert thread has to wait for the delayed insert queue to be emptied.

[17 Aug 2011 14:57] Marc ALFF

This feature is covered by the performance schema, see analysis below.

-- Marc Alff

---

The code related to delayed_queue_size is located in sql/sql_insert.cc,
in function write_delayed().

In 5.6, the code is instrumented as follows:

[1]  THD_STAGE_INFO(thd, stage_waiting_for_handler_insert);
     mysql_mutex_lock(&di->mutex);
     while (di->stacked_inserts >= delayed_queue_size && !thd->killed)
[2]    mysql_cond_wait(&di->cond_client, &di->mutex);
[3]  THD_STAGE_INFO(thd, stage_storing_row_into_queue);

[1] is a stage instrumentation, visible in the performance schema as:

mysql> select * from setup_instruments where name like "%waiting for handler
insert%";
+--------------------------------------+---------+-------+
| NAME                                 | ENABLED | TIMED |
+--------------------------------------+---------+-------+
| stage/sql/waiting for handler insert | YES     | YES   |
+--------------------------------------+---------+-------+
1 row in set (0.00 sec)

[2] is an instrumented condition, visible in the performance schema as:

mysql> select * from setup_instruments where name like
"%Delayed_insert::cond_client%";
+-------------------------------------------------+---------+-------+
| NAME                                            | ENABLED | TIMED |
+-------------------------------------------------+---------+-------+
| wait/synch/cond/sql/Delayed_insert::cond_client | YES     | YES   |
+-------------------------------------------------+---------+-------+
1 row in set (0.00 sec)

[3] is a stage instrumentation, visible in the performance schema as:

mysql> select * from setup_instruments where name like "%storing row%";
+----------------------------------+---------+-------+
| NAME                             | ENABLED | TIMED |
+----------------------------------+---------+-------+
| stage/sql/storing row into queue | YES     | YES   |
+----------------------------------+---------+-------+
1 row in set (0.01 sec)

Entering stage [3] marks the end of stage [1].

As a result, the time spent attempting to insert a request in the delayed
insert queue is counted both:
- as a dedicated "stage/sql/waiting for handler insert" stage, which covers
this very operation,
- as waits on the underlying condition,
"wait/synch/cond/sql/Delayed_insert::cond_client",
  which covers every wait in more details.

Note that the stages [1] and [3] are available starting with 5.6 only,
but the condition instrumentation [2] is available in 5.5 already.

The proposed fix in the feature requested was to:
"report in a status VARIABLE how often the delayed insert thread has to wait
for the delayed insert queue to be emptied.".

"How often the thread has to wait" corresponds to a count of how many times
the code loops, but does not measure how much time is spent waiting.
Also, this metric does not distinguish between 5 delayed inserts waiting 2
times each, and 1 delayed insert waiting 10 times.

The performance schema actually can report both:
@ - the number of times the code has to wait (columns COUNT_STAR in the
performance schema tables),
- the total time spent waiting (columns SUM_TIMER_WAIT in the performance
schema tables).

With the stages instrumentation, the performance schema can report:
- how many times the stage was executed (5 times or 1 time in the example
above),
- how much time is spent on this stage, with min(timer_wait) /
avg(timer_wait) / max(timer_wait) statistics.
and much more aggregations derived from the instrumentation.