[ 
https://issues.apache.org/jira/browse/ZOOKEEPER-1043?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13059501#comment-13059501
 ] 

César Álvarez Núñez commented on ZOOKEEPER-1043:
------------------------------------------------

Today we have had the same problem and the origin seems to be the followin 
exception:

{noformat}
2011-07-04 10:39:55,515 - INFO  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@251][] - 
Accepted socket connection from /YYY.YYY.YYY.67:1500
2011-07-04 10:39:55,581 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@274][] - 
Ignoring exception
java.net.SocketException: Invalid argument
        at sun.nio.ch.Net.setIntOption0(Native Method)
        at sun.nio.ch.Net.setIntOption(Unknown Source)
        at sun.nio.ch.SocketChannelImpl$1.setInt(Unknown Source)
        at sun.nio.ch.SocketOptsImpl.setBoolean(Unknown Source)
        at sun.nio.ch.SocketOptsImpl$IP$TCP.noDelay(Unknown Source)
        at sun.nio.ch.OptionAdaptor.setTcpNoDelay(Unknown Source)
        at sun.nio.ch.SocketAdaptor.setTcpNoDelay(Unknown Source)
        at 
org.apache.zookeeper.server.NIOServerCnxn.<init>(NIOServerCnxn.java:1367)
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.createConnection(NIOServerCnxn.java:215)
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:256)
{noformat}

As you can see, it seems to exist some correlation between the SocketException 
and the looped NPE.

{noformat}
2011-07-04 02:48:07,663 - INFO  [Snapshot Thread:FileTxnSnapLog@208][] - 
Snapshotting: 1801267fa2
2011-07-04 02:48:07,674 - INFO  [SyncThread:2:FileTxnLog@197][] - Creating new 
log file: log.1801267fa4
2011-07-04 08:30:43,812 - INFO  [Snapshot Thread:FileTxnSnapLog@208][] - 
Snapshotting: 18012774dd
2011-07-04 08:30:43,815 - INFO  [SyncThread:2:FileTxnLog@197][] - Creating new 
log file: log.18012774df
2011-07-04 09:23:40,586 - INFO  [Snapshot Thread:FileTxnSnapLog@208][] - 
Snapshotting: 180128bb4d
2011-07-04 09:23:40,596 - INFO  [SyncThread:2:FileTxnLog@197][] - Creating new 
log file: log.180128bb4f
2011-07-04 10:09:23,753 - INFO  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@251][] - 
Accepted socket connection from /XXX.XXX.XXX.245:49993
2011-07-04 10:09:23,754 - INFO  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn@1237][] - Processing 
stat command from /XXX.XXX.XXX.245:49993
2011-07-04 10:09:23,755 - INFO  [Thread-15:NIOServerCnxn$StatCommand@1153][] - 
Stat command output
2011-07-04 10:09:23,758 - INFO  [Thread-15:NIOServerCnxn@1435][] - Closed 
socket connection for client /XXX.XXX.XXX.245:49993 (no session established for 
client)
2011-07-04 10:20:03,391 - INFO  [Snapshot Thread:FileTxnSnapLog@208][] - 
Snapshotting: 180129e6b4
2011-07-04 10:20:03,397 - INFO  [SyncThread:2:FileTxnLog@197][] - Creating new 
log file: log.180129e6b6
2011-07-04 10:24:34,042 - INFO  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@251][] - 
Accepted socket connection from /YYY.YYY.YYY.69:1093
2011-07-04 10:24:34,044 - INFO  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn@1237][] - Processing 
stat command from /YYY.YYY.YYY.69:1093
2011-07-04 10:24:34,045 - INFO  [Thread-16:NIOServerCnxn$StatCommand@1153][] - 
Stat command output
2011-07-04 10:24:34,048 - INFO  [Thread-16:NIOServerCnxn@1435][] - Closed 
socket connection for client /YYY.YYY.YYY.69:1093 (no session established for 
client)
2011-07-04 10:39:55,515 - INFO  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@251][] - 
Accepted socket connection from /YYY.YYY.YYY.67:1500
2011-07-04 10:39:55,581 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@274][] - 
Ignoring exception
java.net.SocketException: Invalid argument
        at sun.nio.ch.Net.setIntOption0(Native Method)
        at sun.nio.ch.Net.setIntOption(Unknown Source)
        at sun.nio.ch.SocketChannelImpl$1.setInt(Unknown Source)
        at sun.nio.ch.SocketOptsImpl.setBoolean(Unknown Source)
        at sun.nio.ch.SocketOptsImpl$IP$TCP.noDelay(Unknown Source)
        at sun.nio.ch.OptionAdaptor.setTcpNoDelay(Unknown Source)
        at sun.nio.ch.SocketAdaptor.setTcpNoDelay(Unknown Source)
        at 
org.apache.zookeeper.server.NIOServerCnxn.<init>(NIOServerCnxn.java:1367)
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.createConnection(NIOServerCnxn.java:215)
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:256)
2011-07-04 10:39:55,601 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
Ignoring unexpected runtime exception
java.lang.NullPointerException
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:262)
2011-07-04 10:39:55,602 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
Ignoring unexpected runtime exception
java.lang.NullPointerException
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:262)
2011-07-04 10:39:55,602 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
Ignoring unexpected runtime exception
java.lang.NullPointerException
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:244)
2011-07-04 10:39:55,603 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
Ignoring unexpected runtime exception
java.lang.NullPointerException
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:244)
2011-07-04 10:39:55,603 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
Ignoring unexpected runtime exception
java.lang.NullPointerException
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:244)
2011-07-04 10:39:55,604 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
Ignoring unexpected runtime exception
java.lang.NullPointerException
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:244)
2011-07-04 10:39:55,604 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
Ignoring unexpected runtime exception
java.lang.NullPointerException
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:244)
2011-07-04 10:39:55,605 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
Ignoring unexpected runtime exception
java.lang.NullPointerException
        at 
