"juju status" trigger errors within my zk logs

[Thiago Martins]

Guys,

 After a week of workarounds here and there with MaaS, now it is time to hit Juju BUGS...

 When I run "juju status", at my node I see:

/var/log/zookeeper/zookeeper.log

----
2012-10-23 22:09:32,032 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:49402
2012-10-23 22:09:32,032 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:49403
2012-10-23 22:09:32,034 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@634] - EndOfStreamException: Unable to read additional data from client sessionid 0x0, likely client has closed socket
2012-10-23 22:09:32,034 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /127.0.0.1:49402 (no session established for client)
2012-10-23 22:09:32,035 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@777] - Client attempting to establish new session at /127.0.0.1:49403
2012-10-23 22:09:32,053 - INFO [SyncThread:0:NIOServerCnxn@1580] - Established session 0x13a8e264dc70007 with negotiated timeout 10000 for client /127.0.0.1:49403
2012-10-23 22:09:32,229 - INFO [ProcessThread:-1:PrepRequestProcessor@399] - Processed session termination for sessionid: 0x13a8e264dc70007
2012-10-23 22:09:32,229 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@634] - EndOfStreamException: Unable to read additional data from client sessionid 0x13a8e264dc70007, likely client has closed socket
2012-10-23 22:09:32,231 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /127.0.0.1:49403 which had sessionid 0x13a8e264dc70007
2012-10-23 22:09:32,233 - ERROR [SyncThread:0:NIOServerCnxn@445] - Unexpected Exception:
java.nio.channels.CancelledKeyException
        at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
        at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
        at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:418)
        at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1509)
        at org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalRequestProcessor.java:359)
        at org.apache.zookeeper.server.SyncRequestProcessor.flush(SyncRequestProcessor.java:163)
        at org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java:98)
----

 The output of "juju status" is:

machines:
  0:
    agent-state: running
    dns-name: node-525400ebb0c8.local
    instance-id: /MAAS/api/1.0/nodes/node-6c2ee0be-1d1a-11e2-bbc9-525400939df1/
    instance-state: unknown
services: {}
2012-10-24 00:09:32,900 INFO 'status' command finished successfully

 When I try to ignore the error and run "juju deploy mysql", I got:

--
2012-10-24 00:11:56,730 INFO Searching for charm cs:precise/mysql in charm store
2012-10-24 00:12:00,402 INFO Connecting to environment...
2012-10-24 00:12:01,463 INFO Connected to environment.
2012-10-24 00:12:03,270 INFO Charm deployed as service: 'mysql'
2012-10-24 00:12:03,273 INFO 'deploy' command finished successfully
--

 But within my node:

--
2012-10-23 22:12:00,744 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:49404
2012-10-23 22:12:00,744 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn$Factory@251] - Accepted socket connection from /127.0.0.1:49405
2012-10-23 22:12:00,746 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@634] - EndOfStreamException: Unable to read additional data from client sessionid 0x0, likely client has closed socket
2012-10-23 22:12:00,746 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /127.0.0.1:49404 (no session established for client)
2012-10-23 22:12:00,749 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@777] - Client attempting to establish new session at /127.0.0.1:49405
2012-10-23 22:12:00,765 - INFO [SyncThread:0:NIOServerCnxn@1580] - Established session 0x13a8e264dc70008 with negotiated timeout 10000 for client /127.0.0.1:49405
2012-10-23 22:12:02,653 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@634] - EndOfStreamException: Unable to read additional data from client sessionid 0x13a8e264dc70008, likely client has closed socket
2012-10-23 22:12:02,655 - INFO [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1435] - Closed socket connection for client /127.0.0.1:49405 which had sessionid 0x13a8e264dc70008
2012-10-23 22:12:14,000 - INFO [SessionTracker:ZooKeeperServer@316] - Expiring session 0x13a8e264dc70008, timeout of 10000ms exceeded
2012-10-23 22:12:14,001 - INFO [ProcessThread:-1:PrepRequestProcessor@399] - Processed session termination for sessionid: 0x13a8e264dc70008
--

 Please, guys, I'm serious now: When MaaS + Juju will become STABLE?

 I'm trying to work with those packages about a week now, just to find and open bugs... WTF?! :-@

Thanks,
Thiago

[Thiago Martins (martinx)]

BTW, there is no mysql running at my node...

[Thiago Martins (martinx)]

Well, guys, I give up.
Hope next year (13.04) MaaS and Juju becomes STABLE.
Right now, it is useless. I just wipe out all the data I have. No more MaaS / Juju for me.

Regards,
Thiago

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Kapil Thangavelu (hazmat)]

so zookeeper logs this exception for normal client operations, this isn't a bug.