| Bug #103616 | Audit log may record set statements that were not executed | ||
|---|---|---|---|
| Submitted: | 7 May 2021 5:57 | Modified: | 10 May 2021 8:02 |
| Reporter: | Xiaodong Huang (OCA) | Email Updates: | |
| Status: | Not a Bug | Impact on me: | |
| Category: | MySQL Server: Security: Audit | Severity: | S3 (Non-critical) |
| Version: | 8.0.24 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[7 May 2021 13:54]
MySQL Verification Team
Hello Xiaodong, Thank you for the report and feedback. regards, Umesh
[10 May 2021 8:02]
MySQL Verification Team
Hello Xiaodong, Our internal discussion concluded that this is an expected and documented behavior of audit log. Audit log will have record of all the executed SQL statements(STATUS will indicate i.e An unsigned integer representing the command status: 0 for success, nonzero if an error occurred) - more details at https://dev.mysql.com/doc/refman/8.0/en/audit-log-file-formats.html regards, Umesh
[10 May 2021 9:11]
Georgi Kodinov
One comment I'd like to add too: Most of the audit API events should be used for "pre-filtering" and only some of them (e.g. MYSQL_AUDIT_QUERY_STATUS_END) should be used for actual logging. It's all about the time when the event is generated. This particular event (MYSQL_AUDIT_GLOBAL_VARIABLE_SET) is generated at a time when the execution of the statement can easily be interrupted. It's not to signify that the event has actually been put into effect.

Description: When execute set statement "SET GLOBAL max_connections = 1000, sort_buffer_size = abc;" , because the "sort_buffer_size = abc" check error here, the statement will not executed. But the "max_connections = 1000" will be recorded in audit log. This is mainly because as long as the variable check is successful, it will be recorded in the audit log in the set_var::check. The detail code is as below. 1076 int set_var::check(THD *thd) { 1077 DBUG_TRACE; 1078 DEBUG_SYNC(current_thd, "after_error_checking"); 1079 1080 if (var == nullptr) { 1081 var = var_tracker.bind_system_variable(thd); 1082 } else { 1083 // No need to rebind: called from sql_set_variables(). 1084 } 1085 if (var == nullptr) { 1086 return -1; 1087 } 1088 1089 /* value is a NULL pointer if we are using SET ... = DEFAULT */ 1090 if (!value) return 0; 1091 1092 if (var->check_update_type(value->result_type())) { 1093 my_error(ER_WRONG_TYPE_FOR_VAR, MYF(0), var->name.str); 1094 return -1; 1095 } 1096 int ret = (type != OPT_PERSIST_ONLY && var->check(thd, this)) ? -1 : 0; 1097 1098 if (!ret && (is_global_persist())) { 1099 ret = mysql_audit_notify(thd, AUDIT_EVENT(MYSQL_AUDIT_GLOBAL_VARIABLE_SET), 1100 var->name.str, value->item_name.ptr(), 1101 value->item_name.length()); 1102 } 1103 1104 return ret; 1105 } When we execute the "SET GLOBAL max_connections = 1000, sort_buffer_size = abc;", the implementation process is consist of two phase.First phase, check whether "max_connections = 1000" and sort_buffer_size = abc are both valid. if both are valid , execute second phase , otherwise return error. Second phase, update the max_connections and sort_buffer_size. Here "max_connections = 1000" is vaild but "sort_buffer_size = abc" is invalid, so the set statement is not executed. The checking action is judged by the set_var::check. Then the log entry which content is "max_connections = 1000" is recorded in audit log but the "max_connections = 1000" isn't executed How to repeat: 1. Open audit log; 2. Execute "SET GLOBAL max_connections = 1000, sort_buffer_size = abc;"; 3. The statement return error, but the audit log occur "max_connections = 1000"; Suggested fix: It is suggested to record the audit log after all variables have passed the checking.