search

Comcast / cmb

This project is no longer actively supported. It is made available as read-only. A highly available, horizontally scalable queuing and notification service compatible with AWS SQS and SNS
Apache License 2.0
277 stars 50 forks source link

automatic confirmation of topic subscriptions required since v2.2.37 #30

Closed leemhenson closed 9 years ago

leemhenson commented 10 years ago

Since this change was introduced in 2.2.37:

https://github.com/Comcast/cmb/commit/03a33df819a8a0142507e2027ec3f8f5c5151663#diff-5829958bd782144c57434cdcdaf16cd0R168

it would appear that cqs subscriptions to topics are no longer able to receive messages published on the topic. According to the AWS docs, SQS subscriptions to SNS topics are automatically confirmed. It is only HTTP/HTTPS endpoints that require confirmation for the subscription. CMB version 2.2.36 emulated that behaviour, but now it is requiring every subscription to be confirmed.

FYI there is no subscription token sent in the response to the subscribe request, so even if I wanted to try to confirm my subscription I could not because I don't have the token I need to call confirmsubscription.

I guess either src/com/comcast/cns/controller/CNSPublishAction.java needs to check to see if the subscription is cqs queue, or that a config option is added to ignore checking of subscription confirmations?

I've already tried setting:

cmb.cns.requireSubscriptionConfirmation=false

in the config file without having any luck.

leemhenson commented 10 years ago

I know this isn't a proper fix for the issue, but I wanted to double-check that this definitely was the problem:

https://github.com/musicglue/cmb/commit/6eb93aa6bd7f21a7a46e85a8d4f74d46f46a45ad

Running my own build of 2.2.41 with that change means I can now receive messages into my queues again.

boriwo commented 10 years ago

Thank you for your report. We will investigate and fix this shortly.

boriwo commented 10 years ago

We have done some testing using the Web UI and couldn't reproduce your problem. Also, all the unit tests are passing and I'm pretty sure some of them rely on auto-subscription of cqs queues. Keep in mind though that only cqs queues created by the same user that created the topic will be auto-subscribed. If you have different users you still need to confirm! See here for the relevant code:

https://github.com/Comcast/cmb/blob/f00b890c9098d798f156fb2eb2a9d7af04e7a879/src/com/comcast/cns/persistence/CNSSubscriptionCassandraPersistence.java#L306-310

Also, setting requireSubscriptionConfirmation to false like you did should indeed auto-subscribe everything.

Are you testing this in a setup with more than one Redis shard? Reason that I'm asking is that we are currently working on a fix for a bug that can cause strange side effects when using multiple shards, including CQS messages not being delivered properly (see disucssion on our Google group for details).

leemhenson commented 10 years ago

If it helps, I can say that I've been using the ruby aws-sdk client:

https://github.com/aws/aws-sdk-core-ruby

along the lines of:

sqs.create_queue queue_name: queue_name
# wait for queue to exist
queue_url = sqs.get_queue_url(queue_name: queue_name).data.queue_url
queue_arn = sqs.get_queue_attributes(
  queue_url: queue_url,
  attribute_names: ['QueueArn']).attributes['QueueArn']

topic_arn = "arn:cmb:cns:ccp:#{cqs_user_id}:#{topic_name}"
subscription_arn = sns.subscribe(
  endpoint: queue_arn,
  protocol: 'cqs',
  topic_arn: topic_arn).subscription_arn
boriwo commented 10 years ago

If you can share the complete source code we can have a look to find out what's not working.

leemhenson commented 10 years ago

I just tried this again using the latest version on master. I wasn't able to subscribe my queue to the topic because I did not have sufficient permissions. I then added:

sns.add_permission topic_arn: "topic-arn", label: "new-permission", aws_account_id: ["cmb-user-id"], action_name: ['Subscribe']

before the call to sns.subscribe and it seems to be working well now.

leemhenson commented 9 years ago

