After discussing with Deep, we realised that this is because my component
used the DataAccess component of the Cassandra feature to connect to the
Cassandra data store.
Since two bundles use the the DataAcess service, due to a fix done for
Stratos, the connection made by one bundle is closed before providing the
connection to the subsequent one, making the connection unusable afterwards.
The work around for this is to use the Hector client directly without using
the Carbon component, but I'm not sure whether the fix done is the correct
one.
Logs:
[2011-08-01 22:32:19,158] INFO
{org.wso2.carbon.bam.analyzer.test.SummaryAnalyzer1} - Super row :
Row(allKeys,ColumnSlice([HColumn(Mon Aug 01 00:00:00 IST
2011-3-2-4b6644ae-a2ee-4b66-a7fd-60aad0ad2c7d=), HColumn(Mon Aug 01 00:00:00
IST 2011-3-2-923b55bd-1635-4266-b971-b256105170b0=), HColumn(Mon Aug 01
01:00:00 IST 2011---3---2=), HColumn(Mon Aug 01 02:00:00 IST
2011---3---2=)]))
[2011-08-01 22:32:19,158] INFO
{org.wso2.carbon.bam.analyzer.test.SummaryAnalyzer1} - Super row : Row(Mon
Aug 01 00:00:00 IST
2011-3-2-923b55bd-1635-4266-b971-b256105170b0,ColumnSlice([HColumn(Sun Aug
01 00:33:26 IST 2011-127.0.0.1-b434c47f-2db7-4295-ad61-38f4ed212110=)]))
[2011-08-01 22:32:19,158] INFO
{org.wso2.carbon.bam.analyzer.test.SummaryAnalyzer1} - Number of entried in
Cassandra : 5
[2011-08-01 22:32:19,158] INFO
{org.wso2.carbon.bam.analyzer.test.SummaryAnalyzer2} - Summary Analyzer 2
executed
[2011-08-01 22:32:48,350] INFO
{me.prettyprint.cassandra.hector.TimingLogger} - start[1312218168331]
time[19] tag[META_READ.success_]
[2011-08-01 22:32:48,370] INFO
{me.prettyprint.cassandra.hector.TimingLogger} - start[1312218168355]
time[15] tag[META_READ.success_]
Suck It!
[2011-08-01 22:32:59,531] INFO
{org.wso2.carbon.bam.receiver.internal.QueueWorker} - 1 messages in queue
before pool-16-thread-1 worker has polled queue
*[2011-08-01 22:32:59,552] INFO
{me.prettyprint.cassandra.connection.HConnectionManager} - Shutdown called
on HConnectionManager*
*[2011-08-01 22:32:59,553] INFO
{me.prettyprint.cassandra.connection.CassandraHostRetryService} - Downed
Host retry shutdown hook called*
*[2011-08-01 22:32:59,556] INFO
{me.prettyprint.cassandra.connection.CassandraHostRetryService} - Downed
Host retry shutdown complete*
*[2011-08-01 22:32:59,556] ERROR
{me.prettyprint.cassandra.connection.NodeAutoDiscoverService} - Auto
Discovery retry shutdown hook called*
*[2011-08-01 22:32:59,558] ERROR
{me.prettyprint.cassandra.connection.NodeAutoDiscoverService} -
AutoDiscovery retry shutdown complete*
*[2011-08-01 22:32:59,562] ERROR
{me.prettyprint.cassandra.connection.ConcurrentHClientPool} - Shutdown
triggered on
<ConcurrentCassandraClientPoolByHost>:{localhost(127.0.0.1):9160}*
*[2011-08-01 22:32:59,588] ERROR
{me.prettyprint.cassandra.connection.ConcurrentHClientPool} - Shutdown
complete *on
<ConcurrentCassandraClientPoolByHost>:{localhost(127.0.0.1):9160}
[2011-08-01 22:32:59,588] INFO
{me.prettyprint.cassandra.connection.CassandraHostRetryService} - Downed
Host Retry service started with queue size 3 and retry delay 10s
[2011-08-01 22:32:59,620] INFO
{me.prettyprint.cassandra.hector.TimingLogger} - start[1312218179605]
time[15] tag[META_READ.success_]
[2011-08-01 22:32:59,660] INFO
{me.prettyprint.cassandra.hector.TimingLogger} - start[1312218179625]
time[35] tag[WRITE.success_]
[2011-08-01 22:32:59,685] INFO
{me.prettyprint.cassandra.hector.TimingLogger} - start[1312218179661]
time[24] tag[WRITE.success_]
[2011-08-01 22:32:59,703] INFO
{me.prettyprint.cassandra.hector.TimingLogger} - start[1312218179686]
time[16] tag[WRITE.success_]
[2011-08-01 22:32:59,732] INFO
{me.prettyprint.cassandra.hector.TimingLogger} - start[1312218179703]
time[29] tag[WRITE.success_]
[2011-08-01 22:32:59,759] INFO
{me.prettyprint.cassandra.hector.TimingLogger} - start[1312218179732]
time[27] tag[WRITE.success_]
[2011-08-01 22:32:59,760] INFO
{org.wso2.carbon.bam.receiver.internal.QueueWorker} - 0 messages in queue
after pool-16-thread-1 worker has finished work
[2011-08-01 22:33:01,021] INFO
{org.wso2.carbon.bam.analyzer.test.SummaryAnalyzer1} - Summary Analyzer 1
started
[2011-08-01 22:33:01,022] INFO
{me.prettyprint.cassandra.hector.TimingLogger} - start[1312218181022]
time[0] tag[READ.fail_]
[2011-08-01 22:33:01,024] ERROR {org.quartz.core.JobRunShell} - Job
synapse.simple.quartz.testSequence threw an unhandled Exception:
me.prettyprint.hector.api.exceptions.HectorException: General exception in
getClientFromLBPolicy
at
me.prettyprint.cassandra.connection.HConnectionManager.getClientFromLBPolicy(HConnectionManager.java:231)
at
me.prettyprint.cassandra.connection.HConnectionManager.operateWithFailover(HConnectionManager.java:149)
at
me.prettyprint.cassandra.service.KeyspaceServiceImpl.operateWithFailover(KeyspaceServiceImpl.java:129)
at
me.prettyprint.cassandra.service.KeyspaceServiceImpl.getRangeSlices(KeyspaceServiceImpl.java:165)
at
me.prettyprint.cassandra.model.thrift.ThriftRangeSlicesQuery$1.doInKeyspace(ThriftRangeSlicesQuery.java:67)
at
me.prettyprint.cassandra.model.thrift.ThriftRangeSlicesQuery$1.doInKeyspace(ThriftRangeSlicesQuery.java:63)
at
me.prettyprint.cassandra.model.KeyspaceOperationCallback.doInKeyspaceAndMeasure(KeyspaceOperationCallback.java:20)
at
me.prettyprint.cassandra.model.ExecutingKeyspace.doExecute(ExecutingKeyspace.java:72)
at
me.prettyprint.cassandra.model.thrift.ThriftRangeSlicesQuery.execute(ThriftRangeSlicesQuery.java:62)
at
org.wso2.carbon.bam.analyzer.test.SummaryAnalyzer1.analyze(SummaryAnalyzer1.java:64)
at
org.wso2.carbon.bam.analyzer.task.AnalyzerJob.execute(AnalyzerJob.java:39)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
Caused by: me.prettyprint.hector.api.exceptions.HectorException: Attempt to
borrow on in-active pool:
<ConcurrentCassandraClientPoolByHost>:{localhost(127.0.0.1):9160}
at
me.prettyprint.cassandra.connection.ConcurrentHClientPool.borrowClient(ConcurrentHClientPool.java:57)
at
me.prettyprint.cassandra.connection.HConnectionManager.getClientFromLBPolicy(HConnectionManager.java:229)
... 12 more
[2011-08-01 22:33:01,030] ERROR {org.quartz.core.ErrorLogger} - Job
(synapse.simple.quartz.testSequence threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception. [See nested
exception: me.prettyprint.hector.api.exceptions.HectorException: General
exception in getClientFromLBPolicy]
at org.quartz.core.JobRunShell.run(JobRunShell.java:213)
at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
Caused by: me.prettyprint.hector.api.exceptions.HectorException: General
exception in getClientFromLBPolicy
at
me.prettyprint.cassandra.connection.HConnectionManager.getClientFromLBPolicy(HConnectionManager.java:231)
at
me.prettyprint.cassandra.connection.HConnectionManager.operateWithFailover(HConnectionManager.java:149)
at
me.prettyprint.cassandra.service.KeyspaceServiceImpl.operateWithFailover(KeyspaceServiceImpl.java:129)
at
me.prettyprint.cassandra.service.KeyspaceServiceImpl.getRangeSlices(KeyspaceServiceImpl.java:165)
at
me.prettyprint.cassandra.model.thrift.ThriftRangeSlicesQuery$1.doInKeyspace(ThriftRangeSlicesQuery.java:67)
at
me.prettyprint.cassandra.model.thrift.ThriftRangeSlicesQuery$1.doInKeyspace(ThriftRangeSlicesQuery.java:63)
at
me.prettyprint.cassandra.model.KeyspaceOperationCallback.doInKeyspaceAndMeasure(KeyspaceOperationCallback.java:20)
at
me.prettyprint.cassandra.model.ExecutingKeyspace.doExecute(ExecutingKeyspace.java:72)
at
me.prettyprint.cassandra.model.thrift.ThriftRangeSlicesQuery.execute(ThriftRangeSlicesQuery.java:62)
at
org.wso2.carbon.bam.analyzer.test.SummaryAnalyzer1.analyze(SummaryAnalyzer1.java:64)
at
org.wso2.carbon.bam.analyzer.task.AnalyzerJob.execute(AnalyzerJob.java:39)
at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
... 1 more
Caused by: me.prettyprint.hector.api.exceptions.HectorException: Attempt to
borrow on in-active pool:
<ConcurrentCassandraClientPoolByHost>:{localhost(127.0.0.1):9160}
at
me.prettyprint.cassandra.connection.ConcurrentHClientPool.borrowClient(ConcurrentHClientPool.java:57)
at
me.prettyprint.cassandra.connection.HConnectionManager.getClientFromLBPolicy(HConnectionManager.java:229)
... 12 more
On Mon, Aug 1, 2011 at 8:11 AM, Deependra Ariyadewa <[email protected]> wrote:
>
>
> On Mon, Aug 1, 2011 at 2:00 AM, Tharindu Mathew <[email protected]> wrote:
>
>> Noticed that this happens, if I make writes and reads after getting
>> connections separately. It is easily reproducible.
>>
>> Maybe, this is related connection params. Any help would be appreciated.
>>
>
> I'll look in to this issue. Is there any app or code sample that I can run
> to reproduce this issue.
>
> Thanks,
>
> Deependra.
>
>
>>
>>
>> On Mon, Aug 1, 2011 at 12:51 AM, Tharindu Mathew <[email protected]>wrote:
>>
>>> From the 3.2.1 Cassandra component, I sometimes get this exception.
>>>
>>> Is this due to a timeout?
>>>
>>> [2011-08-01 00:49:32,574] ERROR
>>> {me.prettyprint.cassandra.connection.NodeAutoDiscoverService} - Error
>>> getting nodes list for keyspace : BAMKeyspace
>>> me.prettyprint.hector.api.exceptions.HectorException: General exception
>>> in getClientFromLBPolicy
>>> at
>>> me.prettyprint.cassandra.connection.HConnectionManager.getClientFromLBPolicy(HConnectionManager.java:231)
>>> at
>>> me.prettyprint.cassandra.connection.HConnectionManager.operateWithFailover(HConnectionManager.java:149)
>>> at
>>> me.prettyprint.cassandra.service.ThriftCluster.describeRing(ThriftCluster.java:35)
>>> at
>>> me.prettyprint.cassandra.connection.NodeAutoDiscoverService.discoverNodes(NodeAutoDiscoverService.java:102)
>>> at
>>> me.prettyprint.cassandra.connection.NodeAutoDiscoverService$QueryRing.run(NodeAutoDiscoverService.java:61)
>>> at
>>> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>>> at
>>> java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:317)
>>> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:150)
>>> at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:98)
>>> at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:181)
>>> at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:205)
>>> at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
>>> at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
>>> at java.lang.Thread.run(Thread.java:619)
>>> Caused by: me.prettyprint.hector.api.exceptions.HectorException: Attempt
>>> to borrow on in-active pool:
>>> <ConcurrentCassandraClientPoolByHost>:{localhost(127.0.0.1):9160}
>>> at
>>> me.prettyprint.cassandra.connection.ConcurrentHClientPool.borrowClient(ConcurrentHClientPool.java:57)
>>> at
>>> me.prettyprint.cassandra.connection.HConnectionManager.getClientFromLBPolicy(HConnectionManager.java:229)
>>> ... 13 more
>>>
>>>
>>> --
>>> Regards,
>>>
>>> Tharindu
>>>
>>>
>>
>>
>> --
>> Regards,
>>
>> Tharindu
>>
>>
>> _______________________________________________
>> Carbon-dev mailing list
>> [email protected]
>> http://mail.wso2.org/cgi-bin/mailman/listinfo/carbon-dev
>>
>>
>
>
> --
> Deependra Ariyadewa
> WSO2, Inc.; http://wso2.com/
> email: [email protected]; cell: +94 71 403 5996 ;
> PGP info: KeyID: 'DC627E6F'
>
>
> _______________________________________________
> Carbon-dev mailing list
> [email protected]
> http://mail.wso2.org/cgi-bin/mailman/listinfo/carbon-dev
>
>
--
Regards,
Tharindu
_______________________________________________
Carbon-dev mailing list
[email protected]
http://mail.wso2.org/cgi-bin/mailman/listinfo/carbon-dev
