Support Forums : DataStax

DataStax Support Forums » OpsCenter

Stomp Connection Timeouts

(22 posts) (2 voices)

Started 4 months ago by davidace47
Latest reply from davidace47
This topic is not resolved

Tags:

No tags yet.

12 Next »

davidace47
Member

Hi guys,
I just installed OpsCenter and its agents. I installed the agents following the step by step directions here http://www.datastax.com/docs/opscenter/agent/agent_tar. Somehow when I start the any of the agents I get this:

[root@server1-test-01 agent]# bin/opscenter-agent -f
log4j:WARN No appenders could be found for logger (org.eclipse.jetty.util.log).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
INFO [main] 2013-01-24 22:23:35,828 Loading conf files: ./conf/address.yaml
INFO [main] 2013-01-24 22:23:36,161 Java vendor/version: Java HotSpot(TM) 64-Bit Server VM/1.6.0_38
INFO [main] 2013-01-24 22:23:36,164 Waiting for the config from OpsCenter
INFO [main] 2013-01-24 22:23:36,168 SSL communication is disabled
INFO [main] 2013-01-24 22:23:36,171 Creating stomp connection to 69.252.206.59:61620
INFO [StompConnection receiver] 2013-01-24 22:23:36,194 Reconnecting in 0s.
INFO [StompConnection receiver] 2013-01-24 22:23:36,225 Connected to 69.252.206.59:61620
ERROR [pool-2-thread-1] 2013-01-24 22:23:36,307 failed sending message to /conf-request:
java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at java.io.DataOutputStream.write(DataOutputStream.java:90)
at java.io.FilterOutputStream.write(FilterOutputStream.java:80)
at org.jgroups.client.StompConnection.send(StompConnection.java:200)
at org.jgroups.client.StompConnection.send(StompConnection.java:219)
at org.jgroups.client.StompConnection.send(StompConnection.java:223)
at opsagent.messaging$send_message$send_msg__3447.invoke(messaging.clj:68)
at clojure.lang.AFn.applyToHelper(AFn.java:167)
at clojure.lang.AFn.applyTo(AFn.java:151)
at clojure.lang.Agent$Action.doRun(Agent.java:100)
at clojure.lang.Agent$Action.run(Agent.java:150)
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:662)
ERROR [StompConnection receiver] 2013-01-24 22:23:36,335 Connection closed unexpectedly:
java.io.EOFException: reading verb
at org.jgroups.protocols.STOMP.readFrame(STOMP.java:227)
at org.jgroups.client.StompConnection.run(StompConnection.java:253)
at java.lang.Thread.run(Thread.java:662)
INFO [StompConnection receiver] 2013-01-24 22:23:36,339 Reconnecting in 2s.
INFO [StompConnection receiver] 2013-01-24 22:23:38,341 Connected to 69.252.206.59:61620
ERROR [StompConnection receiver] 2013-01-24 22:23:38,345 Connection closed unexpectedly:
java.io.EOFException: reading verb
at org.jgroups.protocols.STOMP.readFrame(STOMP.java:227)
at org.jgroups.client.StompConnection.run(StompConnection.java:253)
at java.lang.Thread.run(Thread.java:662)
INFO [StompConnection receiver] 2013-01-24 22:23:38,346 Reconnecting in 6s.
INFO [StompConnection receiver] 2013-01-24 22:23:44,351 Connected to 69.252.206.59:61620
ERROR [StompConnection receiver] 2013-01-24 22:23:44,353 Connection closed unexpectedly:
java.io.EOFException: reading verb
at org.jgroups.protocols.STOMP.readFrame(STOMP.java:227)
at org.jgroups.client.StompConnection.run(StompConnection.java:253)
at java.lang.Thread.run(Thread.java:662)
INFO [StompConnection receiver] 2013-01-24 22:23:44,365 Reconnecting in 14s.

Do you know what I may be doing wrong?. I'll really appreciate your input on this.

