logger won't start: /opt/zimbra/bin/zmlogswatchctl: line 69: kill: (5491) - No such

[oopstu]

Hi,

I've been using M3 on Fedora Core3 and have been really happy. This weekend I upgraded to 3.0.1 but ran into a couple of snags. The biggest one is that the logger wouldn't, and still won't start.

In order to get zimbra working after the upgrade I had to follow the instructions: here: Mailbox Stopped
to reset my mysql passwords and that worked great.

Now by running the various *ctl commands and statusing them I was able to get everything up except for the logger.

When I run 'sh -x bin/zmloggerctl status' i get:

+ BASE=/opt/zimbra
+ SCRIPTS='logmysql.server zmlogswatchctl'
+ case "$1" in
+ STATUS=0
+ for i in '$SCRIPTS'
+ '[' logmysql.server = logmysql.server ']'
+ /opt/zimbra/bin/logmysqladmin status
+ R=1
+ '[' 1 -ne 0 ']'
+ STATUS=1
+ for i in '$SCRIPTS'
+ '[' zmlogswatchctl = logmysql.server ']'
+ /opt/zimbra/bin/zmlogswatchctl status
/opt/zimbra/bin/zmlogswatchctl: line 69: kill: (5491) - No such process

Then, running the logswatch directly i get the same thing. Everything else is running fine and mail is being delivered and sent. zmcontrol reports that logger isn't running:

 antispam                Running
        antivirus               Running
        ldap                    Running
        logger                  Stopped
        mailbox                 Running
        mta                     Running
        snmp                    Running
        spell                   Running

In my zimbra.log that's in /opt/zimbra/log I'm still seeing mysql login errors event though I've reset the mysql passwords as described above.

com.zimbra.cs.service.ServiceException: system failure: getting database logger connection
    at com.zimbra.cs.service.ServiceException.FAILURE(ServiceException.java:131)
    at com.zimbra.cs.db.DbPool.getLoggerConnection(DbPool.java:364)
    at com.zimbra.cs.service.admin.GetServiceStatus.handle(GetServiceStatus.java:67)
    at com.zimbra.soap.SoapEngine.dispatchRequest(SoapEngine.java:252)
    at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:163)
    at com.zimbra.soap.SoapEngine.dispatch(SoapEngine.java:84)
    at com.zimbra.soap.SoapServlet.doPost(SoapServlet.java:228)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:709)
    at com.zimbra.cs.servlet.ZimbraServlet.service(ZimbraServlet.java:154)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:214)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:526)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:825)
    at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:738)
    at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:526)
    at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
    at java.lang.Thread.run(Thread.java:595)
Caused by: java.sql.SQLException: Access denied for user 'zimbra'@'localhost' (using password: YES)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2928)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:771)
    at com.mysql.jdbc.MysqlIO.secureAuth411(MysqlIO.java:3649)
    at com.mysql.jdbc.MysqlIO.doHandshake(MysqlIO.java:1176)
    at com.mysql.jdbc.Connection.createNewIO(Connection.java:2558)
    at com.mysql.jdbc.Connection.<init>(Connection.java:1485)
    at com.mysql.jdbc.NonRegisteringDriver.connect(NonRegisteringDriver.java:266)
    at java.sql.DriverManager.getConnection(DriverManager.java:525)
    at java.sql.DriverManager.getConnection(DriverManager.java:193)
    at com.zimbra.cs.db.DbPool.getLoggerConnection(DbPool.java:361)
    ... 23 more

Any help would be great. Thanks a lot.
stu

[KevinH]

There are separate user/pass for the logger DB. I'd recommend trying to reset those.

[marcmac]

You can't get the sql connection because the sql instance isn't starting (nor is swatch).

logmysql.server start should start the sql instance, or give some info as to why it's not starting.

/tmp/logswatch.out may have some swatch errors.

[oopstu]

logswatch.out shows a login problem, and starting logmysql.server says mysqld is running.

