[debian-mysql] Bug#516795: Bug#516795: mysql-server-5.1: error logging goes to /var/lib/{hostname}.err

Olivier Bonvalet ob.reportbug at daevel.fr
Tue Apr 28 20:49:50 UTC 2009


Hi,

I rechecked on a fresh Debian Lenny (amd64) installation, directly with 
the 5.1.34-1 package from experimental (thought apt-pinning).

In fact there is some error logging in syslog and some in 
/var/lib/mysql/{hostname}.err.


Logging start in syslog (this is the first MySQL launch, thout "aptitude 
install") :

root! slave:/var/lib/mysql# grep -i mysql /var/log/syslog
Apr 28 22:25:57 slave mysqld_safe[17661]: 090428 22:25:57 [Warning] 
Forcing shutdown of 2 plugins
Apr 28 22:25:57 slave mysqld_safe[17661]: 090428 22:25:57 [Warning] 
Forcing shutdown of 2 plugins
Apr 28 22:25:57 slave mysqld_safe[17661]:
Apr 28 22:25:57 slave mysqld_safe[17661]: PLEASE REMEMBER TO SET A 
PASSWORD FOR THE MySQL root USER !
Apr 28 22:25:57 slave mysqld_safe[17661]: To do so, start the server, 
then issue the following commands:
Apr 28 22:25:57 slave mysqld_safe[17661]:
Apr 28 22:25:57 slave mysqld_safe[17661]: /usr/bin/mysqladmin -u root 
password 'new-password'
Apr 28 22:25:57 slave mysqld_safe[17661]: /usr/bin/mysqladmin -u root -h 
slave password 'new-password'
Apr 28 22:25:57 slave mysqld_safe[17661]:
Apr 28 22:25:57 slave mysqld_safe[17661]: Alternatively you can run:
Apr 28 22:25:57 slave mysqld_safe[17661]: /usr/bin/mysql_secure_installation
Apr 28 22:25:57 slave mysqld_safe[17661]:
Apr 28 22:25:57 slave mysqld_safe[17661]: which will also give you the 
option of removing the test
Apr 28 22:25:57 slave mysqld_safe[17661]: databases and anonymous user 
created by default.  This is
Apr 28 22:25:57 slave mysqld_safe[17661]: strongly recommended for 
production servers.
Apr 28 22:25:57 slave mysqld_safe[17661]:
Apr 28 22:25:57 slave mysqld_safe[17661]: See the manual for more 
instructions.
Apr 28 22:25:57 slave mysqld_safe[17661]:
Apr 28 22:25:57 slave mysqld_safe[17661]: Please report any problems 
with the /usr/scripts/mysqlbug script!
Apr 28 22:25:57 slave mysqld_safe[17661]:
Apr 28 22:25:57 slave mysqld_safe[17661]: The latest information about 
MySQL is available at http://www.mysql.com/
Apr 28 22:25:57 slave mysqld_safe[17661]: Support MySQL by buying 
support/licenses from http://shop.mysql.com/
Apr 28 22:25:57 slave mysqld_safe[17661]:
Apr 28 22:25:57 slave mysqld_safe[17706]: InnoDB: The first specified 
data file ./ibdata1 did not exist:
Apr 28 22:25:57 slave mysqld_safe[17706]: InnoDB: a new database to be 
created!
Apr 28 22:25:57 slave mysqld_safe[17706]: 090428 22:25:57  InnoDB: 
Setting file ./ibdata1 size to 10 MB
Apr 28 22:25:57 slave mysqld_safe[17706]: InnoDB: Database physically 
writes the file full: wait...
Apr 28 22:25:58 slave mysqld_safe[17706]: 090428 22:25:58  InnoDB: Log 
file ./ib_logfile0 did not exist: new to be created
Apr 28 22:25:58 slave mysqld_safe[17706]: InnoDB: Setting log file 
./ib_logfile0 size to 5 MB
Apr 28 22:25:58 slave mysqld_safe[17706]: InnoDB: Database physically 
writes the file full: wait...
Apr 28 22:25:58 slave mysqld_safe[17706]: 090428 22:25:58  InnoDB: Log 
file ./ib_logfile1 did not exist: new to be created
Apr 28 22:25:58 slave mysqld_safe[17706]: InnoDB: Setting log file 
./ib_logfile1 size to 5 MB
Apr 28 22:25:58 slave mysqld_safe[17706]: InnoDB: Database physically 
writes the file full: wait...
Apr 28 22:25:58 slave mysqld_safe[17706]: InnoDB: Doublewrite buffer not 
found: creating new
Apr 28 22:25:58 slave mysqld_safe[17706]: InnoDB: Doublewrite buffer created
Apr 28 22:25:58 slave mysqld_safe[17706]: InnoDB: Creating foreign key 
constraint system tables
Apr 28 22:25:58 slave mysqld_safe[17706]: InnoDB: Foreign key constraint 
system tables created
Apr 28 22:25:58 slave mysqld_safe[17706]: 090428 22:25:58  InnoDB: 
Started; log sequence number 0 0
Apr 28 22:25:58 slave mysqld_safe[17706]: 090428 22:25:58  InnoDB: 
Starting shutdown...
Apr 28 22:25:59 slave mysqld_safe[17706]: 090428 22:25:59  InnoDB: 
Shutdown completed; log sequence number 0 46409
Apr 28 22:25:59 slave mysqld_safe[17706]: 090428 22:25:59 [Warning] 
Forcing shutdown of 1 plugins
Apr 28 22:25:59 slave mysqld_safe[17723]: 090428 22:25:59  InnoDB: 
Started; log sequence number 0 46409
Apr 28 22:25:59 slave mysqld_safe[17723]: ERROR: 1064  You have an error 
in your SQL syntax; check the manual that corresponds to your MySQL 
server version for the right syntax to use near 'ALTER TABLE user ADD 
column Show_view_priv enum('N','Y') CHARACTER SET utf8 NOT ' at line 1
Apr 28 22:25:59 slave mysqld_safe[17723]: 090428 22:25:59 [ERROR] Aborting
Apr 28 22:25:59 slave mysqld_safe[17723]:
Apr 28 22:25:59 slave mysqld_safe[17723]: 090428 22:25:59  InnoDB: 
Starting shutdown...
Apr 28 22:26:01 slave mysqld_safe[17723]: 090428 22:26:01  InnoDB: 
Shutdown completed; log sequence number 0 46409
Apr 28 22:26:01 slave mysqld_safe[17723]: 090428 22:26:01 [Warning] 
Forcing shutdown of 1 plugins
Apr 28 22:26:01 slave mysqld_safe[17723]: 090428 22:26:01 [Note] 
/usr/sbin/mysqld: Shutdown complete
Apr 28 22:26:01 slave mysqld_safe[17723]:
Apr 28 22:26:01 slave mysqld_safe[17737]: 090428 22:26:01  InnoDB: 
Started; log sequence number 0 46409
Apr 28 22:26:01 slave mysqld_safe[17737]: ERROR: 1064  You have an error 
in your SQL syntax; check the manual that corresponds to your MySQL 
server version for the right syntax to use near 'Create_user_priv='Y', 
Event_priv='Y', Trigger_priv='Y'' at line 1
Apr 28 22:26:01 slave mysqld_safe[17737]: 090428 22:26:01 [ERROR] Aborting
Apr 28 22:26:01 slave mysqld_safe[17737]:
Apr 28 22:26:01 slave mysqld_safe[17737]: 090428 22:26:01  InnoDB: 
Starting shutdown...
Apr 28 22:26:02 slave mysqld_safe[17737]: 090428 22:26:02  InnoDB: 
Shutdown completed; log sequence number 0 46409
Apr 28 22:26:02 slave mysqld_safe[17737]: 090428 22:26:02 [Warning] 
Forcing shutdown of 1 plugins
Apr 28 22:26:02 slave mysqld_safe[17737]: 090428 22:26:02 [Note] 
/usr/sbin/mysqld: Shutdown complete
Apr 28 22:26:02 slave mysqld_safe[17737]:
Apr 28 22:26:02 slave mysqld_safe[17751]: 090428 22:26:02  InnoDB: 
Started; log sequence number 0 46409
Apr 28 22:26:02 slave mysqld_safe[17751]: ERROR: 1050  Table 'plugin' 
already exists
Apr 28 22:26:02 slave mysqld_safe[17751]: 090428 22:26:02 [ERROR] Aborting
Apr 28 22:26:02 slave mysqld_safe[17751]:
Apr 28 22:26:02 slave mysqld_safe[17751]: 090428 22:26:02  InnoDB: 
Starting shutdown...
Apr 28 22:26:03 slave mysqld_safe[17751]: 090428 22:26:03  InnoDB: 
Shutdown completed; log sequence number 0 46409
Apr 28 22:26:03 slave mysqld_safe[17751]: 090428 22:26:03 [Warning] 
Forcing shutdown of 1 plugins
Apr 28 22:26:03 slave mysqld_safe[17751]: 090428 22:26:03 [Note] 
/usr/sbin/mysqld: Shutdown complete
Apr 28 22:26:03 slave mysqld_safe[17751]:
Apr 28 22:26:04 slave /etc/mysql/debian-start[17972]: Upgrading MySQL 
tables if necessary.
Apr 28 22:26:04 slave /etc/mysql/debian-start[17975]: Looking for 
'mysql' as: /usr/bin/mysql
Apr 28 22:26:04 slave /etc/mysql/debian-start[17975]: Looking for 
'mysqlcheck' as: /usr/bin/mysqlcheck
Apr 28 22:26:04 slave /etc/mysql/debian-start[17975]: Running 
'mysqlcheck'...
Apr 28 22:26:04 slave /etc/mysql/debian-start[17975]: 
/usr/bin/mysqlcheck: Got error: 1045: Access denied for user 
'debian-sys-maint'@'localhost' (using password: YES) when trying to connect
Apr 28 22:26:04 slave /etc/mysql/debian-start[17975]: FATAL ERROR: 
Upgrade failed
Apr 28 22:26:04 slave /etc/mysql/debian-start[17983]: Checking for 
insecure root accounts.

================================================================================================

And I also have this : ({hostname}.err-old)

root! slave:/var/lib/mysql# cat slave.err-old
090428 22:26:03 mysqld_safe Starting mysqld daemon with databases from 
/var/lib/mysql
090428 22:26:03  InnoDB: Started; log sequence number 0 46409
090428 22:26:03 [Note] Event Scheduler: Loaded 0 events
090428 22:26:03 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.1.34-1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  
(Debian)

Status information:

Current dir: /var/lib/mysql/
Running threads: 0  Stack size: 131072
Current locks:
lock: 0x26555d8:

lock: 0x264a5c8:

lock: 0x263fa18:

lock: 0x2633158:

lock: 0x262c4a8:

lock: 0x261d678:

lock: 0x26177a8:

lock: 0x260faf8:


Key caches:
default
Buffer_size:      16777216
Block_size:           1024
Division_limit:        100
Age_limit:             300
blocks used:             0
not flushed:             0
w_requests:              0
writes:                  0
r_requests:              0
reads:                   0


handler status:
read_key:            0
read_next:           0
read_rnd             0
read_first:          3
write:               0
delete               0
update:              0

Table status:
Opened tables:         15
Open tables:            8
Open files:            16
Open streams:           0

Alarm status:
Active alarms:   0
Max used alarms: 1
Next alarm time: 0

Begin safemalloc memory dump:

End safemalloc memory dump.

Memory status:
Non-mmapped space allocated from system: 6606848
Number of free chunks:             20
Number of fastbin blocks:         0
Number of mmapped regions:         12
Space in mmapped regions:         48758784
Maximum total allocated space:         0
Space available in freed fastbin blocks: 0
Total allocated space:             6518896
Total free space:             87952
Top-most, releasable space:         65920
Estimated memory (with thread stack):    55365632



Events status:
LLA = Last Locked At  LUA = Last Unlocked At
WOC = Waiting On Condition  DL = Data Locked

Event scheduler status:
State      : INITIALIZED
Thread id  : 0
LLA        : n/a:0
LUA        : n/a:0
WOC        : NO
Workers    : 0
Executed   : 0
Data locked: NO

Event queue status:
Element count   : 0
Data locked     : NO
Attempting lock : NO
LLA             : init_queue:132
LUA             : init_queue:142
WOC             : NO
Next activation : never


================================================================================================

And now I have this : ({hostname}.err)

root! slave:/var/lib/mysql# cat slave.err
090428 22:27:45 [Note] /usr/sbin/mysqld: Normal shutdown

090428 22:27:45 [Note] Event Scheduler: Purging the queue. 0 events
090428 22:27:45  InnoDB: Starting shutdown...
090428 22:27:46  InnoDB: Shutdown completed; log sequence number 0 46409
090428 22:27:46 [Warning] Forcing shutdown of 1 plugins
090428 22:27:46 [Note] /usr/sbin/mysqld: Shutdown complete

090428 22:27:46 mysqld_safe mysqld from pid file 
/var/run/mysqld/mysqld.pid ended
090428 22:27:55 mysqld_safe Starting mysqld daemon with databases from 
/var/lib/mysql
090428 22:27:55  InnoDB: Started; log sequence number 0 46409
090428 22:27:55 [Note] Event Scheduler: Loaded 0 events
090428 22:27:55 [Note] /usr/sbin/mysqld: ready for connections.

Olivier

Note : so there is some SQL errors in logs during installation, and the 
"debian-sys-maint" account was not created. Also, no file was created in 
/etc/mysql/conf.d/ to disable "old_passwords". But I should maybe open 
an other bug report ?





More information about the pkg-mysql-maint mailing list