Thanks,
David

Posted 4 months ago #
mbulman
Key Master

David,

It's possible there is some sort of firewall issue. It looks like the agent is connecting to the stomp server okay, but messages can't be sent. I also see that SSL is disabled on the agent, so you'll want to make sure it's also disabled on the opscenterd side.

Are there any errors in opscenterd.log?

Posted 3 months ago #
davidace47
Member

Hi,

Thanks a lot for your reply. So I made sure SSL was disabled on the opscenterd side as well.
root@dayview-dev-ch2-02 agent]# bin/opscenter-agent -f
log4j:WARN No appenders could be found for logger (org.eclipse.jetty.util.log).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
INFO [main] 2013-01-31 21:18:27,236 Loading conf files: ./conf/address.yaml
INFO [main] 2013-01-31 21:18:27,361 Java vendor/version: Java HotSpot(TM) 64-Bit Server VM/1.6.0_38
INFO [main] 2013-01-31 21:18:27,361 Waiting for the config from OpsCenter
INFO [main] 2013-01-31 21:18:27,363 SSL communication is disabled
INFO [main] 2013-01-31 21:18:27,363 Creating stomp connection to 69.252.206.59:61620
INFO [StompConnection receiver] 2013-01-31 21:18:27,396 Reconnecting in 0s.
INFO [StompConnection receiver] 2013-01-31 21:18:27,413 Connected to 69.252.206.59:61620

It looks fine bit I still don't see the agents connected on Datastax, it still says "0 of agents connected". However I looked at opscenterd.log and got this:

13-01-31 21:19:19+0000 [Dev_Cluster] INFO: (No candidate nodes to expand pool to target size 5 from 0; there are 0 pending requests. Expected candidate node retry in 209.8 seconds.)
2013-01-31 21:19:19+0000 [Dev_Cluster] INFO: (No candidate nodes to expand pool to target size 5 from 0; there are 0 pending requests. Expected candidate node retry in 209.8 seconds.)
2013-01-31 21:19:19+0000 [Dev_Cluster] INFO: (No candidate nodes to expand pool to target size 5 from 0; there are 0 pending requests. Expected candidate node retry in 209.8 seconds.)
2013-01-31 21:19:19+0000 [Dev_Cluster] INFO: (No candidate nodes to expand pool to target size 5 from 0; there are 0 pending requests. Expected candidate node retry in 209.8 seconds.)
2013-01-31 21:19:19+0000 [Dev_Cluster] INFO: (No candidate nodes to expand pool to target size 5 from 0; there are 0 pending requests. Expected candidate node retry in 209.8 seconds.)
2013-01-31 21:19:39+0000 [] Problem while calling InspectKeyspaceController
Traceback (most recent call last):
Failure: opscenterd.CassandraService.NoCassandraConnection: No Cassandra connections available.

The way I have it setup, I have 3 nodes and the server with Opscenter on it doesn't have cassandra running, but the agents do. Cassandra on all the agents are currently running

[root@dayview-dev-ch2-02 agent]# service cassandra status
Cassandra is running.
[root@dayview-dev-ch2-02 agent]#

Wondering what you might make of this

-David

Posted 3 months ago #
davidace47
Member

Just thought I 'd share the conf files with you so you could get a better understanding:
dayview-dev-ch2-01(69.252.206.59): This has Opscenter configured without cassandra
dayview-dev-ch2-02(69.252.206.60): This has Opscenter agent configured and cassandra running as well on it...same with the other agents

Opscenterd.conf
[webserver]
port = 8088
interface = 69.252.206.59
[agents]
use_ssl = false

On the main Opscenter server (69.252.206.59)
[address.yaml]
stomp_interface: "69.252.206.59"
local_interface: "69.252.206.59"
use_ssl: 0

Cluster_name.conf
[jmx]
username =
password =
port = 7199

