[ 
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$mywatc...@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.selectionkeyi...@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.

Reply via email to