Bug #74007 Problem with general_log_file when I use fifo file
Submitted: 22 Sep 2014 9:28 Modified: 6 Oct 2014 11:18
Reporter: Area sistemi Ripartizione Informatica Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Logging Severity:S3 (Non-critical)
Version:5.5.37 OS:Linux (Red Hat Enterprise Linux Server release 6.5 with software collections)
Assigned to: CPU Architecture:Any

[22 Sep 2014 9:28] Area sistemi Ripartizione Informatica
Description:
I have a problem with mysql 5.5.37 general log configuration, after setting my.cnf file in this mode: 

general_log=1 
general_log_file=/var/lib/mysql/mysql_access.fifo 

where mysql_access.fifo is a fifo file.

This file is read and filtered (Connect|Quit), then redirected to logger for having an access log file. 

No problems with mysql 5.1.73 but with 5.5.37 version when i stopped the service this crashing and restarting:

140919 10:59:05 [Note] /opt/rh/mysql55/root/usr/libexec/mysqld: Normal shutdown

140919 10:59:05 [Note] Event Scheduler: Purging the queue. 0 events
140919 10:59:05 [ERROR] /opt/rh/mysql55/root/usr/libexec/mysqld: Can't sync file '/opt/rh/mysql55/root/var/lib/mysql/mysql.fifo' to disk (Errcode: 22)
08:59:05 UTC - mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 338508 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0 thread_stack 0x40000
/opt/rh/mysql55/root/usr/libexec/mysqld(my_print_stacktrace+0x2e)[0x7f676a1d594e]
/opt/rh/mysql55/root/usr/libexec/mysqld(handle_fatal_signal+0x493)[0x7f676a0be6a3]
/lib64/libpthread.so.0(+0x327de0f710)[0x7f67698ac710]
/opt/rh/mysql55/root/usr/libexec/mysqld(_ZN9MYSQL_LOG5closeEj+0x1f6)[0x7f676a1476c6]
/opt/rh/mysql55/root/usr/libexec/mysqld(_ZN25Log_to_file_event_handler7cleanupEv+0xd)[0x7f676a147c5d]
/opt/rh/mysql55/root/usr/libexec/mysqld(+0x2857b9)[0x7f6769f617b9]
/opt/rh/mysql55/root/usr/libexec/mysqld(_Z10unireg_endv+0xe)[0x7f6769f61b0e]
/opt/rh/mysql55/root/usr/libexec/mysqld(+0x2875d9)[0x7f6769f635d9]
/opt/rh/mysql55/root/usr/libexec/mysqld(kill_server_thread+0xe)[0x7f6769f6369e]
/lib64/libpthread.so.0(+0x327de079d1)[0x7f67698a49d1]
/lib64/libc.so.6(clone+0x6d)[0x7f6767dabb5d]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
140919 10:59:05 mysqld_safe Number of processes running now: 0
140919 10:59:05 mysqld_safe mysqld restarted
140919 10:59:06 [Note] Plugin 'FEDERATED' is disabled.
140919 10:59:06 InnoDB: The InnoDB memory heap is disabled
140919 10:59:06 InnoDB: Mutexes and rw_locks use GCC atomic builtins
140919 10:59:06 InnoDB: Compressed tables use zlib 1.2.3
140919 10:59:06 InnoDB: Using Linux native AIO
140919 10:59:06 InnoDB: Initializing buffer pool, size = 128.0M
140919 10:59:06 InnoDB: Completed initialization of buffer pool
140919 10:59:06 InnoDB: highest supported file format is Barracuda.
140919 10:59:06  InnoDB: Waiting for the background threads to start
140919 10:59:07 InnoDB: 5.5.37 started; log sequence number 1595685
/opt/rh/mysql55/root/usr/libexec/mysqld: Can't seek in file '/opt/rh/mysql55/root/var/lib/mysql/mysql.fifo' (Errcode: 29)
140919 10:59:07 [Note] Server hostname (bind-address): '141.250.199.6'; port: 3306
140919 10:59:07 [Note]   - '141.250.199.6' resolves to '141.250.199.6';
140919 10:59:07 [Note] Server socket created on IP: '141.250.199.6'.
140919 10:59:07 [Note] Event Scheduler: Loaded 0 events
140919 10:59:07 [Note] /opt/rh/mysql55/root/usr/libexec/mysqld: ready for connections.
Version: '5.5.37-log'  socket: '/opt/rh/mysql55/root/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server (GPL) 

I use this configuration because  I haven't found alternative for recording only access from users.

Best regards
Federico Ragni

How to repeat:
1) Mysql stopped
2) Configure my.cnf with general_log=1 and general_log_file=/var/lib/mysql/mysql_access.fifo
3) Use tail -f  /var/lib/mysql/mysql_access.fifo for read the output of pipe
4) Start the service
5) Stop the service

I found the same result with mysqladmin -u root -p shutdown
[22 Sep 2014 20:47] MySQL Verification Team
See this: https://bugs.mysql.com/bug.php?id=59847
[23 Sep 2014 10:32] Area sistemi Ripartizione Informatica
Dear support,

this isn't a duplicate bug, because I receive the same error message of Bug #59847 in version 5.1, but when I stop the service this shut down correctly.
When I stop the 5.5 version it crashes and restarts.

Best Regards
Federico Ragni
[6 Oct 2014 11:18] Area sistemi Ripartizione Informatica
Duplicate:
http://bugs.mysql.com/bug.php?id=67088

this bug will be fixed with MySQL 5.5.40 release:
http://dev.mysql.com/doc/relnotes/mysql/5.5/en/news-5-5-40.html

I have temporarily worked around the problem by disabling general_log (set global general_log = 0) before stopping.

Federico Ragni