How do i reset the passwords for the logger as suggested? (I'll search the forums for that answer now in preparation for the rtfm response. ) Thanks for the quick replies. Look forward to having this last issue resolved.



[zimbra@mail ~]$ cat /tmp/logswatch.out

*** logswatch version 3.1.1 (pid:30558) started at Mon Mar 20 11:30:04 EST 2006

DBI connect('database=zimbra_logger;mysql_read_default _file=/opt/zimbra/conf/my.logger.cnf;mysql_socket=/opt/zimbra/logger/db/mysql.sock','zimbra',...) failed: Access denied for user 'zimbra'@'localhost' (using password: YES) at /opt/zimbra/bin/zmlogger line 44
DB: Can't connect to dbi:mysql:database=zimbra_logger;mysql_read_defaul t_file=/opt/zimbra/conf/my.logger.cnf;mysql_socket=/opt/zimbra/logger/db/mysql.sock: Access denied for user 'zimbra'@'localhost' (using password: YES)

[marcmac]

It sounds like you may have an instance sitting around from a previous install, or somesuch.

ps auxww | grep sql | grep logger.

Kill it (make sure it's the logger instance, not the other one).

Try restarting, see if you can get in then.

If not, you can try resetting the password with zmlogmypasswd, but if the root sql passwd is out of sync, that won't work - you'll have to restart the instance with --skip-grant-tables (that's your search term, btw) and set it manually.

[oopstu]

marcmac, you're rapidly becoming my hero. So I duplicated the steps outlined in your post about manualy resetting mysql passwords but I substitued logmysql.server for mysql.server. Now, the sql server appears to run, or maybe run-crash-run. I think I've got the passwords all in sync, but the /tmp/logswatch.out is showing this:

DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 973.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 974.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 975.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 976.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 977.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 978.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 979.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 980.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 981.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 982.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 983.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 984.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 985.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 986.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 987.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 988.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 989.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 990.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 991.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 992.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 993.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 994.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 995.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 996.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 997.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 998.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 999.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 1000.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 1001.
DBD::mysql::st execute failed: MySQL server has gone away at /opt/zimbra/bin/zmlogger line 162, <> line 1002.


Swatch appears to be running now.

zmloggerctl status is much happier:

[zimbra@mail ~]$ sh -x bin/zmloggerctl status
+ BASE=/opt/zimbra
+ SCRIPTS='logmysql.server zmlogswatchctl'
+ case "$1" in
+ STATUS=0
+ for i in '$SCRIPTS'
+ '[' logmysql.server = logmysql.server ']'
+ /opt/zimbra/bin/logmysqladmin status
+ R=1
+ '[' 1 -ne 0 ']'
+ STATUS=1
+ for i in '$SCRIPTS'
+ '[' zmlogswatchctl = logmysql.server ']'
+ /opt/zimbra/bin/zmlogswatchctl status
+ R=0
+ '[' 0 -ne 0 ']'
+ exit 1
[zimbra@mail ~]$

If i could get just a *bit* more help or one more magic pointer like the last I think I'll be there. Thanks again for all the help. What a great community you have around a killer system.

[marcmac]

+ for i in '$SCRIPTS'
+ '[' logmysql.server = logmysql.server ']'
+ /opt/zimbra/bin/logmysqladmin status
+ R=1
+ '[' 1 -ne 0 ']'
+ STATUS=1

This means that sql still isn't running. Have you started it?

[oopstu]

it *seems* like mysql is running, but not correctly? Or swatch or something else isn't running that I should know about but don't?

[zimbra@mail log]$ zmloggerctl start
[zimbra@mail log]$ Starting mysqld daemon with databases from /opt/zimbra/logger/db/data

[zimbra@mail log]$ ps auxww | grep sql | grep logger
zimbra 11983 1.0 0.0 2180 1076 pts/4 S 13:48 0:00 /bin/sh /opt/zimbra/logger/mysql/bin/mysqld_safe --defaults-file=/opt/zimbra/conf/my.logger.cnf --ledir=/opt/zimbra/logger/mysql/bin
zimbra 12024 5.0 0.6 105248 13860 pts/4 Sl 13:48 0:00 /opt/zimbra/logger/mysql/bin/mysqld --defaults-file=/opt/zimbra/conf/my.logger.cnf --basedir=/opt/zimbra/logger/mysql --datadir=/opt/zimbra/logger/db/data --pid-file=/opt/zimbra/logger/db/mysql.pid --skip-locking --port=7307 --socket=/opt/zimbra/logger/db/mysql.sock

[marcmac]

then logmysqadmin status is returning a non-zero exit value, which is probably password again - what happens when you run that?

logmysqladmin status
echo $?

If you get a non-zero status, change the sql root password (skip-grant-tables, etc)

[oopstu]

It is definitely permissions. So there's a setting I can't find.

When editing mysql.server i changed the associated properties:
zimbra_mysql_password
mysql_root_password

but... for the logger I can only find:
zimbra_logger_mysql_password

where is the root pwd for this mysql isntance in the localconfig settings?