org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:262)
2011-07-04 10:39:55,605 - WARN  
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
Ignoring unexpected runtime exception
java.lang.NullPointerException
...
{noformat}

Any help,
/César.

> Looped NPE at 
> org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:244)
> -------------------------------------------------------------------------------------------
>
>                 Key: ZOOKEEPER-1043
>                 URL: https://issues.apache.org/jira/browse/ZOOKEEPER-1043
>             Project: ZooKeeper
>          Issue Type: Bug
>    Affects Versions: 3.3.3
>         Environment: Sparc Solaris 10
> Java 6u17 64 bits
> 5 nodes ensemble
>            Reporter: César Álvarez Núñez
>
> I'm sorry but I only have this log (which belongs to a "follower" node) and a 
> previous message [Unexpected NodeCreated event after a 
> reconnection.|http://mail-archives.apache.org/mod_mbox/zookeeper-user/201103.mbox/%[email protected]%3E]
>  where I describe a potential side-effect at client side.
> {noformat}
> 2011-04-04 09:31:09,608 - INFO  [Snapshot Thread:FileTxnSnapLog@208][] - 
> Snapshotting: 1700527e36
> 2011-04-04 09:31:09,653 - INFO  [SyncThread:1:FileTxnLog@197][] - Creating 
> new log file: log.1700527e38
> 2011-04-04 10:13:39,287 - INFO  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@251][] - 
> Accepted socket connection from /XXX.XXX.XXX.69:1093
> 2011-04-04 10:13:39,371 - INFO  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn@777][] - Client 
> attempting to establish new session at /XXX.XXX.XXX.69:1093
> 2011-04-04 10:13:39,376 - INFO  [CommitProcessor:1:NIOServerCnxn@1580][] - 
> Established session 0x12ee79c4a720022 with negotiated timeout 20000 for 
> client /XXX.XXX.XXX.69:1093
> 2011-04-04 12:04:11,131 - INFO  [SyncThread:1:FileTxnLog@197][] - Creating 
> new log file: log.170053bf15
> 2011-04-04 12:04:11,131 - INFO  [Snapshot Thread:FileTxnSnapLog@208][] - 
> Snapshotting: 170053bf17
> 2011-04-04 12:13:10,779 - INFO  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@251][] - 
> Accepted socket connection from /XXX.XXX.XXX.63:1817
> 2011-04-04 12:13:10,790 - INFO  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn@777][] - Client 
> attempting to establish new session at /XXX.XXX.XXX.63:1817
> 2011-04-04 12:13:10,794 - INFO  [CommitProcessor:1:NIOServerCnxn@1580][] - 
> Established session 0x12ee79c4a720023 with negotiated timeout 20000 for 
> client /XXX.XXX.XXX.63:1817
> 2011-04-04 12:13:10,814 - WARN  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn@634][] - 
> EndOfStreamException: Unable to read additional data from client sessionid 
> 0x12ee79c4a720023, likely client has closed socket
> 2011-04-04 12:13:10,816 - INFO  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn@1435][] - Closed 
> socket connection for client /XXX.XXX.XXX.63:1817 which had sessionid 
> 0x12ee79c4a720023
> 2011-04-04 12:13:10,839 - INFO  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@251][] - 
> Accepted socket connection from /XXX.XXX.XXX.63:1814
> 2011-04-04 12:13:10,840 - WARN  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@274][] - 
> Ignoring exception
> java.net.SocketException: Invalid argument
>         at sun.nio.ch.Net.setIntOption0(Native Method)
>         at sun.nio.ch.Net.setIntOption(Unknown Source)
>         at sun.nio.ch.SocketChannelImpl$1.setInt(Unknown Source)
>         at sun.nio.ch.SocketOptsImpl.setBoolean(Unknown Source)
>         at sun.nio.ch.SocketOptsImpl$IP$TCP.noDelay(Unknown Source)
>         at sun.nio.ch.OptionAdaptor.setTcpNoDelay(Unknown Source)
>         at sun.nio.ch.SocketAdaptor.setTcpNoDelay(Unknown Source)
>         at 
> org.apache.zookeeper.server.NIOServerCnxn.<init>(NIOServerCnxn.java:1367)
>         at 
> org.apache.zookeeper.server.NIOServerCnxn$Factory.createConnection(NIOServerCnxn.java:215)
>         at 
> org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:256)
> 2011-04-04 12:13:10,841 - WARN  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
> Ignoring unexpected runtime exception
> java.lang.NullPointerException
>         at 
> org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:244)
> 2011-04-04 12:13:10,841 - WARN  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
> Ignoring unexpected runtime exception
> java.lang.NullPointerException
>         at 
> org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:244)
> 2011-04-04 12:13:10,842 - WARN  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
> Ignoring unexpected runtime exception
> java.lang.NullPointerException
>         at 
> org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:244)
> ...
> ...
> ...
> 2011-04-04 16:49:23,101 - WARN  
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2301:NIOServerCnxn$Factory@272][] - 
> Ignoring unexpected runtime exception
> java.lang.NullPointerException
>         at 
> org.apache.zookeeper.server.NIOServerCnxn$Factory.run(NIOServerCnxn.java:244)
> {noformat}

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira


Reply via email to