[cassandra]
username =
seed_hosts = 69.252.206.59
api_port = 9160
password =

Opscenter-agent (69.252.206.60)
[address.yaml]
stomp_interface: "69.252.206.59"
local_interface: "69.252.206.60"
use_ssl: 0

Cassandra (only set up on opscenter-agents)
[cassandra.yaml]
seeds: "69.252.206.60"
listen_address: 69.252.206.60
rpc_port: 9160
rpc_address: 0.0.0.0

If there is anything else you might need, I'll be more than happy to provide info.

Thanks again for your help

-David

Posted 3 months ago #
mbulman
Key Master

Under [cassandra].seed_hosts in Cluster_name.conf, you'll want that to point to at least one of your Cassandra nodes. So in this case, 69.252.206.60

Posted 3 months ago #
davidace47
Member

Ok so I changed [cassandra].seed_hosts in Cluster_name.conf and pointed that to 69.252.206.60 like you suggested. Restarted both Opscenter and the agent. I still see 0 of 0 agents connected.
I did a "tail" on opscenterd.log and this is what I got (changed Cluster_name to Dev_Cluster)

[dayview@dayview-dev-ch2-01 /opt/dayview/opscenter/log] $ tail -f opscenterd.log
2013-02-01 16:06:40+0000 [Dev_Cluster] INFO: Agent for ip 69.252.206.60 is version u'2.10'
2013-02-01 16:06:42+0000 [Dev_Cluster] INFO: Using 69.252.206.60 as the RPC address for node 69.252.206.60
2013-02-01 16:06:53+0000 [Dev_Cluster] INFO: Node 69.252.206.60 changed its mode to normal
2013-02-01 16:07:27+0000 [Dev_Cluster] INFO: Agent for ip 69.252.206.61 is version u'2.10'
2013-02-01 16:07:27+0000 [Dev_Cluster] INFO: Agent for ip 69.252.206.61 is version u'2.10'
2013-02-01 16:07:27+0000 [Dev_Cluster] INFO: Agent for ip 69.252.206.60 is version u'2.10'
2013-02-01 16:07:27+0000 [Dev_Cluster] INFO: Agent for ip 69.252.206.60 is version u'2.10'
2013-02-01 16:08:36+0000 [Dev_Cluster] INFO: Snitch: org.apache.cassandra.locator.SimpleSnitch
2013-02-01 16:08:37+0000 [Dev_Cluster] WARN: HTTP request http://69.252.206.62:61621/cluster/rack?node_ip=69.252.206.61 failed: Connection was refused by other side: 111: Connection refused.
2013-02-01 16:08:37+0000 [Dev_Cluster] WARN: Unable to collect datacenter, rack information: Failed query to http://69.252.206.62:61621/cluster/rack?node_ip=69.252.206.61 : Connection was refused by other side: 111: Connection refused.
2013-02-01 16:10:05+0000 [Dev_Cluster] INFO: Agent for ip 69.252.206.60 is version u'2.10'
2013-02-01 16:10:05+0000 [Dev_Cluster] INFO: Agent for ip 69.252.206.61 is version u'2.10'
2013-02-01 16:10:05+0000 [Dev_Cluster] INFO: Agent for ip 69.252.206.61 is version u'2.10'
2013-02-01 16:10:37+0000 [Dev_Cluster] WARN: HTTP request http://69.252.206.62:61621/cluster/rack?node_ip=69.252.206.62 failed: Connection was refused by other side: 111: Connection refused.
2013-02-01 16:10:37+0000 [Dev_Cluster] WARN: Unable to collect datacenter, rack information: Failed query to http://69.252.206.62:61621/cluster/rack?node_ip=69.252.206.62 : Connection was refused by other side: 111: Connection refused.
2013-02-01 16:12:26+0000 [] INFO: Starting factory <opscenterd.CassandraService.NoReconnectCassandraClientFactory instance at 0x1e5fbd8>
2013-02-01 16:12:26+0000 [] INFO: <twisted.internet.tcp.Connector instance at 0x1e5f680> will retry in 2 seconds
2013-02-01 16:12:26+0000 [] WARN: ProcessingError while calling UpdateClusterConfController: Unable to connect to cluster
2013-02-01 16:12:26+0000 [] INFO: Stopping factory <opscenterd.CassandraService.NoReconnectCassandraClientFactory instance at 0x1e5fbd8>
2013-02-01 16:12:37+0000 [Dev_Cluster] WARN: HTTP request http://69.252.206.62:61621/cluster/datacenter?node_ip=69.252.206.60 failed: Connection was refused by other side: 111: Connection refused.

