Re: [Zookeeper-user] odd exceptions when using zookeeper

SourceForge Headquarters 1320 Columbia Street Suite 310 San Diego, CA 92101 +1 (858) 422-6466

A bit more info in the trace file, but no obvious reason why the server 
is expiring the session:

2008-05-23 14:25:47,267 - TRACE [main:ZooTrace@68][] - Snapshotting: 0
2008-05-23 14:25:47,287 - TRACE [main:ZooTrace@68][] - Snapshotting 
finished: 0
2008-05-23 14:26:08,354 - WARN 
[NIOServerCxn.Factory:NIOServerCnxn@471][] - Connected to 
/xxx.xxx.xxx.xxx:35713 lastZxid 0
2008-05-23 14:26:08,357 - TRACE [NIOServerCxn.Factory:ZooTrace@68][] - 
SessionTrackerImpl --- Adding 11a1707891b0000 6000
2008-05-23 14:26:08,362 - WARN 
[NIOServerCxn.Factory:NIOServerCnxn@500][] - Creating new session 
11a1707891b0000
2008-05-23 14:26:08,363 - TRACE [ProcessThread:ZooTrace@87][] - 
:P11a1707891b0000 0 fffffffffffffffe  txn type = unknown createSession n/a
2008-05-23 14:26:08,369 - TRACE [ProcessThread:ZooTrace@68][] - 
SessionTrackerImpl --- Existing session 11a1707891b0000 6000
2008-05-23 14:26:08,371 - TRACE [SyncThread:ZooTrace@87][] - 
:S11a1707891b0000 0 1  txn type = -10 createSession n/a
2008-05-23 14:26:08,397 - TRACE [SyncThread:ZooTrace@87][] - 
:E11a1707891b0000 0 1  txn type = -10 createSession n/a
2008-05-23 14:26:08,400 - TRACE [SyncThread:ZooTrace@68][] - 
SessionTrackerImpl --- Existing session 11a1707891b0000 6000
2008-05-23 14:26:08,406 - WARN  [SyncThread:NIOServerCnxn@774][] - 
Finished init of 11a1707891b0000: true
2008-05-23 14:26:08,412 - TRACE [ProcessThread:ZooTrace@87][] - 
:P11a1707891b0000 1 fffffffffffffffe  txn type = unknown exists /locks
2008-05-23 14:26:08,413 - TRACE [SyncThread:ZooTrace@87][] - 
:S11a1707891b0000 1 fffffffffffffffe  txn type = unknown exists /locks
2008-05-23 14:26:08,415 - TRACE [SyncThread:ZooTrace@87][] - 
:E11a1707891b0000 1 fffffffffffffffe  txn type = unknown exists /locks
2008-05-23 14:26:14,435 - TRACE [NIOServerCxn.Factory:ZooTrace@68][] - 
close  NIOServerCnxn: java.nio.channels.SocketChannel[connected 
local=/xxx.xxx.xxx.xxx:2181 remote=/xxx.xxx.xxx.xxx:35713]
2008-05-23 14:26:15,010 - WARN 
[SessionTracker:SessionTrackerImpl@133][] - Expiring 11a1707891b0000
2008-05-23 14:26:15,012 - TRACE [SessionTracker:ZooTrace@68][] - 
ZooKeeperServer --- Session to expire: 11a1707891b0000
2008-05-23 14:26:15,013 - TRACE [SessionTracker:ZooTrace@68][] - 
ZooKeeperServer --- Session to be closed: 11a1707891b0000
2008-05-23 14:26:15,015 - TRACE [ProcessThread:ZooTrace@87][] - 
:P11a1707891b0000 0 fffffffffffffffe  txn type = unknown closeSession n/a
2008-05-23 14:26:15,017 - WARN 
[ProcessThread:PrepRequestProcessor@341][] - Processed session 
termination request for id: 11a1707891b0000
2008-05-23 14:26:15,019 - TRACE [SyncThread:ZooTrace@87][] - 
:S11a1707891b0000 0 2  txn type = -11 closeSession n/a
2008-05-23 14:26:15,023 - TRACE [SyncThread:ZooTrace@87][] - 
:E11a1707891b0000 0 2  txn type = -11 closeSession n/a
2008-05-23 14:26:15,025 - TRACE [SyncThread:ZooTrace@68][] - 
SessionTrackerImpl --- Removing 11a1707891b0000
2008-05-23 14:26:15,816 - WARN 
[NIOServerCxn.Factory:NIOServerCnxn@471][] - Connected to 
/xxx.xxx.xxx.xxx:35714 lastZxid -1
2008-05-23 14:26:15,818 - TRACE [NIOServerCxn.Factory:ZooTrace@68][] - 
Session 11a1707891b0000 is valid: false
2008-05-23 14:26:15,819 - WARN 
[NIOServerCxn.Factory:NIOServerCnxn@774][] - Finished init of 
11a1707891b0000: false
2008-05-23 14:26:15,821 - WARN 
[NIOServerCxn.Factory:NIOServerCnxn@497][] - Renewing session 
11a1707891b0000
2008-05-23 14:26:15,823 - TRACE [NIOServerCxn.Factory:ZooTrace@68][] - 
close  NIOServerCnxn: java.nio.channels.SocketChannel[connected 
local=/xxx.xxx.xxx.xxx:2181 remote=/xxx.xxx.xxx.xxx:35714]