Hmm. I'm reopening this because I think I got myself confused about two different issues, and the comment above was the solution to a different issue I was having. I've just tried again with f33ab38 and I still get this message (from https://github.com/Comcast/cmb/blob/master/src/com/comcast/cns/controller/CNSPublishAction.java#L166):

event=no_confirmed_subscribers action=publish topic_arn=<topic arn>

when I attempt to publish to a topic that has an unconfirmed subscription which was created with:

cmb.cns.requireSubscriptionConfirmation=false

in the config file.

I've added extra logging here:

https://github.com/Comcast/cmb/blob/f00b890c9098d798f156fb2eb2a9d7af04e7a879/src/com/comcast/cns/persistence/CNSSubscriptionCassandraPersistence.java#L287

to prove to myself that requireSubscriptionConfirmation=false is being honoured. It would appear that it is, so I believe the real issue here is that the subscriptionsConfirmed counter in the topic attributes is not being incremented in my scenario. A zero in that counter means this check succeeds when it shouldn't:

https://github.com/Comcast/cmb/blob/master/src/com/comcast/cns/controller/CNSPublishAction.java#L162

I can see this line being called:

https://github.com/Comcast/cmb/blob/f00b890c9098d798f156fb2eb2a9d7af04e7a879/src/com/comcast/cns/persistence/CNSSubscriptionCassandraPersistence.java#L290

so what else is missing?

boriwo commented 9 years ago

If I understand correctly you were expecting that setting requireSubscriptionConfirmation to false would auto-confirm already pending subscriptions that were created in the past. This is not the case: The change in your configuration only applies to future subscriptions. Existing subscriptions in pending confirmation state still have to be confirmed manually or deleted.

Also keep in mind that confirmations are really only an issue when topic and queue are created by different CMB users. If you can use a single CMB user all subscriptions will be auto-confirmed.

I just retested all possible scenarios (same user and different users with requireSubscriptionConfirmation turned on and off) and it was all working for me. I also added detailed descriptions to some common scenarios in

https://github.com/Comcast/cmb/blob/master/FAQ.txt

leemhenson commented 9 years ago

If I understand correctly you were expecting that setting requireSubscriptionConfirmation to false would auto-confirm already pending subscriptions that were created in the past.

No, I only use cmb for developing locally before I push code to production to run against AWS. I am deleting all queues and topics and rebuilding them from scratch many times a day. Since v2.2.37 I am unable to publish a message to a topic and have it delivered to a queue.

Also keep in mind that confirmations are really only an issue when topic and queue are created by different CMB users. If you can use a single CMB user all subscriptions will be auto-confirmed.

I using a single user account. I do not have multiple users.

I've created a branch that contains an executable ruby script that I hope will allow you to observe the behaviour I'm seeing:

  1. Check out https://github.com/musicglue/cmb/tree/issue-30
  2. mvn -Dmaven.test.skip=true assembly:assembly
  3. unpack target/cmb-blah.tar.gz somewhere and cd into it
  4. chmod 755 ./bin/cmb.sh
  5. bin/cmb.sh > /tmp/cmb.log 2>&1 &
  6. create a user account in the cmb web ui
  7. cd ./tests/ruby
  8. bundle install
  9. ACCESS_KEY="the new user's access key" SECRET_KEY="the new user's secret key" ruby ./test.rb
  10. grep no_confirmed_subscribers /tmp/cmb.log

Then you could check out https://github.com/musicglue/cmb/tree/unconfirmed-subscriptions and rerun the script. It now succeeds.

boriwo commented 9 years ago

I just ran your ruby script test.rb successfully without any changes. I could see your "test" message delivered to your queue via web ui. I ran your script multiple times and it worked each time.

All I had to do was add an entry to my /etc/hosts file to make sure eu-west-1.localhost is pointing to my cmb server (I used the latest version of CMB, not your fork but this should not make a difference).

This tells me that both are working, your ruby script as well as cmb.

I still suspect a cmb configuration issue in your setup. Looking at the steps above I wonder: Do you have Cassandra and Redis set up correctly? Does your cmb.properties point to Cassandra and Redis? Have you installed the correct version of the schema in your Cassandra (from time to time there are schema changes so you always need to use an up to date schema for cmb in Cassandra)? Even if you believe you have set up everything correctly it might still be a good idea to delete and recreate your schema in Cassandra for a fresh start.

Bottom line, if you cannot publish into a queue manually using webui (as described in the FAQ) then there is no chance your script could work.

You could also send me a complete cmb.log from the point the service starts until you run your script. Maybe this will explain what's happening for you.

Finally, if you don't mind I would like to add your ruby script as an example to our cmb repo. Or if you prefer you could also contribute it as a pull request if that's ok with you. Thanks!

leemhenson commented 9 years ago

Thanks for your patience with this one Boris! It's a bit spooky. :ghost:

I just did the following:

Creating topic: topic-1420626508
Creating queue: queue-1420626508
Subscribing: queue-1420626508 to topic-1420626508
Publishing to: topic-1420626508
Published message was not delivered to any subscribers. Check the cmb log output for "WARN  CNSPublishAction - event=no_confirmed_subscribers action=publish".

Publishing via the webui does not work either. I see the same no_confirmed_subscribers message in the logs.

I am running cassandra 2.1.2, redis 2.8.19.

Finally, if you don't mind I would like to add your ruby script as an example to our cmb repo.

Yeah no problem, go for it.

boriwo commented 9 years ago

Since I can't reproduce your problem in my environment, I'd still suggest you send me the complete cmb.log. If you delete any old cmb.log, restart the service and then run your ruby script the log should be relatively short. You can also email me directly at mail@boriswolf.com.

I will go ahead and create an example folder in cmb and place a copy of your ruby script there for future reference. Thank you!

leemhenson commented 9 years ago 
2015-01-07 18:48:41,688 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CMBProperties - event=loading_cmb_properties file=/Users/leemhenson/src/tools/cmb-broken/./config/cmb.properties
2015-01-07 18:48:41,696 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  Util - event=init_log4j file=./config/log4j.properties
2015-01-07 18:48:41,829 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  Server - jetty-8.1.10.v20130312
2015-01-07 18:48:42,039 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  StandardDescriptorProcessor - NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
2015-01-07 18:48:42,121 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  AbstractConnector - Started SelectChannelConnector@0.0.0.0:6059
2015-01-07 18:48:42,121 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CMB - event=launched_cqs_service_endpoint port=6059 max_request_length=524288 cl_read=QUORUM cl_write=QUORUM
2015-01-07 18:48:42,254 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  ConnectionPoolMBeanManager - Registering mbean: com.netflix.MonitoredResources:type=ASTYANAX,name=CMBAstyananxConnectionPool,ServiceType=connectionpool
2015-01-07 18:48:42,267 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CountingConnectionPoolMonitor - AddHost: localhost
2015-01-07 18:48:42,335 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CountingConnectionPoolMonitor - AddHost: 127.0.0.1
2015-01-07 18:48:42,336 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CountingConnectionPoolMonitor - RemoveHost: localhost
2015-01-07 18:48:42,411 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CountingConnectionPoolMonitor - AddHost: localhost
2015-01-07 18:48:42,416 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CountingConnectionPoolMonitor - AddHost: 127.0.0.1
2015-01-07 18:48:42,416 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CountingConnectionPoolMonitor - RemoveHost: localhost
2015-01-07 18:48:42,425 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CountingConnectionPoolMonitor - AddHost: localhost
2015-01-07 18:48:42,429 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CountingConnectionPoolMonitor - AddHost: 127.0.0.1
2015-01-07 18:48:42,429 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CountingConnectionPoolMonitor - RemoveHost: localhost
2015-01-07 18:48:42,440 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CQSControllerServlet - event=ping version=2.2.42 ip=192.168.1.91 port=6059
2015-01-07 18:48:42,689 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CQSLongPollReceiver - event=longpoll_receiver_service_listening port=5555
2015-01-07 18:48:42,697 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CQSLongPollSender - event=longpoll_sender_service_initialized
2015-01-07 18:48:42,697 [Thread-14] [757a1952-7965-49a4-8f5d-e2639bb0e701] INFO  CQSLongPollSender$LongPollSenderThread - event=reloading_active_cqs_api_server_list
2015-01-07 18:48:42,697 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  Server - jetty-8.1.10.v20130312
2015-01-07 18:48:42,710 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  StandardDescriptorProcessor - NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
2015-01-07 18:48:42,720 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  AbstractConnector - Started SelectChannelConnector@0.0.0.0:6061
2015-01-07 18:48:42,720 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CMB - event=launched_cns_service_endpoint port=6061 max_request_length=524288 cl_read=QUORUM cl_write=QUORUM
2015-01-07 18:48:42,722 [Thread-14] [757a1952-7965-49a4-8f5d-e2639bb0e701] INFO  ThriftKeyspaceImpl - Detected partitioner org.apache.cassandra.dht.Murmur3Partitioner for keyspace CQS
2015-01-07 18:48:43,727 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CNSPublisher - event=startup version=2.2.42 ip=192.168.1.91 io_mode=SYNC mode=[Producer, Consumer]
2015-01-07 18:48:43,780 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  RedisSortedSetPersistence - event=initialize_redis pools_size=1 max_total=100 server_list=localhost:6379
2015-01-07 18:48:43,780 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CNSEndpointPublisherJobProducer - event=initializing_cns_producer
2015-01-07 18:48:43,781 [CNSEPJobProducer-0] [ddf76604-6c56-4283-b87f-431b91fbe051] INFO  CNSEndpointPublisherJobProducer - event=ping version=2.2.42 ip=192.168.1.91
2015-01-07 18:48:43,791 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CNSEndpointPublisherJobConsumer - event=initializing_cns_consumer
2015-01-07 18:48:43,791 [CNSEPJobConsumer-0] [88d773a8-c718-41d8-98f8-d8b7cd1608b2] INFO  CNSEndpointPublisherJobConsumer - event=ping version=2.2.42 ip=192.168.1.91
2015-01-07 18:48:43,794 [main] [137c1e93-c5b5-4e31-b9b7-e2f70cd5da1c] INFO  CMB - event=launched_cns_publisher mode=Producer,Consumer
2015-01-07 18:48:50,355 [pool-21-thread-19] [e24444da-daf8-4afa-a6db-a8732c61b6ac] WARN  CMBControllerServlet - event=invalid_action action=null url=http://eu-west-1.localhost:6059/favicon.ico
2015-01-07 18:48:50,357 [qtp2017354584-93] [17d15879-2060-4c67-a3de-ad369f42250b] WARN  AsyncContinuation -
java.lang.NullPointerException
    at com.comcast.cmb.common.controller.CMBControllerServlet$1.onComplete(CMBControllerServlet.java:647)
    at org.eclipse.jetty.server.AsyncContinuation.doComplete(AsyncContinuation.java:644)
    at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:555)
    at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:79)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
    at java.lang.Thread.run(Thread.java:745)