I also ran the agent in the foreground:

[root@dayview-dev-ch2-02 agent]# bin/opscenter-agent -f
log4j:WARN No appenders could be found for logger (org.eclipse.jetty.util.log).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
INFO [main] 2013-02-01 16:06:39,424 Loading conf files: ./conf/address.yaml
INFO [main] 2013-02-01 16:06:39,597 Java vendor/version: Java HotSpot(TM) 64-Bit Server VM/1.6.0_38
INFO [main] 2013-02-01 16:06:39,597 Waiting for the config from OpsCenter
INFO [main] 2013-02-01 16:06:39,598 SSL communication is disabled
INFO [main] 2013-02-01 16:06:39,599 Creating stomp connection to 69.252.206.59:61620
INFO [StompConnection receiver] 2013-02-01 16:06:39,610 Reconnecting in 0s.
INFO [StompConnection receiver] 2013-02-01 16:06:39,695 Connected to 69.252.206.59:61620
INFO [StompConnection receiver] 2013-02-01 16:06:39,959 Got new config from OpsCenter: {:rollups300_ttl 2419200, :rollups60_ttl 604800, :thrift_port 9160, :metrics_enabled 1, :rollups7200_ttl 31536000, :metrics_ignored_column_families "", :jmx_port 7199, :rollups86400_ttl -1, :api_port "61621", :metrics_ignored_solr_cores "", :metrics_ignored_keyspaces "system, OpsCenter"}
INFO [StompConnection receiver] 2013-02-01 16:06:39,960 Using 69.252.206.60 as the cassandra broadcast address
INFO [StompConnection receiver] 2013-02-01 16:06:39,967 Connecting to Cassandra cluster: (69.252.206.60 9160)
INFO [StompConnection receiver] 2013-02-01 16:06:39,984 Downed Host Retry service started with queue size -1 and retry delay 10s
INFO [StompConnection receiver] 2013-02-01 16:06:39,991 Registering JMX me.prettyprint.cassandra.service_Agent Cluster:ServiceType=hector,MonitorType=hector
INFO [StompConnection receiver] 2013-02-01 16:06:40,052 Connected to Cassandra cluster: Dev Cluster
INFO [StompConnection receiver] 2013-02-01 16:06:40,054 in execute with client org.apache.cassandra.thrift.Cassandra$Client@134683c0
INFO [StompConnection receiver] 2013-02-01 16:06:40,076 Using partitioner: org.apache.cassandra.dht.RandomPartitioner
INFO [StompConnection receiver] 2013-02-01 16:06:40,089 Starting OS metric collectors (Linux)
INFO [Thread-4] 2013-02-01 16:06:40,095 in execute with client org.apache.cassandra.thrift.Cassandra$Client@134683c0
INFO [StompConnection receiver] 2013-02-01 16:06:40,107 Starting Cassandra JMX metric collectors
INFO [Thread-4] 2013-02-01 16:06:40,119 Attempting to load stored metric values.
INFO [StompConnection receiver] 2013-02-01 16:06:40,292 Starting Jetty server: {:port 61621, :host "69.252.206.60", :ssl? false, :join? false}
WARN [Jetty] 2013-02-01 16:06:40,832 FAILED SelectChannelConnector@69.252.206.60:61621: java.net.BindException: Address already in use
java.net.BindException: Address already in use
INFO [qtp788730640-64] 2013-02-01 17:38:49,904 HTTP: :get /os-metric/disk-space - 200
INFO [qtp788730640-62] 2013-02-01 17:40:13,248 New JMX connection (127.0.0.1:7199)
INFO [qtp788730640-60] 2013-02-01 17:40:13,251 New JMX connection (127.0.0.1:7199)
INFO [qtp788730640-64] 2013-02-01 17:40:13,254 New JMX connection (127.0.0.1:7199)
INFO [qtp788730640-64] 2013-02-01 17:40:13,289 HTTP: :get /cluster/datacenter - 200
INFO [qtp788730640-60] 2013-02-01 17:40:13,299 HTTP: :get /cluster/datacenter - 200
INFO [qtp788730640-62] 2013-02-01 17:40:13,303 HTTP: :get /cluster/datacenter - 200
INFO [qtp788730640-60] 2013-02-01 17:42:13,250 New JMX connection (127.0.0.1:7199)
INFO [qtp788730640-60] 2013-02-01 17:42:13,268 HTTP: :get /cluster/datacenter - 200
INFO [qtp788730640-64] 2013-02-01 17:43:49,900 HTTP: :get /os-metric/disk-space - 200
INFO [StompConnection receiver] 2013-02-01 17:43:49,938 Got new config from OpsCenter: {:rollups300_ttl 2419200, :rollups60_ttl 604800, :thrift_port 9160, :metrics_enabled 1, :rollups7200_ttl 31536000, :metrics_ignored_column_families "", :thrift_rpc_interface "69.252.206.60", :jmx_port 7199, :rollups86400_ttl -1, :api_port "61621", :metrics_ignored_solr_cores "", :metrics_ignored_keyspaces "system, OpsCenter", :rollup_subscriptions []}
INFO [qtp788730640-61] 2013-02-01 17:48:13,249 New JMX connection (127.0.0.1:7199)
INFO [qtp788730640-61] 2013-02-01 17:48:13,285 HTTP: :get /cluster/datacenter - 200

