Bug #69785 WB sends unnecessary COM_PING operations
Submitted: 18 Jul 2013 22:04 Modified: 19 Nov 2014 18:07
Reporter: Todd Farmer (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:Connector / C++ Severity:S3 (Non-critical)
Version:6.0.3 OS:Any
Assigned to: CPU Architecture:Any

[18 Jul 2013 22:04] Todd Farmer
Description:
 <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:21" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW FULL TABLES FROM `performance_schema`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:21" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW PROCEDURE STATUS WHERE Db='performance_schema'"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:21" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW FUNCTION STATUS WHERE Db='performance_schema'"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:23" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:23" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`accounts`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:23" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:23" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`cond_instances`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:23" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:23" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_stages_current`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:24" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:24" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_stages_history`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:24" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:24" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_stages_history_long`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:24" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:24" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_stages_summary_by_account_by_event_name`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:25" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:25" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_stages_summary_by_host_by_event_name`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:25" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:25" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_stages_summary_by_thread_by_event_name`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:25" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:25" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_stages_summary_by_user_by_event_name`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:25" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:25" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_stages_summary_global_by_event_name`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:26" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
WB needlessly pings the connection between internal queries.  The below is a partial capture of what happens when I expand the schema navigator on performance_schema database:

  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:26" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_statements_current`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:27" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:27" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_statements_history`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:28" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:28" NAME="Query" CONNECTION_ID="2" STATUS="0" SQLTEXT="SHOW COLUMNS FROM `performance_schema`.`events_statements_history_long`"/>
  <AUDIT_RECORD TIMESTAMP="2013-07-18T22:00:29" NAME="Ping" CONNECTION_ID="2" STATUS="0"/>

How to repeat:
Turn audit logging on.
Expand a database in the schema navigator.
Observe COM_PING operations in audit log.

Suggested fix:
Suppress COM_PING when connection is being used for sequential operations.  Perhaps ensure COM_PING is called no more frequently than once every 10s.
[18 Jul 2013 22:05] Todd Farmer
Somehow, I jumbled the initial description.  Extracting the comment for easy reference:

"WB needlessly pings the connection between internal queries.  The below is a partial capture of what happens when I expand the schema navigator on performance_schema database:"
[19 Nov 2014 12:48] Hemant Dangi
Posted by developer:
 
isClosed() (according to JDBC doc) should not ping() to check connection is active.
[19 Nov 2014 12:51] Hemant Dangi
Posted by developer:
 
isClosed() (according to JDBC doc) should not ping() to check connection is active.
[19 Nov 2014 18:07] Paul DuBois
Noted in Connector/C++ 1.1.5 changelog.

Connector/C++ issued a ping command every time isClosed() was called
in a Connection, rather than just checking whether close() had been
called earlier or when a fatal error occurred in an earlier
operation.