Bug #77456 Command line client "mysql" lacks command logging in batch mode
Submitted: 23 Jun 2015 14:45 Modified: 17 Jul 2015 11:38
Reporter: Jörg Brühe (OCA) Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server: Command-line Clients Severity:S4 (Feature request)
Version:5.5.29 and up, 5.6.24 and up OS:Any
Assigned to: Georgi Kodinov CPU Architecture:Any
Tags: batch, client, log

[23 Jun 2015 14:45] Jörg Brühe
Description:
I'm trying to reproduce a customer problem.
For this, I'm writing a file containing SQL commands which I will pass to the "mysql" client, either as standard input (redirection) or using the "source" command.

I want to get a log, listing the command, its result, and the error/warning/timing information, like I have on the screen when using "mysql" interactively.
However, in batch mode (including the "-e" parameter) the program will only produce the results, not the other parts of a log.

The only way which I found is to use "-v" ("--verbose"), but its formatting is not helpful because of blank lines in the wrong place (see in "How to repeat").

I also tried "--debug", this triggered my report of bug#77455.

Some people might propose I should use "mysqltest" - no, that is no solution:
1) It is designed to run complete test cases with individual protocol files, I need to combine SQL snippets with other commands in-between.
2) It is not part of a standard installation.
3) It has too much built-in special handling.
4) It is not known to the average MySQL user.

How to repeat:
mysql@support:~ [mysqld-5529, 3329]> echo "show global variables like 'version%' " | mysql -u root --table
+-------------------------+------------------------------+
| Variable_name           | Value                        |
+-------------------------+------------------------------+
| version                 | 5.5.29-log                   |
| version_comment         | MySQL Community Server (GPL) |
| version_compile_machine | x86_64                       |
| version_compile_os      | linux2.6                     |
+-------------------------+------------------------------+
mysql@support:~ [mysqld-5529, 3329]> echo "show global variables like 'version%' " > /tmp/t1
mysql@support:~ [mysqld-5529, 3329]> mysql -u root --table < /tmp/t1
+-------------------------+------------------------------+
| Variable_name           | Value                        |
+-------------------------+------------------------------+
| version                 | 5.5.29-log                   |
| version_comment         | MySQL Community Server (GPL) |
| version_compile_machine | x86_64                       |
| version_compile_os      | linux2.6                     |
+-------------------------+------------------------------+
mysql@support:~ [mysqld-5529, 3329]> mysql -u root
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 8
Server version: 5.5.29-log MySQL Community Server (GPL)

Copyright (c) 2000, 2012, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

root@localhost mysqld-5529 [(none)] SQL> source /tmp/t1
+-------------------------+------------------------------+
| Variable_name           | Value                        |
+-------------------------+------------------------------+
| version                 | 5.5.29-log                   |
| version_comment         | MySQL Community Server (GPL) |
| version_compile_machine | x86_64                       |
| version_compile_os      | linux2.6                     |
+-------------------------+------------------------------+
4 rows in set (0.00 sec)

root@localhost mysqld-5529 [(none)] SQL> Bye
mysql@support:~ [mysqld-5529, 3329]> 

Note that "source" will display the row count and time, the other ways don't.
See below why "--verbose" is not really helpful:

mysql@support:~ [mysqld-5529, 3329]> cat /tmp/t2
show global variables like 'version%' ;
show databases;
mysql@support:~ [mysqld-5529, 3329]> mysql -u root --table --verbose < /tmp/t2
--------------
show global variables like 'version%'
--------------

+-------------------------+------------------------------+
| Variable_name           | Value                        |
+-------------------------+------------------------------+
| version                 | 5.5.29-log                   |
| version_comment         | MySQL Community Server (GPL) |
| version_compile_machine | x86_64                       |
| version_compile_os      | linux2.6                     |
+-------------------------+------------------------------+
--------------
show databases
--------------

+--------------------+
| Database           |
+--------------------+
| information_schema |
| mysql              |
| performance_schema |
| test               |
+--------------------+
mysql@support:~ [mysqld-5529, 3329]>

Note:
1) The semicolon is not logged.
2) There is a blank line between command and result, but none between result and next command.

Suggested fix:
I would like to see an option "--log-commands" (or similar) that makes "mysql" produce the same output in batch mode like it does in interactive mode:
- the statement text, including the terminator (';' or '\G'),
- the result (like now),
- the info on errors, warning, row count, and timing,
- no unmotivated separator lines (like "--verbose" does).

The option should have the same effect on statements read via "source" during an interactive run.

It might be good to also log a marker for the end of a "source" file.
[3 Jul 2015 15:51] Jörg Brühe
I just noticed that "mysql --verbose" will *not* log a "use" statement.

Given the importance which "use" has on logging and replication (I am researching effects of "replicate-*" options), I consider this a severe defect.
[17 Jul 2015 11:38] Georgi Kodinov
Thank you for your feature request. 

BTW, --verbose can be specified multiple times according to http://dev.mysql.com/doc/refman/5.7/en/mysql-command-options.html#option_mysql_verbose.

See what I get when I do it:

d:\ade\git\mysql-5.7\bld\mysql-test>..\client\Debug\mysql.exe --verbose -u root -p --port=13000 < gogo.sql
Enter password:
--------------
SELECT 1 FROM DUAL
--------------

1
1

d:\ade\git\mysql-5.7\bld\mysql-test>..\client\Debug\mysql.exe --verbose --verbose -u root -p --port=13000 < gogo.sql
Enter password:
--------------
SELECT 1 FROM DUAL
--------------

1
1
1 row in set

Bye

d:\ade\git\mysql-5.7\bld\mysql-test>..\client\Debug\mysql.exe --verbose --verbose --verbose -u root -p --port=13000 < gogo.sql
Enter password:
--------------
SELECT 1 FROM DUAL
--------------

+---+
| 1 |
+---+
| 1 |
+---+
1 row in set (0.00 sec)

Bye

So basically this feature request boils down to different formatting of the command printout and adding a semicolon at the end of it.
I believe the current difference in formatting is a feature in itself, as it does visualize the mode used to execute the statements (and thus adds extra information to bug reports).
Feel free to re-open the bug please if you can think of some usage scenarios I may be missing.