2015-01-07 18:48:55,037 [qtp2017354584-23] [2922ffa7-07ba-40ce-aeaf-0b3292f4dcc3] INFO  UserLoginPageServlet - event=login_admin_ui user_name=cns_internal user_id=420624778847
2015-01-07 18:48:55,044 [qtp2017354584-92] [144aa553-6f80-4e85-bd2c-94d63012b849] INFO  ThriftKeyspaceImpl - Detected partitioner org.apache.cassandra.dht.Murmur3Partitioner for keyspace CMB
2015-01-07 18:48:55,339 [pool-21-thread-23] [bbe08fb9-9271-4ab9-b090-5437d1d1ad88] WARN  CMBControllerServlet - event=invalid_action action=null url=http://eu-west-1.localhost:6059/favicon.ico
2015-01-07 18:48:55,339 [qtp2017354584-81] [31fd2930-280c-44df-b2ce-e92ad3567111] WARN  AsyncContinuation -
java.lang.NullPointerException
    at com.comcast.cmb.common.controller.CMBControllerServlet$1.onComplete(CMBControllerServlet.java:647)
    at org.eclipse.jetty.server.AsyncContinuation.doComplete(AsyncContinuation.java:644)
    at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:555)
    at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:79)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
    at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
    at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
    at java.lang.Thread.run(Thread.java:745)