Juan Ramirez wrote:
> Hi, Ben.  Thanks for the prompt reply.
> 
> Benjamin Reed wrote:
>> Usually, this exception means that the server closed the socket. Are you 
>> seeing anything strange in the server log?
>>
> 
> It seems like the server is expiring the session; not sure why.
> 
> 2008-05-23 14:26:08,354 - WARN  [NIOServerCxn.Factory:NIOServerCnxn@471] 
> - Connected to /xxx.xxx.xxx.xxx:35713 lastZxid 0
> 2008-05-23 14:26:08,362 - WARN  [NIOServerCxn.Factory:NIOServerCnxn@500] 
> - Creating new session 11a1707891b0000
> 2008-05-23 14:26:08,406 - WARN  [SyncThread:NIOServerCnxn@774] - 
> Finished init of 11a1707891b0000: true
> 2008-05-23 14:26:15,010 - WARN  [SessionTracker:SessionTrackerImpl@133] 
> - Expiring 11a1707891b0000
> 2008-05-23 14:26:15,017 - WARN  [ProcessThread:PrepRequestProcessor@341] 
> - Processed session termination request for id: 11a1707891b0000
> 
> New connection request from client?
> 
> 2008-05-23 14:26:15,816 - WARN  [NIOServerCxn.Factory:NIOServerCnxn@471] 
> - Connected to /xxx.xxx.xxx.xxx:35714 lastZxid -1
> 2008-05-23 14:26:15,819 - WARN  [NIOServerCxn.Factory:NIOServerCnxn@774] 
> - Finished init of 11a1707891b0000: false
> 2008-05-23 14:26:15,821 - WARN  [NIOServerCxn.Factory:NIOServerCnxn@497] 
> - Renewing session 11a1707891b0000
> 
> But doesn't seem like the client recovers:
> 
> com.yahoo.zookeeper.KeeperException: KeeperErrorCode = SessionExpired
>          at com.yahoo.zookeeper.ZooKeeper.exists(ZooKeeper.java:357)
>          at zookeeperclient.Main$Process.tryCreate(Main.java:143)
>          at zookeeperclient.Main$Process.<init>(Main.java:88)
>          at zookeeperclient.Main.main(Main.java:43)
> com.yahoo.zookeeper.KeeperException: KeeperErrorCode = SessionExpired
>          at com.yahoo.zookeeper.ZooKeeper.exists(ZooKeeper.java:357)
>          at zookeeperclient.Main$Process.tryCreate(Main.java:143)
>          at zookeeperclient.Main$Process.<init>(Main.java:88)
>          at zookeeperclient.Main.main(Main.java:43)
> 
> 
> 
>> The null pointer exception is coming from the code that parses the hostPort 
>> list. Since you are running in standalone mode your hostPort should be a 
>> string of the form host:port. The relevant code is the following:
>>
>>         String hostsList[] = hosts.split(",");
>>         for (String host : hostsList) {
>>             int port = 2181;
>>             String parts[] = host.split(":"); // LINE 218
>>
>> It would seem that host is null, but I'm at a complete loss for how that could 
>> be...
> 
> Sorry, that was my bad.  It seems that once the ZooKeeper instance gets 
> into the SessionExpired state, it doesn't recover.  Is this expected?  I 
> had some code creating a new instance as a workaround and had not 
> properly persisted the connection string.
> 
> Thanks again,
> 
> Juan
> 
> 
> -------------------------------------------------------------------------
> This SF.net email is sponsored by: Microsoft
> Defy all challenges. Microsoft(R) Visual Studio 2008.
> http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/
> _______________________________________________
> Zookeeper-user mailing list
> Zoo...@li...
> https://lists.sourceforge.net/lists/listinfo/zookeeper-user