[
https://issues.apache.org/jira/browse/KAFKA-1400?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14337452#comment-14337452
]
Gwen Shapira commented on KAFKA-1400:
-------------------------------------
.... and here are the logs :
{code}
[2015-02-25 15:11:10,002] INFO Awaiting socket connections on 0.0.0.0:52503.
(kafka.network.Acceptor:68)
[2015-02-25 15:11:10,007] INFO [Socket Server on Broker 0], Started
(kafka.network.SocketServer:68)
[2015-02-25 15:11:10,096] INFO Awaiting socket connections on 0.0.0.0:52504.
(kafka.network.Acceptor:68)
[2015-02-25 15:11:10,096] INFO [Socket Server on Broker 0], Started
(kafka.network.SocketServer:68)
wrote data to socket Socket[addr=localhost/127.0.0.1,port=52504,localport=52505]
[2015-02-25 15:11:10,111] DEBUG Accepted connection from /127.0.0.1 on
/127.0.0.1:52504. sendBufferSize [actual|requested]: [300000|300000]
recvBufferSize [actual|requested]: [310308|300000] (kafka.network.Acceptor:52)
[2015-02-25 15:11:10,114] TRACE Processor id 0 selection time = 17218000 ns
(kafka.network.Processor:36)
[2015-02-25 15:11:10,115] DEBUG Processor 0 listening to new connection from
/127.0.0.1:52505 (kafka.network.Processor:52)
[2015-02-25 15:11:10,115] TRACE Processor id 0 selection time = 36000 ns
(kafka.network.Processor:36)
[2015-02-25 15:11:10,121] TRACE 42 bytes read from /127.0.0.1:52505
(kafka.network.Processor:36)
[2015-02-25 15:11:10,160] TRACE Processor 1 received request : Name:
ProducerRequest; Version: 0; CorrelationId: 0; ClientId: ; RequiredAcks: 0;
AckTimeoutMs: 0 ms; TopicAndPartition: (kafka.network.RequestChannel$:36)
[2015-02-25 15:11:10,161] TRACE Processor 0 received request : Name:
ProducerRequest; Version: 0; CorrelationId: 0; ClientId: ; RequiredAcks: 0;
AckTimeoutMs: 0 ms; TopicAndPartition: (kafka.network.RequestChannel$:36)
[2015-02-25 15:11:10,165] TRACE Processor id 0 selection time = 3599000 ns
(kafka.network.Processor:36)
[2015-02-25 15:11:10,165] INFO [Socket Server on Broker 0], Shutting down
(kafka.network.SocketServer:68)
[2015-02-25 15:11:10,166] DEBUG Closing server socket and selector.
(kafka.network.Acceptor:52)
[2015-02-25 15:11:10,166] TRACE Socket server received response to send,
registering for write:
Response(0,Request(0,sun.nio.ch.SelectionKeyImpl@4328493c,null,1424905870123,/127.0.0.1:52505),kafka.network.BoundedByteBufferSend@318b1420,SendAction)
(kafka.network.Processor:36)
[2015-02-25 15:11:10,167] TRACE Processor id 0 selection time = 26000 ns
(kafka.network.Processor:36)
[2015-02-25 15:11:10,170] TRACE 22 bytes written to /127.0.0.1:52505 using key
sun.nio.ch.SelectionKeyImpl@4328493c (kafka.network.Processor:36)
[2015-02-25 15:11:10,170] DEBUG is socket
ServerSocket[addr=/0:0:0:0:0:0:0:0,localport=52504] closed? true
(kafka.network.Acceptor:52)
[2015-02-25 15:11:10,171] DEBUG Done shutting down acceptor.
(kafka.network.Acceptor:52)
[2015-02-25 15:11:10,231] TRACE Completed request:Name: ProducerRequest;
Version: 0; CorrelationId: 0; ClientId: ; RequiredAcks: 0; AckTimeoutMs: 0 ms;
TopicAndPartition: from client
/127.0.0.1:52505;totalTime:47,requestQueueTime:0,localTime:1424905870165,remoteTime:0,responseQueueTime:1,sendTime:5
(kafka.request.logger:85)
[2015-02-25 15:11:10,232] TRACE Finished writing, registering for read on
connection /127.0.0.1:52505 (kafka.network.Processor:36)
[2015-02-25 15:11:10,232] DEBUG Closing selector. (kafka.network.Processor:52)
[2015-02-25 15:11:10,233] DEBUG Closing connection from /127.0.0.1:52505
(kafka.network.Processor:52)
[2015-02-25 15:11:10,237] DEBUG done shutting down processor
(kafka.network.Processor:52)
[2015-02-25 15:11:10,237] INFO [Socket Server on Broker 0], SocketServer:
Shutdown completed (kafka.network.SocketServer:68)
wrote data to socket Socket[addr=localhost/127.0.0.1,port=52504,localport=52505]
- testSocketsCloseOnShutdown
{code}
Note that we successfully wrote to the socket (... the "wrote data" line is
logged after calling flush() and sending the request). This is with trunk code
(I added few extra log lines for clarity).
Are we sure that writing a single packet (we are not sending a lot of data) to
a server that did socket.close() is actually expected to fail?
Because it looks like this may not be the case:
http://stackoverflow.com/questions/11436013/writing-to-a-closed-local-tcp-socket-not-failing
> transient unit test failure in SocketServerTest
> -----------------------------------------------
>
> Key: KAFKA-1400
> URL: https://issues.apache.org/jira/browse/KAFKA-1400
> Project: Kafka
> Issue Type: Bug
> Components: core
> Affects Versions: 0.8.2.0
> Reporter: Jun Rao
> Assignee: Neha Narkhede
> Fix For: 0.8.2.0
>
> Attachments: KAFKA-1400.patch
>
>
> Saw the following transient failure.
> kafka.network.SocketServerTest > testSocketsCloseOnShutdown FAILED
> java.lang.AssertionError: Expected exception: java.net.SocketException
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
