This issue is caused by my network. Cassandra maintains multiple gossip connections per node pair. One of these connections is used for heartbeat and load broadcasting traffic. Its quite talky. Another one is used for distributed key reads. Its idle unless distributed keys are actively being sought.
So if your switches are configured to drop conns in an impolite way as a defense against flooding, and maybe the default is 3 hours or 4hrs 15 minutes, then you can run into my behavior. Thanks all for your attention and advice. AJ On Sat, Jun 19, 2010 at 8:16 PM, AJ Slater <a...@zuno.com> wrote: > The only indication I have that cassandra realized something was wrong > during this period was this INFO message: > > 10.33.2.70:/var/log/cassandra/output.log > > DEBUG 20:00:35,841 get_slice > DEBUG 20:00:35,841 weakreadremote reading > SliceFromReadCommand(table='jolitics.c > om', key='4c43228354b38f14a1a015dd722cdf4b', > column_parent='QueryPath(columnFami > lyName='Images', superColumnName='null', columnName='null')', start='', > finish=' > ', reversed=false, count=100) > DEBUG 20:00:35,841 weakreadremote reading > SliceFromReadCommand(table='jolitics.c > om', key='4c43228354b38f14a1a015dd722cdf4b', > column_parent='QueryPath(columnFami > lyName='Images', superColumnName='null', columnName='null')', start='', > finish=' > ', reversed=false, count=100) from 60999@/10.33.3.10 > INFO 20:00:35,842 error writing to /10.33.3.10 > TRACE 20:00:36,267 Received a GossipDigestSynMessage from /10.33.3.10 > TRACE 20:00:36,267 reporting /10.33.3.10 > TRACE 20:00:36,267 reporting /10.33.3.10 > > > Where it notes there's an error. The next read I did at 20:02, while > writing my last mail to this list, succeeded. > > So, its timing out, but al the while sending heartbeats and > GossipDIgestSyns and Acks back and forth and maybe not really querying > its peers when it should, or timing out trying to do so. When it > finally realizes theres an error, it resets something? And then we're > back in business? > > I'm going to be offline for 48 hours. > > AJ > > On Sat, Jun 19, 2010 at 8:09 PM, AJ Slater <a...@zuno.com> wrote: >> Agreed. But those connection errors were happening at a sort of random >> time. Not the time when I was seeing the problem. Now I am seeing the >> problem and here are some logs without ConnectionExceptions. >> >> Here we're asking 10.33.2.70 for key: 52e86817a577f75e545cdecd174d8b17 >> which resides only on 10.33.3.10 and 10.33.3.20. Note all the >> apparently normal communication. Execept that no mention of a request >> for key 52e86817a577f75e545cdecd174d8b17 ever comes up in 10.33.3.10's >> log, despite 10.33.2.70 saying it was reading from 10.33.3.10 >> >> The problem resolved itself again at 20:02, maybe 20 minutes later. >> where all of a sudden I get my columns returned in milliseconds and I >> see good stuff like: >> >> DEBUG 20:06:35,238 Reading consistency digest for >> 52e86817a577f75e545cdecd174d8b17 from 59...@[/10.33.3.10, /10.33.3.20] >> >> Here's some logs from the problem period >> >> 10.33.2.70:/var/log/cassandra/output.log >> >> DEBUG 19:42:03,230 get_slice >> DEBUG 19:42:03,231 weakreadremote reading >> SliceFromReadCommand(table='jolitics.c >> om', key='52e86817a577f75e545cdecd174d8b17', >> column_parent='QueryPath(columnFami >> lyName='Images', superColumnName='null', columnName='null')', start='', >> finish=' >> ', reversed=false, count=100) >> DEBUG 19:42:03,231 weakreadremote reading >> SliceFromReadCommand(table='jolitics.c >> om', key='52e86817a577f75e545cdecd174d8b17', >> column_parent='QueryPath(columnFami >> lyName='Images', superColumnName='null', columnName='null')', start='', >> finish=' >> ', reversed=false, count=100) from 57663@/10.33.3.10 >> TRACE 19:42:03,619 Gossip Digests are : /10.33.2.70:1276981671:20386 >> /10.33.3.10 >> :1276983719:18303 /10.33.3.20:1276983726:18295 /10.33.2.70:1276981671:20386 >> TRACE 19:42:03,619 Sending a GossipDigestSynMessage to /10.33.3.20 ... >> TRACE 19:42:03,619 Performing status check ... >> TRACE 19:42:03,619 PHI for /10.33.3.10 : 0.95343619570936 >> TRACE 19:42:03,619 PHI for /10.33.3.20 : 0.8635116192106644 >> TRACE 19:42:03,621 Received a GossipDigestAckMessage from /10.33.3.20 >> TRACE 19:42:03,621 reporting /10.33.3.10 >> TRACE 19:42:03,621 reporting /10.33.3.20 >> TRACE 19:42:03,621 marking as alive /10.33.3.10 >> TRACE 19:42:03,621 Updating heartbeat state version to 18304 from 18303 for >> /10. >> 33.3.10 ... >> TRACE 19:42:03,621 marking as alive /10.33.3.20 >> TRACE 19:42:03,621 Updating heartbeat state version to 18296 from 18295 for >> /10. >> 33.3.20 ... >> TRACE 19:42:03,622 Scanning for state greater than 20385 for /10.33.2.70 >> TRACE 19:42:03,622 Scanning for state greater than 20385 for /10.33.2.70 >> TRACE 19:42:03,622 Sending a GossipDigestAck2Message to /10.33.3.20 >> TRACE 19:42:04,172 Received a GossipDigestSynMessage from /10.33.3.10 >> TRACE 19:42:04,172 reporting /10.33.3.10 >> TRACE 19:42:04,172 reporting /10.33.3.10 >> TRACE 19:42:04,172 Scanning for state greater than 20385 for /10.33.2.70 >> TRACE 19:42:04,172 @@@@ Size of GossipDigestAckMessage is 52 >> TRACE 19:42:04,172 Sending a GossipDigestAckMessage to /10.33.3.10 >> TRACE 19:42:04,174 Received a GossipDigestAck2Message from /10.33.3.10 >> TRACE 19:42:04,174 reporting /10.33.3.10 >> TRACE 19:42:04,174 marking as alive /10.33.3.10 >> TRACE 19:42:04,174 Updating heartbeat state version to 18305 from 18304 for >> /10. >> 33.3.10 ... >> >> >> 10.33.3.10:/var/log/cassandra/output.log >> >> TRACE 19:42:03,174 Sending a GossipDigestSynMessage to /10.33.3.20 ... >> TRACE 19:42:03,174 Performing status check ... >> TRACE 19:42:03,174 PHI for /10.33.2.70 : 1.3363463863632534 >> TRACE 19:42:03,174 PHI for /10.33.3.20 : 0.9297110501502452 >> TRACE 19:42:03,175 Received a GossipDigestAckMessage from /10.33.3.20 >> TRACE 19:42:03,176 reporting /10.33.2.70 >> TRACE 19:42:03,176 marking as alive /10.33.2.70 >> TRACE 19:42:03,176 Updating heartbeat state version to 20385 from 20384 for >> /10. >> 33.2.70 ... >> TRACE 19:42:03,176 Scanning for state greater than 18303 for /10.33.3.10 >> TRACE 19:42:03,176 Scanning for state greater than 18303 for /10.33.3.10 >> TRACE 19:42:03,176 Sending a GossipDigestAck2Message to /10.33.3.20 >> TRACE 19:42:03,230 Received a GossipDigestSynMessage from /10.33.3.20 >> TRACE 19:42:03,230 reporting /10.33.3.20 >> TRACE 19:42:03,231 reporting /10.33.3.20 >> TRACE 19:42:03,231 @@@@ Size of GossipDigestAckMessage is 35 >> TRACE 19:42:03,231 Sending a GossipDigestAckMessage to /10.33.3.20 >> TRACE 19:42:03,232 Received a GossipDigestAck2Message from /10.33.3.20 >> TRACE 19:42:03,232 reporting /10.33.3.20 >> TRACE 19:42:03,232 marking as alive /10.33.3.20 >> TRACE 19:42:03,232 Updating heartbeat state version to 18296 from 18295 for >> /10. >> 33.3.20 ... >> TRACE 19:42:04,173 Gossip Digests are : /10.33.3.10:1276983719:18305 >> /10.33.2.70 >> >> >> >> 10.33.3.20:/var/log/cassandra/output.log >> >> TRACE 19:42:03,174 Received a GossipDigestSynMessage from /10.33.3.10 >> TRACE 19:42:03,174 reporting /10.33.3.10 >> TRACE 19:42:03,174 reporting /10.33.3.10 >> TRACE 19:42:03,174 Scanning for state greater than 20384 for /10.33.2.70 >> TRACE 19:42:03,175 @@@@ Size of GossipDigestAckMessage is 52 >> TRACE 19:42:03,175 Sending a GossipDigestAckMessage to /10.33.3.10 >> TRACE 19:42:03,176 Received a GossipDigestAck2Message from /10.33.3.10 >> TRACE 19:42:03,176 reporting /10.33.3.10 >> TRACE 19:42:03,177 marking as alive /10.33.3.10 >> TRACE 19:42:03,177 Updating heartbeat state version to 18304 from 18303 for >> /10. >> 33.3.10 ... >> TRACE 19:42:03,229 Gossip Digests are : /10.33.3.20:1276983726:18296 >> /10.33.3.10 >> :1276983719:18304 /10.33.3.20:1276983726:18296 /10.33.2.70:1276981671:20385 >> TRACE 19:42:03,229 Sending a GossipDigestSynMessage to /10.33.3.10 ... >> TRACE 19:42:03,229 Performing status check ... >> TRACE 19:42:03,229 PHI for /10.33.2.70 : 0.5938079948279411 >> TRACE 19:42:03,229 PHI for /10.33.3.10 : 0.045531699282787594 >> TRACE 19:42:03,231 Received a GossipDigestAckMessage from /10.33.3.10 >> TRACE 19:42:03,231 Scanning for state greater than 18295 for /10.33.3.20 >> TRACE 19:42:03,231 Scanning for state greater than 18295 for /10.33.3.20 >> TRACE 19:42:03,232 Sending a GossipDigestAck2Message to /10.33.3.10 >> TRACE 19:42:03,622 Received a GossipDigestSynMessage from /10.33.2.70 >> TRACE 19:42:03,622 reporting /10.33.2.70 >> TRACE 19:42:03,622 reporting /10.33.2.70 >> TRACE 19:42:03,622 Scanning for state greater than 18295 for /10.33.3.20 >> TRACE 19:42:03,623 Scanning for state greater than 18303 for /10.33.3.10 >> TRACE 19:42:03,623 @@@@ Size of GossipDigestAckMessage is 69 >> TRACE 19:42:03,623 Sending a GossipDigestAckMessage to /10.33.2.70 >> TRACE 19:42:03,625 Received a GossipDigestAck2Message from /10.33.2.70 >> TRACE 19:42:03,625 reporting /10.33.2.70 >> TRACE 19:42:03,625 marking as alive /10.33.2.70 >> TRACE 19:42:03,625 Updating heartbeat state version to 20386 from 20385 for >> /10. >> 33.2.70 ... >> TRACE 19:42:04,229 Gossip Digests are : /10.33.3.20:1276983726:18297 >> /10.33.2.70 >> :1276981671:20386 /10.33.3.10:1276983719:18304 /10.33.3.20:1276983726:18297 >> TRACE 19:42:04,229 Sending a GossipDigestSynMessage to /10.33.3.10 ... >> TRACE 19:42:04,229 Performing status check ... >> >> >> AJ >> >> On Sat, Jun 19, 2010 at 7:02 PM, Jonathan Ellis <jbel...@gmail.com> wrote: >>> This is definitely not a Cassandra bug, something external is causing >>> those connection failures. >>> >>> On Sat, Jun 19, 2010 at 3:12 PM, AJ Slater <a...@zuno.com> wrote: >>>> Logging with TRACE reveals immediate problems with no client requests >>>> coming in to the servers. The problem was immediate and persisted over >>>> the course of half an hour: >>>> >>>> 10.33.2.70 lpc03 >>>> 10.33.3.10 fs01 >>>> 10.33.3.20 fs02 >>>> >>>> a...@lpc03:~$ grep unable /var/log/cassandra/output.log >>>> TRACE 14:07:52,104 unable to connect to /10.33.3.10 >>>> ... >>>> TRACE 14:42:00,008 unable to connect to /10.33.3.20 >>>> ... >>>> TRACE 14:42:06,751 unable to connect to /10.33.3.20 >>>> >>>> Note that lpc03 has trouble talking to fs01 and fs02. But after After >>>> seeing this I started logging TRACE on fs01 and fs02. >>>> >>>> During the six seconds before I restarted fs02: >>>> >>>> a...@fs01:~/logs$ grep unable /var/log/cassandra/output.log | grep unable >>>> Bad configuration; unable to start server >>>> TRACE 14:42:00,865 unable to connect to /10.33.3.20 >>>> ... >>>> TRACE 14:42:06,730 unable to connect to /10.33.3.20 >>>> >>>> Restarted fs02 and no issues in any of the logs. >>>> >>>> a...@fs02:~$ grep unable /var/log/cassandra/output.log >>>> a...@fs02:~$ >>>> >>>> >>>> >>>> The unfiltered log messages all look more like: >>>> >>>> TRACE 14:42:06,248 unable to connect to /10.33.3.20 >>>> java.net.ConnectException: Connection refused >>>> at java.net.PlainSocketImpl.socketConnect(Native Method) >>>> at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333) >>>> at >>>> java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195) >>>> at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182) >>>> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366) >>>> at java.net.Socket.connect(Socket.java:529) >>>> at java.net.Socket.connect(Socket.java:478) >>>> at java.net.Socket.<init>(Socket.java:375) >>>> at java.net.Socket.<init>(Socket.java:276) >>>> at >>>> org.apache.cassandra.net.OutboundTcpConnection.connect(OutboundTcpCon >>>> nection.java:149) >>>> at >>>> org.apache.cassandra.net.OutboundTcpConnection.run(OutboundTcpConnect >>>> ion.java:85) >>>> >>>> >>>> On Sat, Jun 19, 2010 at 2:19 PM, AJ Slater <a...@zuno.com> wrote: >>>>> I shall do just that. I did a bunch of tests this morning and the >>>>> situation appears to be this: >>>>> >>>>> I have three nodes A, B and C, with RF=2. I understand now why this >>>>> issue wasn't apparent with RF=3. >>>>> >>>>> If there are regular intranode column requests going on (e.g. i set up >>>>> a pinger to get remote columns), the cluster functions normally. >>>>> However, if no intranode column requests happen for a few hours, (3 >>>>> hours is the minimum I've seen, but sometimes it takes longer), things >>>>> go wrong. Using node A as the point of contact from the client, all >>>>> columns that live on A are returned in a timely fashion, but for >>>>> columns that only live on B & C, the retrieval times out, with this in >>>>> the log: >>>>> >>>>> INFO 13:13:28,345 error writing to /10.33.3.20 >>>>> >>>>> No request for replicas, or consistency checks are seen in the logs of >>>>> B & C at this time. Using 'nodetool ring' from each of the three nodes >>>>> shows all nodes as Up. Telnet from A to B on port 7000 connects. >>>>> Tcpdump logs look like, at first glance, that gossip communication, >>>>> perhaps heartbeats, are proceeding normally, but I haven't really >>>>> analyzed them. >>>>> >>>>> Fifteen minutes later, the cluster decided to behave normally again. >>>>> Everyone talks to each other like buddies and delivers columns fast an >>>>> regularly. >>>>> >>>>> This is really looking like a Cassandra bug. I'll report back with my >>>>> TRACE log later and I expect I'll be opening a ticket. The confidence >>>>> level of my employer in my Cassandra solution to their petabyte data >>>>> storage project is... uh... well... it could be better. >>>>> >>>>> AJ >>>>> >>>>> >>>>> On Fri, Jun 18, 2010 at 8:16 PM, Jonathan Ellis <jbel...@gmail.com> wrote: >>>>>> set log level to TRACE and see if the OutboundTcpConnection is going >>>>>> bad. that would explain the message never arriving. >>>>>> >>>>>> On Fri, Jun 18, 2010 at 10:39 AM, AJ Slater <a...@zuno.com> wrote: >>>>>>> To summarize: >>>>>>> >>>>>>> If a request for a column comes in *after a period of several hours >>>>>>> with no requests*, then the node servicing the request hangs while >>>>>>> looking for its peer rather than servicing the request like it should. >>>>>>> It then throws either a TimedOutException or a (wrong) >>>>>>> NotFoundExeption. >>>>>>> >>>>>>> And it doen't appear to actually send the message it says it does to >>>>>>> its peer. Or at least its peer doesn't report the request being >>>>>>> received. >>>>>>> >>>>>>> And then the situation magically clears up after approximately 2 >>>>>>> minutes. >>>>>>> >>>>>>> However, if the idle period never occurs, then the problem does not >>>>>>> manifest. If I run a cron job with wget against my server every >>>>>>> minute, I do not see the problem. >>>>>>> >>>>>>> I'll be looking at some tcpdump logs to see if i can suss out what's >>>>>>> really happening, and perhaps file this as a bug. The several hours >>>>>>> between reproducible events makes this whole thing aggravating for >>>>>>> detection, debugging and I'll assume, fixing, if it is indeed a >>>>>>> cassandra problem. >>>>>>> >>>>>>> It was suggested on IRC that it may be my network. But gossip is >>>>>>> continually sending heartbeats and nodetool and the logs show the >>>>>>> nodes as up and available. If my network was flaking out I'd think it >>>>>>> would be dropping heartbeats and I'd see that. >>>>>>> >>>>>>> AJ >>>>>>> >>>>>>> On Thu, Jun 17, 2010 at 2:26 PM, AJ Slater <a...@zuno.com> wrote: >>>>>>>> These are physical machines. >>>>>>>> >>>>>>>> storage-conf.xml.fs03 is here: >>>>>>>> >>>>>>>> http://pastebin.com/weL41NB1 >>>>>>>> >>>>>>>> Diffs from that for the other two storage-confs are inline here: >>>>>>>> >>>>>>>> a...@worm:../Z3/cassandra/conf/dev$ diff storage-conf.xml.lpc03 >>>>>>>> storage-conf.xml.fs01 >>>>>>>> 185c185 >>>>>>>> >>>>>>>>> <InitialToken>71603818521973537678586548668074777838</InitialToken> >>>>>>>> 229c229 >>>>>>>> < <ListenAddress>10.33.2.70</ListenAddress> >>>>>>>> --- >>>>>>>>> <ListenAddress>10.33.3.10</ListenAddress> >>>>>>>> 241c241 >>>>>>>> < <ThriftAddress>10.33.2.70</ThriftAddress> >>>>>>>> --- >>>>>>>>> <ThriftAddress>10.33.3.10</ThriftAddress> >>>>>>>> 341c341 >>>>>>>> < <ConcurrentReads>16</ConcurrentReads> >>>>>>>> --- >>>>>>>>> <ConcurrentReads>4</ConcurrentReads> >>>>>>>> >>>>>>>> >>>>>>>> a...@worm:../Z3/cassandra/conf/dev$ diff storage-conf.xml.lpc03 >>>>>>>> storage-conf.xml.fs02 >>>>>>>> 185c185 >>>>>>>> < <InitialToken>0</InitialToken> >>>>>>>> --- >>>>>>>>> <InitialToken>120215585224964746744782921158327379306</InitialToken> >>>>>>>> 206d205 >>>>>>>> < <Seed>10.33.3.20</Seed> >>>>>>>> 229c228 >>>>>>>> < <ListenAddress>10.33.2.70</ListenAddress> >>>>>>>> --- >>>>>>>>> <ListenAddress>10.33.3.20</ListenAddress> >>>>>>>> 241c240 >>>>>>>> < <ThriftAddress>10.33.2.70</ThriftAddress> >>>>>>>> --- >>>>>>>>> <ThriftAddress>10.33.3.20</ThriftAddress> >>>>>>>> 341c340 >>>>>>>> < <ConcurrentReads>16</ConcurrentReads> >>>>>>>> --- >>>>>>>>> <ConcurrentReads>4</ConcurrentReads> >>>>>>>> >>>>>>>> >>>>>>>> Thank you for your attention, >>>>>>>> >>>>>>>> AJ >>>>>>>> >>>>>>>> >>>>>>>> On Thu, Jun 17, 2010 at 2:09 PM, Benjamin Black <b...@b3k.us> wrote: >>>>>>>>> Are these physical machines or virtuals? Did you post your >>>>>>>>> cassandra.in.sh and storage-conf.xml someplace? >>>>>>>>> >>>>>>>>> On Thu, Jun 17, 2010 at 10:31 AM, AJ Slater <a...@zuno.com> wrote: >>>>>>>>>> Total data size in the entire cluster is about twenty 12k images. >>>>>>>>>> With >>>>>>>>>> no other load on the system. I just ask for one column and I get >>>>>>>>>> these >>>>>>>>>> timeouts. Performing multiple gets on the columns leads to multiple >>>>>>>>>> timeouts for a period of a few seconds or minutes and then the >>>>>>>>>> situation magically resolves itself and response times are down to >>>>>>>>>> single digit milliseconds for a column get. >>>>>>>>>> >>>>>>>>>> On Thu, Jun 17, 2010 at 10:24 AM, AJ Slater <a...@zuno.com> wrote: >>>>>>>>>>> Cassandra 0.6.2 from the apache debian source. >>>>>>>>>>> Ubunutu Jaunty. Sun Java6 jvm. >>>>>>>>>>> >>>>>>>>>>> All nodes in separate racks at 365 main. >>>>>>>>>>> >>>>>>>>>>> On Thu, Jun 17, 2010 at 10:12 AM, AJ Slater <a...@zuno.com> wrote: >>>>>>>>>>>> I'm seing 10s timeouts on reads few times a day. Its hard to >>>>>>>>>>>> reproduce >>>>>>>>>>>> consistently but seems to happen most often after its been a long >>>>>>>>>>>> time >>>>>>>>>>>> between reads. After presenting itself for a couple minutes the >>>>>>>>>>>> problem then goes away. >>>>>>>>>>>> >>>>>>>>>>>> I've got a three node cluster with replication factor 2, reading at >>>>>>>>>>>> consistency level ONE. The columns being read are around 12k each. >>>>>>>>>>>> The >>>>>>>>>>>> nodes are 8GB multicore boxes with the JVM limits between 4GB and >>>>>>>>>>>> 6GB. >>>>>>>>>>>> >>>>>>>>>>>> Here's an application log from early this morning when a developer >>>>>>>>>>>> in >>>>>>>>>>>> Belgrade accessed the system: >>>>>>>>>>>> >>>>>>>>>>>> Jun 17 03:54:17 lpc03 pinhole[5736]: MainThread:pinhole.py:61 | >>>>>>>>>>>> Requested image_id: 5827067133c3d670071c17d9144f0b49 >>>>>>>>>>>> Jun 17 03:54:27 lpc03 pinhole[5736]: MainThread:pinhole.py:76 | >>>>>>>>>>>> TimedOutException for Image 5827067133c3d670071c17d9144f0b49 >>>>>>>>>>>> Jun 17 03:54:27 lpc03 pinhole[5736]: MainThread:zlog.py:105 | Image >>>>>>>>>>>> Get took 10005.388975 ms >>>>>>>>>>>> Jun 17 03:54:27 lpc03 pinhole[5736]: MainThread:pinhole.py:61 | >>>>>>>>>>>> Requested image_id: af8caf3b76ce97d13812ddf795104a5c >>>>>>>>>>>> Jun 17 03:54:27 lpc03 pinhole[5736]: MainThread:zlog.py:105 | Image >>>>>>>>>>>> Get took 3.658056 ms >>>>>>>>>>>> Jun 17 03:54:27 lpc03 pinhole[5736]: MainThread:zlog.py:105 | Image >>>>>>>>>>>> Transform took 0.978947 ms >>>>>>>>>>>> >>>>>>>>>>>> That's a Timeout and then a successful get of another column. >>>>>>>>>>>> >>>>>>>>>>>> Here's the cassandra log for 10.33.2.70: >>>>>>>>>>>> >>>>>>>>>>>> DEBUG 03:54:17,070 get_slice >>>>>>>>>>>> DEBUG 03:54:17,071 weakreadremote reading >>>>>>>>>>>> SliceFromReadCommand(table='jolitics.com', >>>>>>>>>>>> key='5827067133c3d670071c17d9144f0b49', >>>>>>>>>>>> column_parent='QueryPath(columnFamilyName='Images', >>>>>>>>>>>> superColumnName='null', columnName='null')', start='', finish=' >>>>>>>>>>>> ', reversed=false, count=100) >>>>>>>>>>>> DEBUG 03:54:17,071 weakreadremote reading >>>>>>>>>>>> SliceFromReadCommand(table='jolitics.com', >>>>>>>>>>>> key='5827067133c3d670071c17d9144f0b49', >>>>>>>>>>>> column_parent='QueryPath(columnFamilyName='Images', >>>>>>>>>>>> superColumnName='null', columnName='null')', start='', finish=' >>>>>>>>>>>> ', reversed=false, count=100) from 45138@/10.33.3.10 >>>>>>>>>>>> DEBUG 03:54:27,077 get_slice >>>>>>>>>>>> DEBUG 03:54:27,078 weakreadlocal reading >>>>>>>>>>>> SliceFromReadCommand(table='jolitics.com', >>>>>>>>>>>> key='af8caf3b76ce97d13812ddf795104a5c', >>>>>>>>>>>> column_parent='QueryPath(columnFamilyName='Images', >>>>>>>>>>>> superColumnName='null', columnName='null')', start='', finish='' >>>>>>>>>>>> , reversed=false, count=100) >>>>>>>>>>>> DEBUG 03:54:27,079 collecting body:false:1...@1275951327610885 >>>>>>>>>>>> DEBUG 03:54:27,080 collecting body:false:1...@1275951327610885 >>>>>>>>>>>> DEBUG 03:54:27,080 Reading consistency digest for >>>>>>>>>>>> af8caf3b76ce97d13812ddf795104a >>>>>>>>>>>> 5c from 45...@[/10.33.2.70, /10.33.3.10] >>>>>>>>>>>> DEBUG 03:54:50,779 Disseminating load info ... >>>>>>>>>>>> >>>>>>>>>>>> It looks like it asks for key='5827067133c3d670071c17d9144f0b49' >>>>>>>>>>>> from >>>>>>>>>>>> the local host and also queries 10.33.3.10 for the first one and >>>>>>>>>>>> then >>>>>>>>>>>> for 'af8caf3b76ce97d13812ddf795104a5c' it only queries the local >>>>>>>>>>>> host >>>>>>>>>>>> and then returns appropriately. >>>>>>>>>>>> >>>>>>>>>>>> Here's the log for 10.33.3.10 around that time: >>>>>>>>>>>> >>>>>>>>>>>> DEBUG 03:54:19,645 Disseminating load info ... >>>>>>>>>>>> DEBUG 03:55:19,645 Disseminating load info ... >>>>>>>>>>>> DEBUG 03:56:19,646 Disseminating load info ... >>>>>>>>>>>> DEBUG 03:57:19,645 Disseminating load info ... >>>>>>>>>>>> DEBUG 03:58:19,645 Disseminating load info ... >>>>>>>>>>>> DEBUG 03:59:19,646 Disseminating load info ... >>>>>>>>>>>> DEBUG 04:00:18,635 GC for ParNew: 4 ms, 21443128 reclaimed leaving >>>>>>>>>>>> 55875144 used; max is 6580535296 >>>>>>>>>>>> >>>>>>>>>>>> No record of communication from 10.33.2.70. >>>>>>>>>>>> >>>>>>>>>>>> Does this ring any bells for anyone? I can of course attach >>>>>>>>>>>> storage-conf's for all nodes if that sounds useful and I'll be on >>>>>>>>>>>> #cassandra as ajslater. >>>>>>>>>>>> >>>>>>>>>>>> Much thanks for taking a look and any suggestions. We fear we'll >>>>>>>>>>>> have >>>>>>>>>>>> to abandon Cassandra if this bug cannot be resolved. >>>>>>>>>>>> >>>>>>>>>>>> AJ >>>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>> >>>>>>>>> >>>>>>>> >>>>>>> >>>>>> >>>>>> >>>>>> >>>>>> -- >>>>>> Jonathan Ellis >>>>>> Project Chair, Apache Cassandra >>>>>> co-founder of Riptano, the source for professional Cassandra support >>>>>> http://riptano.com >>>>>> >>>>> >>>> >>> >>> >>> >>> -- >>> Jonathan Ellis >>> Project Chair, Apache Cassandra >>> co-founder of Riptano, the source for professional Cassandra support >>> http://riptano.com >>> >> >
