You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@zookeeper.apache.org by "Patrick Hunt (JIRA)" <ji...@apache.org> on 2009/10/30 07:14:59 UTC
[jira] Commented: (ZOOKEEPER-564) Give more feedback on that
current flow of events in java client logs
[ https://issues.apache.org/jira/browse/ZOOKEEPER-564?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12771829#action_12771829 ]
Patrick Hunt commented on ZOOKEEPER-564:
----------------------------------------
I've worked out the following for session establishment, teardown and expiration handling. I'm not convinced about the numbering (and getting the numbers "right" (no gaps for example) in all cases might be tough).
We'd also include some documentation describing the client session establishment, teardown, and expiration handling which would refer to the messages (a bit of handwaving here cuz nothing yet, but think that it would be some docs describing what's below). These logs make it more clear re documenting the steps - first a socket connection is created, then a session is established.
following is logging at info level
client side log create session
2009-10-29 21:37:05,393 - INFO - Initiating client connection, connectString=localhost:2181 sessionTimeout=30000 watcher=org.apache.zookeeper.ZooKeeperMain$MyWatcher@1608e05
2009-10-29 21:37:05,449 - INFO - Opening socket connection to server localhost/127.0.0.1:2181
2009-10-29 21:37:05,493 - INFO - Socket connection established to localhost/127.0.0.1:2181, initiating session
Welcome to ZooKeeper!
2009-10-29 21:37:05,547 - INFO - Session establishment complete, sessionid = 0x124a3f255ce0000
client side log close session
2009-10-29 21:37:08,677 - INFO - Session: 0x124a3f255ce0000 closed
server watching client session creation
2009-10-29 20:57:19,748 - INFO - Accepted socket connection from /127.0.0.1:49641
2009-10-29 20:57:19,784 - INFO - Client attempting to establish new session at /127.0.0.1:49641
2009-10-29 20:57:19,801 - INFO - Established session 0x124a3cdf52d0000 for client /127.0.0.1:49641
server watching client close session
2009-10-29 20:57:49,772 - INFO - Processed session termination for sessionid: 0x124a3cdf52d0000
2009-10-29 20:57:49,775 - INFO - Closed socket connection for client /127.0.0.1:49641 which had sessionid 0x124a3cdf52d0000
server expiring client session
2009-10-29 21:00:18,001 - INFO - Expiring session 0x124a3cdf52d0001, timeout of 30000ms exceeded
2009-10-29 21:00:18,002 - INFO - Processed session termination for sessionid: 0x124a3cdf52d0001
2009-10-29 21:00:18,004 - INFO - Closed socket connection for client /127.0.0.1:49644 which had sessionid 0x124a3cdf52d0001
server watching client attempt to re-establish expired session
2009-10-29 21:00:28,222 - INFO - Accepted socket connection from /127.0.0.1:51000
2009-10-29 21:00:28,223 - INFO - Client attempting to renew session 0x124a3cdf52d0001 at /127.0.0.1:51000
2009-10-29 21:00:28,225 - INFO - Invalid session 0x124a3cdf52d0001 for client /127.0.0.1:51000, probably expired
2009-10-29 21:00:28,227 - INFO - Closed socket connection for client /127.0.0.1:51000 which had sessionid 0
> Give more feedback on that current flow of events in java client logs
> ---------------------------------------------------------------------
>
> Key: ZOOKEEPER-564
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-564
> Project: Zookeeper
> Issue Type: Improvement
> Affects Versions: 3.2.1
> Reporter: Jean-Daniel Cryans
>
> As discussed during the 10/23 meeting, one issue we have in debugging ZK client logs with HBase is that we have a hard time following the flow of events. It may be obvious for a ZK dev, but in our POV that kind of trace isn't very intuitive:
> {code}
> 2009-09-27 15:41:10,776 INFO org.apache.zookeeper.ClientCnxn: Attempting connection to server ...
> 2009-09-27 15:41:10,776 INFO org.apache.zookeeper.ClientCnxn: Priming connection to java.nio.channels.SocketChannel[connected local=/ ... remote=...
> 2009-09-27 15:41:10,776 INFO org.apache.zookeeper.ClientCnxn: Server connection successful
> 2009-09-27 15:41:10,784 WARN org.apache.zookeeper.ClientCnxn: Exception closing session 0x0 to sun.nio.ch.SelectionKeyImpl@2c9b42e6
> {code}
> This excerpt is just an example. We would like to see something like a numbering of the events and possibly, in the case of an exception, at which point did it went wrong and what's the next step.
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.