Thanks

Posted 3 months ago #
davidace47
Member

It says connection refused by other side 69.252.206.61, and 69.252.206.62 and that's fine because I only started 69.252.206.60 at that moment. But I was of the impression that I would at least see one of the agents connected, since I started just one...

Posted 3 months ago #
mbulman
Key Master

Can you send the output of http://<opsc-host>:8888/Dev_Cluster/nodes?

It also seems like you have multiple agents running on dayview-dev-ch2-02. Make sure you kill any running agent processes before starting up another.

Posted 3 months ago #
davidace47
Member

This is the output you asked for:
[{"load": 1.3, "has_jna": true, "devices": {"saved_caches": "dm_3", "commitlog": "dm_3", "other": ["dm_2", "dm_1", "dm_0", "sda"], "data": ["dm_3"]}, "task_progress": {}, "node_ip": "69.252.206.61", "network_interfaces": ["lo", "eth0"], "node_version": {"search": null, "dse": "2.2", "tasktracker": null, "jobtracker": null, "cassandra": "1.1.5"}, "dc": "datacenter1", "node_name": "dayview-dev-ch2-03.sys.comcast.net", "num_procs": 1, "streaming": {}, "token": "56713727820156410577229101238628035242", "data_held": 2533011.0, "mode": "normal", "rpc_ip": "69.252.206.61", "partitions": {"saved_caches": "/dev/mapper/RootVolGroup00_lv_var", "commitlog": "/dev/mapper/RootVolGroup00_lv_var", "other": ["/dev/mapper/RootVolGroup00_lv_opt", "/dev/sda1", "/dev/mapper/RootVolGroup00_lv_root"], "data": ["/dev/mapper/RootVolGroup00_lv_var"]}, "os": "linux", "rack": "rack1", "last_seen": 0}, {"load": 1.0600000000000001, "has_jna": true, "devices": {"saved_caches": "dm_3", "commitlog": "dm_3", "other": ["dm_2", "dm_1", "dm_0", "sda"], "data": ["dm_3"]}, "task_progress": {}, "node_ip": "69.252.206.60", "network_interfaces": ["lo", "eth0"], "node_version": {"search": null, "dse": "2.2", "tasktracker": null, "jobtracker": null, "cassandra": "1.1.5"}, "dc": "datacenter1", "node_name": "dayview-dev-ch2-02.sys.comcast.net", "num_procs": 1, "streaming": {}, "token": "0", "data_held": 2687731.0, "mode": "normal", "rpc_ip": "69.252.206.60", "partitions": {"saved_caches": "/dev/mapper/RootVolGroup00_lv_var", "commitlog": "/dev/mapper/RootVolGroup00_lv_var", "other": ["/dev/mapper/RootVolGroup00_lv_opt", "/dev/sda1", "/dev/mapper/RootVolGroup00_lv_root"], "data": ["/dev/mapper/RootVolGroup00_lv_var"]}, "os": "linux", "rack": "rack1", "last_seen": 0}, {"load": null, "has_jna": false, "devices": {"saved_caches": null, "commitlog": null, "other": null, "data": null}, "task_progress": {}, "node_ip": "69.252.206.62", "network_interfaces": null, "node_version": {}, "dc": "datacenter1", "node_name": null, "num_procs": null, "streaming": {}, "token": "113427455640312821154458202477256070485", "data_held": null, "mode": "unknown", "rpc_ip": "69.252.206.62", "partitions": {"saved_caches": null, "commitlog": null, "other": null, "data": null}, "os": null, "rack": "rack1", "last_seen": 0}]

