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 2010/03/10 06:43:27 UTC
[jira] Created: (ZOOKEEPER-696) NPE in the hudson logs, seems
nioservercnxn closed twice
NPE in the hudson logs, seems nioservercnxn closed twice
--------------------------------------------------------
Key: ZOOKEEPER-696
URL: https://issues.apache.org/jira/browse/ZOOKEEPER-696
Project: Zookeeper
Issue Type: Bug
Components: server
Reporter: Patrick Hunt
Priority: Blocker
Fix For: 3.3.0
seeing the following on the console for http://hudson.zones.apache.org/hudson/view/ZooKeeper/job/ZooKeeper-trunk/729/
looks like the cnxn is closed twice? (the second time 'sock' is null). perhaps it's due to client closing and sending session term, then closing socket, server sees the read return -1, so closes cnxn, then sees the session close request (which was queued)?
[junit] 2010-03-10 03:15:53,205 - INFO [main:NIOServerCnxn@1232] - Closed socket connection for client /127.0.0.1:41285 which had sessionid 0x127461233fc0000
[junit] 2010-03-10 03:15:53,206 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn$Factory@269] - Ignoring unexpected runtime exception
[junit] java.lang.NullPointerException
[junit] at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1232)
[junit] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:594)
[junit] at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:259)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-696) NPE in the hudson logs, seems
nioservercnxn closed twice
Posted by "Hudson (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-696?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12844057#action_12844057 ]
Hudson commented on ZOOKEEPER-696:
----------------------------------
Integrated in ZooKeeper-trunk #732 (See [http://hudson.zones.apache.org/hudson/job/ZooKeeper-trunk/732/])
. NPE in the hudson logs, seems nioservercnxn closed twice (phunt via mahadev)
> NPE in the hudson logs, seems nioservercnxn closed twice
> --------------------------------------------------------
>
> Key: ZOOKEEPER-696
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-696
> Project: Zookeeper
> Issue Type: Bug
> Components: server
> Reporter: Patrick Hunt
> Assignee: Patrick Hunt
> Priority: Blocker
> Fix For: 3.3.0
>
> Attachments: ZOOKEEPER-696.patch
>
>
> seeing the following on the console for http://hudson.zones.apache.org/hudson/view/ZooKeeper/job/ZooKeeper-trunk/729/
> looks like the cnxn is closed twice? (the second time 'sock' is null). perhaps it's due to client closing and sending session term, then closing socket, server sees the read return -1, so closes cnxn, then sees the session close request (which was queued)?
> [junit] 2010-03-10 03:15:53,205 - INFO [main:NIOServerCnxn@1232] - Closed socket connection for client /127.0.0.1:41285 which had sessionid 0x127461233fc0000
> [junit] 2010-03-10 03:15:53,206 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn$Factory@269] - Ignoring unexpected runtime exception
> [junit] java.lang.NullPointerException
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1232)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:594)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:259)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-696) NPE in the hudson logs, seems
nioservercnxn closed twice
Posted by "Patrick Hunt (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-696?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Patrick Hunt updated ZOOKEEPER-696:
-----------------------------------
Attachment: ZOOKEEPER-696.patch
this patch removes all npes in the log on my machine
1) close could be called from multiple threads (in case of testing). I changed the synchronization quite a bit here so pay close attention
2) notice that clear and other methods calling close on the cnxns list now clone the list and call close, close removes the cnxn from the list itself
3) notice that close determines at the start whether the cnxn is closed yet or not - based on whether the cnxn is in the cnxns list or not
4) sessiontest - fixed unrelated npe that was showing up
5) leader - this code looked wrong to me. Notice that ss close was after the cnxns close, seems to me that this should be first to eliminate the possibility that someone added to the cnxns after that list had been cleared (factory run method checks if ss is closed or not and exits if it is)
would be good to have more than one pair of eyes on this review
> NPE in the hudson logs, seems nioservercnxn closed twice
> --------------------------------------------------------
>
> Key: ZOOKEEPER-696
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-696
> Project: Zookeeper
> Issue Type: Bug
> Components: server
> Reporter: Patrick Hunt
> Assignee: Patrick Hunt
> Priority: Blocker
> Fix For: 3.3.0
>
> Attachments: ZOOKEEPER-696.patch
>
>
> seeing the following on the console for http://hudson.zones.apache.org/hudson/view/ZooKeeper/job/ZooKeeper-trunk/729/
> looks like the cnxn is closed twice? (the second time 'sock' is null). perhaps it's due to client closing and sending session term, then closing socket, server sees the read return -1, so closes cnxn, then sees the session close request (which was queued)?
> [junit] 2010-03-10 03:15:53,205 - INFO [main:NIOServerCnxn@1232] - Closed socket connection for client /127.0.0.1:41285 which had sessionid 0x127461233fc0000
> [junit] 2010-03-10 03:15:53,206 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn$Factory@269] - Ignoring unexpected runtime exception
> [junit] java.lang.NullPointerException
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1232)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:594)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:259)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-696) NPE in the hudson logs, seems
nioservercnxn closed twice
Posted by "Patrick Hunt (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-696?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Patrick Hunt updated ZOOKEEPER-696:
-----------------------------------
Assignee: Patrick Hunt
Looks like the issue is that in the tests we are both shutting down the clients and also shutting down the server. As a result in some cases the socket is nulled by one/other of the close calls while the other close call then sees a null for the sock and NPEs. I'll work on a patch.
> NPE in the hudson logs, seems nioservercnxn closed twice
> --------------------------------------------------------
>
> Key: ZOOKEEPER-696
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-696
> Project: Zookeeper
> Issue Type: Bug
> Components: server
> Reporter: Patrick Hunt
> Assignee: Patrick Hunt
> Priority: Blocker
> Fix For: 3.3.0
>
>
> seeing the following on the console for http://hudson.zones.apache.org/hudson/view/ZooKeeper/job/ZooKeeper-trunk/729/
> looks like the cnxn is closed twice? (the second time 'sock' is null). perhaps it's due to client closing and sending session term, then closing socket, server sees the read return -1, so closes cnxn, then sees the session close request (which was queued)?
> [junit] 2010-03-10 03:15:53,205 - INFO [main:NIOServerCnxn@1232] - Closed socket connection for client /127.0.0.1:41285 which had sessionid 0x127461233fc0000
> [junit] 2010-03-10 03:15:53,206 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn$Factory@269] - Ignoring unexpected runtime exception
> [junit] java.lang.NullPointerException
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1232)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:594)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:259)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-696) NPE in the hudson logs, seems
nioservercnxn closed twice
Posted by "Hadoop QA (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-696?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12843821#action_12843821 ]
Hadoop QA commented on ZOOKEEPER-696:
-------------------------------------
+1 overall. Here are the results of testing the latest attachment
http://issues.apache.org/jira/secure/attachment/12438453/ZOOKEEPER-696.patch
against trunk revision 921509.
+1 @author. The patch does not contain any @author tags.
+1 tests included. The patch appears to include 3 new or modified tests.
+1 javadoc. The javadoc tool did not generate any warning messages.
+1 javac. The applied patch does not increase the total number of javac compiler warnings.
+1 findbugs. The patch does not introduce any new Findbugs warnings.
+1 release audit. The applied patch does not increase the total number of release audit warnings.
+1 core tests. The patch passed core unit tests.
+1 contrib tests. The patch passed contrib unit tests.
Test results: http://hudson.zones.apache.org/hudson/job/Zookeeper-Patch-h8.grid.sp2.yahoo.net/138/testReport/
Findbugs warnings: http://hudson.zones.apache.org/hudson/job/Zookeeper-Patch-h8.grid.sp2.yahoo.net/138/artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
Console output: http://hudson.zones.apache.org/hudson/job/Zookeeper-Patch-h8.grid.sp2.yahoo.net/138/console
This message is automatically generated.
> NPE in the hudson logs, seems nioservercnxn closed twice
> --------------------------------------------------------
>
> Key: ZOOKEEPER-696
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-696
> Project: Zookeeper
> Issue Type: Bug
> Components: server
> Reporter: Patrick Hunt
> Assignee: Patrick Hunt
> Priority: Blocker
> Fix For: 3.3.0
>
> Attachments: ZOOKEEPER-696.patch
>
>
> seeing the following on the console for http://hudson.zones.apache.org/hudson/view/ZooKeeper/job/ZooKeeper-trunk/729/
> looks like the cnxn is closed twice? (the second time 'sock' is null). perhaps it's due to client closing and sending session term, then closing socket, server sees the read return -1, so closes cnxn, then sees the session close request (which was queued)?
> [junit] 2010-03-10 03:15:53,205 - INFO [main:NIOServerCnxn@1232] - Closed socket connection for client /127.0.0.1:41285 which had sessionid 0x127461233fc0000
> [junit] 2010-03-10 03:15:53,206 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn$Factory@269] - Ignoring unexpected runtime exception
> [junit] java.lang.NullPointerException
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1232)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:594)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:259)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-696) NPE in the hudson logs, seems
nioservercnxn closed twice
Posted by "Flavio Paiva Junqueira (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-696?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12843835#action_12843835 ]
Flavio Paiva Junqueira commented on ZOOKEEPER-696:
--------------------------------------------------
+1, it looks good to me.
> NPE in the hudson logs, seems nioservercnxn closed twice
> --------------------------------------------------------
>
> Key: ZOOKEEPER-696
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-696
> Project: Zookeeper
> Issue Type: Bug
> Components: server
> Reporter: Patrick Hunt
> Assignee: Patrick Hunt
> Priority: Blocker
> Fix For: 3.3.0
>
> Attachments: ZOOKEEPER-696.patch
>
>
> seeing the following on the console for http://hudson.zones.apache.org/hudson/view/ZooKeeper/job/ZooKeeper-trunk/729/
> looks like the cnxn is closed twice? (the second time 'sock' is null). perhaps it's due to client closing and sending session term, then closing socket, server sees the read return -1, so closes cnxn, then sees the session close request (which was queued)?
> [junit] 2010-03-10 03:15:53,205 - INFO [main:NIOServerCnxn@1232] - Closed socket connection for client /127.0.0.1:41285 which had sessionid 0x127461233fc0000
> [junit] 2010-03-10 03:15:53,206 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn$Factory@269] - Ignoring unexpected runtime exception
> [junit] java.lang.NullPointerException
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1232)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:594)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:259)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Commented: (ZOOKEEPER-696) NPE in the hudson logs, seems
nioservercnxn closed twice
Posted by "Mahadev konar (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-696?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12843842#action_12843842 ]
Mahadev konar commented on ZOOKEEPER-696:
-----------------------------------------
+1 the patch looks good!
> NPE in the hudson logs, seems nioservercnxn closed twice
> --------------------------------------------------------
>
> Key: ZOOKEEPER-696
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-696
> Project: Zookeeper
> Issue Type: Bug
> Components: server
> Reporter: Patrick Hunt
> Assignee: Patrick Hunt
> Priority: Blocker
> Fix For: 3.3.0
>
> Attachments: ZOOKEEPER-696.patch
>
>
> seeing the following on the console for http://hudson.zones.apache.org/hudson/view/ZooKeeper/job/ZooKeeper-trunk/729/
> looks like the cnxn is closed twice? (the second time 'sock' is null). perhaps it's due to client closing and sending session term, then closing socket, server sees the read return -1, so closes cnxn, then sees the session close request (which was queued)?
> [junit] 2010-03-10 03:15:53,205 - INFO [main:NIOServerCnxn@1232] - Closed socket connection for client /127.0.0.1:41285 which had sessionid 0x127461233fc0000
> [junit] 2010-03-10 03:15:53,206 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn$Factory@269] - Ignoring unexpected runtime exception
> [junit] java.lang.NullPointerException
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1232)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:594)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:259)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-696) NPE in the hudson logs, seems
nioservercnxn closed twice
Posted by "Patrick Hunt (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-696?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Patrick Hunt updated ZOOKEEPER-696:
-----------------------------------
Status: Patch Available (was: Open)
> NPE in the hudson logs, seems nioservercnxn closed twice
> --------------------------------------------------------
>
> Key: ZOOKEEPER-696
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-696
> Project: Zookeeper
> Issue Type: Bug
> Components: server
> Reporter: Patrick Hunt
> Assignee: Patrick Hunt
> Priority: Blocker
> Fix For: 3.3.0
>
> Attachments: ZOOKEEPER-696.patch
>
>
> seeing the following on the console for http://hudson.zones.apache.org/hudson/view/ZooKeeper/job/ZooKeeper-trunk/729/
> looks like the cnxn is closed twice? (the second time 'sock' is null). perhaps it's due to client closing and sending session term, then closing socket, server sees the read return -1, so closes cnxn, then sees the session close request (which was queued)?
> [junit] 2010-03-10 03:15:53,205 - INFO [main:NIOServerCnxn@1232] - Closed socket connection for client /127.0.0.1:41285 which had sessionid 0x127461233fc0000
> [junit] 2010-03-10 03:15:53,206 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn$Factory@269] - Ignoring unexpected runtime exception
> [junit] java.lang.NullPointerException
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1232)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:594)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:259)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
[jira] Updated: (ZOOKEEPER-696) NPE in the hudson logs, seems
nioservercnxn closed twice
Posted by "Mahadev konar (JIRA)" <ji...@apache.org>.
[ https://issues.apache.org/jira/browse/ZOOKEEPER-696?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Mahadev konar updated ZOOKEEPER-696:
------------------------------------
Resolution: Fixed
Hadoop Flags: [Reviewed]
Status: Resolved (was: Patch Available)
I just committed this. thanks pat!
> NPE in the hudson logs, seems nioservercnxn closed twice
> --------------------------------------------------------
>
> Key: ZOOKEEPER-696
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-696
> Project: Zookeeper
> Issue Type: Bug
> Components: server
> Reporter: Patrick Hunt
> Assignee: Patrick Hunt
> Priority: Blocker
> Fix For: 3.3.0
>
> Attachments: ZOOKEEPER-696.patch
>
>
> seeing the following on the console for http://hudson.zones.apache.org/hudson/view/ZooKeeper/job/ZooKeeper-trunk/729/
> looks like the cnxn is closed twice? (the second time 'sock' is null). perhaps it's due to client closing and sending session term, then closing socket, server sees the read return -1, so closes cnxn, then sees the session close request (which was queued)?
> [junit] 2010-03-10 03:15:53,205 - INFO [main:NIOServerCnxn@1232] - Closed socket connection for client /127.0.0.1:41285 which had sessionid 0x127461233fc0000
> [junit] 2010-03-10 03:15:53,206 - WARN [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:11221:NIOServerCnxn$Factory@269] - Ignoring unexpected runtime exception
> [junit] java.lang.NullPointerException
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.close(NIOServerCnxn.java:1232)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:594)
> [junit] at org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:259)
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.