Thank you very much for your replay~
The full message like this:
DEBUG [Thread-6] 2012-04-24 21:04:11,024 IncomingTcpConnection.java (line
116) Version is now 3
During "blocking time" I only saw this message(*appendix shown) *and seems
everything is blocked.
I logged all cassandra calling time in RPC and there is no large delay but
RPC itself delay a lot.
I also using JConsole to monitor the GC time (both cassandra and RPC
server) and didn't find large GC delay.
Is my OS blocked during that time?
I also list tpstats as well as compactionstats in the Appendix. Are there
something wrong with my cassandra?
Thank you very much for your help again :)
*Appendix:*
*cassandra debug output block:*
DEBUG [Thread-6] 2012-04-24 21:04:11,024 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-7] 2012-04-24 21:04:11,430 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-7] 2012-04-24 21:04:11,431 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:11,901 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:11,902 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:12,024 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-7] 2012-04-24 21:04:12,431 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-7] 2012-04-24 21:04:12,431 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:13,024 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:13,750 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:13,751 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-7] 2012-04-24 21:04:14,025 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:14,902 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:14,902 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:15,025 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:15,751 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:15,751 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:16,025 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-7] 2012-04-24 21:04:16,431 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-7] 2012-04-24 21:04:16,432 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:16,902 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:16,903 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-7] 2012-04-24 21:04:17,025 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:18,025 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:18,902 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:18,903 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-7] 2012-04-24 21:04:19,026 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:19,752 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:19,752 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:19,903 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:19,903 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:20,026 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:20,752 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-6] 2012-04-24 21:04:20,752 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-7] 2012-04-24 21:04:21,026 IncomingTcpConnection.java (line
116) Version is now 3
DEBUG [Thread-4] 2012-04-24 21:04:22,026 IncomingTcpConnection.java (line
116) Version is now 3
*tpstats:*
Pool Name Active Pending Completed Blocked All
time blocked
ReadStage 0 0 171002 0
0
RequestResponseStage 0 0 1016620 0
0
MutationStage 0 0 278581 0
0
ReadRepairStage 0 0 0 0
0
ReplicateOnWriteStage 0 0 0 0
0
GossipStage 0 0 1123513 0
0
AntiEntropyStage 0 0 0 0
0
MigrationStage 0 0 0 0
0
MemtablePostFlusher 0 0 23 0
0
StreamStage 0 0 0 0
0
FlushWriter 0 0 23 0
0
MiscStage 0 0 0 0
0
InternalResponseStage 0 0 0 0
0
HintedHandoff 0 0 0 0
0
Message type Dropped
RANGE_SLICE 0
READ_REPAIR 0
BINARY 0
READ 0
MUTATION 0
REQUEST_RESPONSE 0
*compactionstats:*
pending tasks: 0
2012/4/24 Maki Watanabe <watanabe.m...@gmail.com>
> If you set trace level for IncomingTCPConnection, the message "Version
> is now ..." will be printed for every inter-cassandra message received
> by the node, including Gossip.
> Enabling this log in high traffic will saturate IO for your log disk by
> itself.
>
> You should better to inspect nodetool tpstats, compactionstats at first.
>
> maki
>
> 2012/4/24 马超 <hossc...@gmail.com>:
> > Does any one have idea for this? Thanks~
> >
> >
> > 2012/4/24 马超 <hossc...@gmail.com>
> >>
> >> Hi all,
> >>
> >> I have some troubles of cassandra in my production:
> >>
> >> I build up a RPC server which using hector client to manipulate the
> >> cassandra. Wired things happen nowadays: the latency of RPC sometimes
> >> becames very high (10seconds~70seconds) in several minutes and reduce
> >> to normal level (30ms in average) after that time. I investigate the
> >> debug log of cassandra. During high latency time, the cassandra output
> >> lots of message like:
> >> "IncomingTcpConnection.java(116) Version is now 3. "
> >> Seems everything be blocked during that time.
> >>
> >> Our settings as following:
> >> The version of cassandra is 1.0.1 and hector version is 0.7.0 for the
> >> compatible of thrift version which we use (0.5.0)
> >> The cluster contains 4 nodes and all of them are seeds. The
> >> gcgraceseconds is 0 since we needn't delete the data
> >>
> >> p.s. It works well for a long time (3 months) but becames crazy these
> >> days after we push the new RPC server which supports bigger data
> >> saving (2mb in average). I'm not sure if these is the reason.
> >>
> >> Hope getting your replay~~
> >>
> >> Thanks,
> >>
> >> Chao.
> >
> >
>