2015-01-07 18:49:04,662 [qtp2017354584-90] [af94e312-021f-47ce-a956-3882672051e7] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_2 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,662 [qtp2017354584-148] [ec3d42a6-82e0-47cd-92c7-1ff49b052932] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,662 [qtp2017354584-84] [704e0109-578f-4fea-bc18-fe82f0f8d7e5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_2 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,662 [qtp2017354584-145] [0a610bbb-897d-46b5-bdab-209728687290] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19930
2015-01-07 18:49:04,662 [qtp2017354584-91] [ac9d7f03-4556-41dc-9375-6cf27aeb90e9] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,663 [qtp2017354584-153] [98d1d3a5-2690-4574-be53-b771faa9fa06] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19932
2015-01-07 18:49:04,663 [qtp2017354584-154] [2d5a40b9-098b-476a-8ab8-eba6080ebf94] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_3 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19932
2015-01-07 18:49:04,662 [qtp2017354584-106] [f03bc0b2-e751-4b4a-a9e5-74736fa671bd] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,662 [qtp2017354584-147] [9e5da5ca-86bc-4d5f-a149-bafc1745730f] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_3 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,665 [qtp2017354584-159] [315b12c8-60fe-40cd-ba32-3f32cc2c43d7] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19934
2015-01-07 18:49:04,665 [qtp2017354584-100] [b66a8636-4a9d-43c8-9266-bf1a96c204d5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,665 [qtp2017354584-81] [31fd2930-280c-44df-b2ce-e92ad3567111] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,665 [qtp2017354584-161] [48f07c25-5926-4f02-b887-2cfcb660fd72] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_2 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,664 [qtp2017354584-90] [af94e312-021f-47ce-a956-3882672051e7] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,664 [qtp2017354584-146] [c8fe4975-7b1e-477f-b165-396a3c4d5c4f] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,664 [qtp2017354584-104] [aa5b370f-4c66-4259-9858-3bc3dea4ba1b] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,664 [qtp2017354584-160] [732db2f6-f186-49df-8e5f-cdebc0c7d9d2] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_3 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,664 [qtp2017354584-86] [d0747550-21af-464a-a710-689f61eb1172] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,664 [qtp2017354584-84] [704e0109-578f-4fea-bc18-fe82f0f8d7e5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_2 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19932
2015-01-07 18:49:04,664 [qtp2017354584-158] [b759c77c-d031-4818-ab0c-b7338f29dfab] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_3 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,664 [qtp2017354584-96] [faece3a5-b22f-4552-964e-36f3f7afb21b] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,664 [qtp2017354584-88] [ac515adb-4fc0-4038-a33c-5856915c52a8] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,664 [qtp2017354584-156] [390ca5a7-460f-404b-a03f-eabcf8bc0c26] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19932
2015-01-07 18:49:04,664 [qtp2017354584-82] [3a1354a3-1354-42cf-b617-e6f9fca2762d] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19933
2015-01-07 18:49:04,663 [qtp2017354584-145] [0a610bbb-897d-46b5-bdab-209728687290] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,663 [qtp2017354584-91] [ac9d7f03-4556-41dc-9375-6cf27aeb90e9] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,663 [qtp2017354584-92] [144aa553-6f80-4e85-bd2c-94d63012b849] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19932
2015-01-07 18:49:04,663 [qtp2017354584-152] [559f2141-ea57-454e-a489-67043549a9b7] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19932
2015-01-07 18:49:04,662 [qtp2017354584-150] [65d9387b-b75b-4a9d-abc0-aeef4317cb84] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,662 [qtp2017354584-89] [fe1d1f9d-cc67-49d1-a10c-98e261857380] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,662 [qtp2017354584-149] [4c428a35-83b4-451e-bd20-21e203087fd5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19931
2015-01-07 18:49:04,662 [qtp2017354584-26] [1c38a3d5-bfbe-417d-b4f7-ba8b639c223b] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=19930
2015-01-07 18:49:04,704 [CNSEPJobProducer-8] [20efea65-07cb-4c8e-852f-1e352e2d13a6] INFO  CNSEndpointPublisherJobProducer - event=ping version=2.2.42 ip=192.168.1.91
2015-01-07 18:49:04,704 [CNSEPJobConsumer-2] [ea68ca3f-2167-43f1-8892-0a779848de08] INFO  CNSEndpointPublisherJobConsumer - event=ping version=2.2.42 ip=192.168.1.91
2015-01-07 18:49:04,714 [pool-21-thread-8] [88a0ab1a-b576-4326-8ea2-a257f6482a17] INFO  CQSControllerServlet - event=ping version=2.2.42 ip=192.168.1.91 port=6059
2015-01-07 18:49:20,397 [pool-21-thread-23] [14776205-eceb-4aac-b9ee-269056884d16] INFO  CNSControllerServlet - event=ping version=2.2.42 ip=192.168.1.91 port=6061
2015-01-07 18:49:20,405 [pool-21-thread-23] [14776205-eceb-4aac-b9ee-269056884d16] INFO  CMBControllerServlet - event=req status=ok client=127.0.0.1 Action=ListTopics Version=2010-03-31 user=cns_test resp_ms=10 cass_ms=5 cass_num_rd=3 cass_num_wr=4 cnscqs_ms=0 io_ms=0 asyncq_ms=0 auth_ms=3
2015-01-07 18:49:20,482 [pool-21-thread-35] [3b8a1df2-2f4e-4429-8f8d-19b8efc76b57] INFO  CMBControllerServlet - event=req status=ok client=127.0.0.1 Action=DeleteTopic TopicArn=arn:cmb:cns:ccp:420624858610:topic-1420626508 Version=2010-03-31 user=cns_test resp_ms=69 cass_ms=35 cass_num_rd=9 cass_num_wr=14 cnscqs_ms=0 io_ms=1 asyncq_ms=1 auth_ms=0
2015-01-07 18:49:20,490 [pool-21-thread-13] [790613d4-58e7-47f3-afd5-a38c1de91db3] INFO  CMBControllerServlet - event=req status=ok client=127.0.0.1 queue=/ Action=ListQueues Version=2012-11-05 user=cns_test resp_ms=3 cass_ms=1 cass_num_rd=1 cass_num_wr=0 redis_ms=0 io_ms=0 asyncq_ms=0 auth_ms=0
2015-01-07 18:49:20,531 [pool-21-thread-37] [e7519325-aaec-4810-99ac-d10dbc82b94c] INFO  CMBControllerServlet - event=req status=ok client=127.0.0.1 queue=/420624858610/queue-1420626508 Action=DeleteQueue Version=2012-11-05 QueueUrl=http://eu-west-1.localhost:6059/420624858610/queue-1420626508 user=cns_test resp_ms=37 cass_ms=35 cass_num_rd=2 cass_num_wr=102 redis_ms=1 io_ms=0 asyncq_ms=1 auth_ms=0
2015-01-07 18:49:20,541 [pool-21-thread-42] [32049dd2-e002-4d3c-993b-e882f69b7aef] INFO  CMBControllerServlet - event=req status=ok client=127.0.0.1 Action=CreateTopic Version=2010-03-31 Name=topic-1420656560 user=cns_test resp_ms=8 cass_ms=4 cass_num_rd=1 cass_num_wr=17 cnscqs_ms=0 io_ms=0 asyncq_ms=1 auth_ms=1
2015-01-07 18:49:20,563 [pool-18-thread-1] [1eb9e5f4-2ffd-45d5-b7a6-3235f7e2bac1] INFO  RedisSortedSetPersistence - event=cache_filler_started queue_url=420624858610/queue-1420656560 shard=0
2015-01-07 18:49:20,563 [pool-21-thread-26] [83db9539-549e-4eac-9e25-84fa9bd7bb74] INFO  CMBControllerServlet - event=req status=ok client=127.0.0.1 queue=/ Action=CreateQueue Version=2012-11-05 QueueName=queue-1420656560 user=cns_test resp_ms=20 cass_ms=1 cass_num_rd=1 cass_num_wr=16 redis_ms=16 io_ms=0 asyncq_ms=0 auth_ms=1
2015-01-07 18:49:20,567 [pool-21-thread-8] [9bbd851e-a534-4d21-bd31-b6c5b7d5da57] INFO  CMBControllerServlet - event=req status=ok client=127.0.0.1 queue=/420624858610/queue-1420656560 Action=GetQueueAttributes Version=2012-11-05 AttributeName.1=QueueArn QueueUrl=http://eu-west-1.localhost:6059/420624858610/queue-1420656560 user=cns_test resp_ms=1 cass_ms=0 cass_num_rd=0 cass_num_wr=0 redis_ms=0 io_ms=0 asyncq_ms=0 auth_ms=0
2015-01-07 18:49:20,587 [pool-21-thread-30] [2b10b34f-873e-4bdb-86cb-37ea3b493014] INFO  CMBControllerServlet - event=req status=ok client=127.0.0.1 Action=Subscribe Endpoint=arn:cmb:cqs:ccp:420624858610:queue-1420656560 TopicArn=arn:cmb:cns:ccp:420624858610:topic-1420656560 Version=2010-03-31 Protocol=cqs user=cns_test resp_ms=17 cass_ms=8 cass_num_rd=8 cass_num_wr=8 cnscqs_ms=0 io_ms=0 asyncq_ms=0 auth_ms=1
2015-01-07 18:49:20,603 [pool-18-thread-1] [1eb9e5f4-2ffd-45d5-b7a6-3235f7e2bac1] INFO  RedisSortedSetPersistence - event=cache_filler_finished  queue_url=420624858610/queue-1420656560 shard=0 num_cached=0 total_ms=40 redis_ms=0 cass_ms=38
2015-01-07 18:49:20,604 [pool-21-thread-32] [8bfd2108-dd1b-4d8c-8e5e-1d065c5631d1] WARN  CNSPublishAction - event=no_confirmed_subscribers action=publish topic_arn=arn:cmb:cns:ccp:420624858610:topic-1420656560
2015-01-07 18:49:20,605 [pool-21-thread-32] [8bfd2108-dd1b-4d8c-8e5e-1d065c5631d1] INFO  CMBControllerServlet - event=req status=ok client=127.0.0.1 Action=Publish Message=test TopicArn=arn:cmb:cns:ccp:420624858610:topic-1420656560 Version=2010-03-31 user=cns_test resp_ms=13 cass_ms=4 cass_num_rd=7 cass_num_wr=0 cnscqs_ms=0 io_ms=0 asyncq_ms=0 auth_ms=0
2015-01-07 18:49:24,719 [qtp2017354584-163] [95c85869-229a-4aae-b3ba-c58049a94b9a] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_2 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20006
2015-01-07 18:49:24,721 [qtp2017354584-85] [6943796b-66e7-4eb0-90d3-fa5b8a28a8c5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_2 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20005
2015-01-07 18:49:24,721 [qtp2017354584-157] [6d2c833c-f719-4529-bca6-1a81ac975756] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_3 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20005
2015-01-07 18:49:24,721 [qtp2017354584-148] [ec3d42a6-82e0-47cd-92c7-1ff49b052932] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20006
2015-01-07 18:49:24,721 [qtp2017354584-106] [f03bc0b2-e751-4b4a-a9e5-74736fa671bd] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20005
2015-01-07 18:49:24,723 [qtp2017354584-161] [48f07c25-5926-4f02-b887-2cfcb660fd72] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_3 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20003
2015-01-07 18:49:24,723 [qtp2017354584-85] [6943796b-66e7-4eb0-90d3-fa5b8a28a8c5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20002
2015-01-07 18:49:24,726 [qtp2017354584-85] [6943796b-66e7-4eb0-90d3-fa5b8a28a8c5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20007
2015-01-07 18:49:24,726 [qtp2017354584-162] [98e5c683-8efb-41b3-9816-58a5a2d51816] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20003
2015-01-07 18:49:24,726 [qtp2017354584-85] [6943796b-66e7-4eb0-90d3-fa5b8a28a8c5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20011
2015-01-07 18:49:24,727 [qtp2017354584-85] [6943796b-66e7-4eb0-90d3-fa5b8a28a8c5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_2 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20010
2015-01-07 18:49:24,727 [qtp2017354584-162] [98e5c683-8efb-41b3-9816-58a5a2d51816] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20002
2015-01-07 18:49:24,727 [qtp2017354584-86] [d0747550-21af-464a-a710-689f61eb1172] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20005
2015-01-07 18:49:24,727 [qtp2017354584-162] [98e5c683-8efb-41b3-9816-58a5a2d51816] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20002
2015-01-07 18:49:24,728 [qtp2017354584-86] [d0747550-21af-464a-a710-689f61eb1172] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20003
2015-01-07 18:49:24,728 [qtp2017354584-162] [98e5c683-8efb-41b3-9816-58a5a2d51816] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20002
2015-01-07 18:49:24,728 [qtp2017354584-86] [d0747550-21af-464a-a710-689f61eb1172] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20010
2015-01-07 18:49:24,720 [qtp2017354584-153] [98d1d3a5-2690-4574-be53-b771faa9fa06] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_3 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20005
2015-01-07 18:49:24,730 [qtp2017354584-90] [af94e312-021f-47ce-a956-3882672051e7] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_3 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20006
2015-01-07 18:49:24,721 [qtp2017354584-155] [4a10ef80-5606-4009-8832-0d4d394a425c] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20005
2015-01-07 18:49:24,727 [qtp2017354584-85] [6943796b-66e7-4eb0-90d3-fa5b8a28a8c5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20001
2015-01-07 18:49:24,726 [qtp2017354584-166] [101b5a0d-5f1a-470c-825c-92d3b65c37a6] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20002
2015-01-07 18:49:24,726 [qtp2017354584-106] [f03bc0b2-e751-4b4a-a9e5-74736fa671bd] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20007
2015-01-07 18:49:24,725 [qtp2017354584-165] [582b0d30-aeba-4d76-bb9b-ce34f7aa94d8] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20003
2015-01-07 18:49:24,725 [qtp2017354584-80] [975f2765-81dd-4dd8-abd4-3de5a79957fe] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20010
2015-01-07 18:49:24,737 [qtp2017354584-80] [975f2765-81dd-4dd8-abd4-3de5a79957fe] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20016
2015-01-07 18:49:24,725 [qtp2017354584-163] [95c85869-229a-4aae-b3ba-c58049a94b9a] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_2 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20002
2015-01-07 18:49:24,725 [qtp2017354584-104] [aa5b370f-4c66-4259-9858-3bc3dea4ba1b] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20003
2015-01-07 18:49:24,725 [qtp2017354584-79] [a869f66d-e328-4caf-a223-18dcb85a757b] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20003
2015-01-07 18:49:24,725 [qtp2017354584-146] [c8fe4975-7b1e-477f-b165-396a3c4d5c4f] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20002
2015-01-07 18:49:24,725 [qtp2017354584-83] [10bac553-18b0-4639-80a5-2f19dda7ff9c] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/EndpointPublishQ_1 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20006
2015-01-07 18:49:24,723 [qtp2017354584-102] [bd16eba3-3027-4622-b82a-879e6eb5a2b5] INFO  CMBControllerServlet - event=req status=ok client=192.168.1.91 queue=/420624778847/PublishJobQ_0 Action=ReceiveMessage MaxNumberOfMessages=1 Version=2012-11-05 WaitTimeSeconds=20 user=cns_internal lp_ms=20003
boriwo commented 9 years ago

Hm, nothing obvious in the logs except the no_confirmed_subscribers warning you already spotted.

I'm curious, after you run your test, can you actually see the subscription with state "pending confirmation" in web ui, or, does the subscription not exist at all?

Also, what happens if you subscribe to an HTTP endpoint instead of CQS? Does publishing to HTTP endpoints work for you? (You can use the built-in http endpoint as described in the FAQ to test this.)

Finally, could you send me your cmb.properties? Are all components (cmb, redis, cassandra, ruby script) hosted on the same machine? I noticed your unconventional choice of hostname "eu-west-1.localhost".

leemhenson commented 9 years ago

I'm curious, after you run your test, can you actually see the subscription with state "pending confirmation" in web ui, or, does the subscription not exist at all?

I can see the subscription by clicking the Subscriptions link next to the topic, and there is no indication that the subscription is pending. The topic list itself shows:

Subscriptions pending: 0
Subscriptions confirmed: 0

Also, what happens if you subscribe to an HTTP endpoint instead of CQS? Does publishing to HTTP endpoints work for you? (You can use the built-in http endpoint as described in the FAQ to test this.)

Using the test http endpoint seems to work. I can see a message on the list endpoint.

Finally, could you send me your cmb.properties?

It's exactly this: https://github.com/musicglue/cmb/blob/issue-30/config/cmb.properties

Are all components (cmb, redis, cassandra, ruby script) hosted on the same machine?

Yes.

I noticed your unconventional choice of hostname "eu-west-1.localhost".

The aws-sdk-core gem seems to expect the service endpoint hostnames to include the region. My hosts file resolves that to 0.0.0.0.

boriwo commented 9 years ago

Just took another shot at by installing from scratch trying to mimic your environment as best I could. Finally I was able to reproduce your issue! For now it looks like there is a problem with the latest Cassandra version you are using (2.1.2). In my dev environment I was running with Cassandra version 2.0.6 and had no issues. For immediate relief you could try to down-grade your Cassandra version and see if that helps. Meanwhile I'll take a deeper look into Cassandra and hope to provide a fix shortly.

boriwo commented 9 years ago

This should now be fixed if you work with HEAD!

Turns out starting with Cassandra 2.1 it's a bad idea to delete counters:

http://stackoverflow.com/questions/13653681/apache-cassandra-delete-from-counter

When creating a topic we were routinely attempting to delete any stale counters (in case a topic by the same name had existed in the past). In effect this immediately made all counters for the new topic unavailable and thus screwed up accounting.

This was working fine up until at least C* version 2.0.6 but in 2.1 it doesn't work any more. Thanks again for bringing this issue to our attention. Hope this resolves your issues.

leemhenson commented 9 years ago

High five! :hand:

Thanks for digging into this!

FYI, the ruby example you've added to master won't work without the Gemfile, so I've opened a pull request to put that back in.