Thanks

Posted 3 months ago #
mbulman
Key Master

And if you refresh the UI right now you still see "0 of 0 agents connected" ?

Posted 3 months ago #
davidace47
Member

Yeah.."0 of 0 agents connected" still. I did grep for Opscenter on the agent though and got nothing

[root@dayview-dev-ch2-02 conf]# ps -ef | grep opscenter
root 12153 20879 0 23:01 pts/1 00:00:00 grep opscenter

Do I restart the agent?

Posted 3 months ago #
davidace47
Member

[root@dayview-dev-ch2-02 conf]# ps -ef | grep opscenter-agent
root 12301 20879 0 23:07 pts/1 00:00:00 grep opscenter-agent

Posted 3 months ago #
mbulman
Key Master

You do need to make sure the agent is running on all of your Cassandra nodes.

The fact that it is still showing "0 of 0 agents connected" is very odd. Do you see any nodes when you open Cluster -> Ring View? If not, it sounds like you may have multiple instances of opscenterd running. The output I had you send from the opscenterd API shows that it is seeing nodes, and I can't think of any reason the UI would not show them.

Posted 3 months ago #
davidace47
Member

I do not see any nodes when I open Opscenter matter of fact I get an error message:
"Error
Error loading cluster view: Unknown cluster partitioner"

However prior to this I checked to see if Opscenter-agent was running (multiple instances) but it came back with nothing.
[dayview@dayview-dev-ch2-02 ~] $ ps -ef | grep opscenter-agent
dayview 12133 12105 0 21:02 pts/0 00:00:00 grep opscenter-agent
Of course I restarted it before I got the "error" message I got that I showed above. Like you said it should be working right I would think and I'm really confused as to why it's not

I must say that I'm really grateful for all your help on this. I really appreciate the time and effort.

Thanks
-David

Posted 3 months ago #
mbulman
Key Master

Can you tell me what version of OpsCenter and Cassandra you're running?

Posted 3 months ago #

RSS feed for this topic

12 Next »

Reply »

You must log in to post.