Debugging and Tracing

The mysqlnd debug log can be used to debug and trace the actitivities of PECL/mysqlnd_ms. As a mysqlnd PECL/mysqlnd_ms adds trace information to the mysqlnd library debug file. Please, see the mysqlnd.debug PHP configuration directive documentation for a detailed description on how to configure the debug log.

Configuration setting example to activate the debug log:

mysqlnd.debug=d:t:x:O,/tmp/mysqlnd.trace

Note:

This feature is only available with a debug build of PHP. Works on Microsoft Windows if using a debug build of PHP and PHP was built using Microsoft Visual C version 9 and above.

The debug log shows mysqlnd library and PECL/mysqlnd_ms plugin function calls, similar to a trace log. Mysqlnd library calls are usually prefixed with mysqlnd_. PECL/mysqlnd internal calls begin with mysqlnd_ms.

Example excerpt from the debug log (connect):

[...]
>mysqlnd_connect
| info : host=myapp user=root db=test port=3306 flags=131072
| >mysqlnd_ms::connect
| | >mysqlnd_ms_config_json_section_exists
| | | info : section=[myapp] len=[5]
| | | >mysqlnd_ms_config_json_sub_section_exists
| | | | info : section=[myapp] len=[5]
| | | | info : ret=1
| | | <mysqlnd_ms_config_json_sub_section_exists
| | | info : ret=1
| | <mysqlnd_ms_config_json_section_exists
[...]

The debug log is not only useful for plugin developers but also to find the cause of user errors. For example, if your application does not do proper error handling and fails to record error messages, checking the debug and trace log may help finding the cause. Use of the debug log to debug application issues should be considered only if no other option is available. Writing the debug log to disk is a slow operation and may have negative impact on the application performance.

Example excerpt from the debug log (connection failure):

[...]
| | | | | | | info : adding error [Access denied for user 'root'@'localhost' (using password: YES)] to the list
| | | | | | | info : PACKET_FREE(0)
| | | | | | | info : PACKET_FREE(0x7f3ef6323f50)
| | | | | | | info : PACKET_FREE(0x7f3ef6324080)
| | | | | | <mysqlnd_auth_handshake
| | | | | | info : switch_to_auth_protocol=n/a
| | | | | | info : conn->error_info.error_no = 1045
| | | | | <mysqlnd_connect_run_authentication
| | | | | info : PACKET_FREE(0x7f3ef63236d8)
| | | | | >mysqlnd_conn::free_contents
| | | | | | >mysqlnd_net::free_contents
| | | | | | <mysqlnd_net::free_contents
| | | | | | info : Freeing memory of members
| | | | | | info : scheme=unix:///tmp/mysql.sock
| | | | | | >mysqlnd_error_list_pdtor
| | | | | | <mysqlnd_error_list_pdtor
| | | | | <mysqlnd_conn::free_contents
| | | | <mysqlnd_conn::connect
[...]

The trace log can also be used to verify correct behaviour of PECL/mysqlnd_ms itself, for example, to check which server has been selected for query execution and why.

Example excerpt from the debug log (plugin decision):

[...]
>mysqlnd_ms::query
| info : query=DROP TABLE IF EXISTS test
| >_mysqlnd_plugin_get_plugin_connection_data
| | info : plugin_id=5
| <_mysqlnd_plugin_get_plugin_connection_data
| >mysqlnd_ms_pick_server_ex
| | info : conn_data=0x7fb6a7d3e5a0 *conn_data=0x7fb6a7d410d0
| | >mysqlnd_ms_select_servers_all
| | <mysqlnd_ms_select_servers_all
| | >mysqlnd_ms_choose_connection_rr
| | | >mysqlnd_ms_query_is_select
[...]
| | | <mysqlnd_ms_query_is_select
[...]
| | | info : Init the master context
| | | info : list(0x7fb6a7d3f598) has 1
| | | info : Using master connection
| | | >mysqlnd_ms_advanced_connect
| | | | >mysqlnd_conn::connect
| | | | | info : host=localhost user=root db=test port=3306 flags=131072 persistent=0 state=0

In this case the statement DROP TABLE IF EXISTS test has been executed. Note that the statement string is shown in the log file. You may want to take measures to restrict access to the log for security considerations.

The statement has been load balanced using round robin policy, as you can easily guess from the functions name >mysqlnd_ms_choose_connection_rr. It has been sent to a master server running on host=localhost user=root db=test port=3306 flags=131072 persistent=0 state=0.