Skip to content
This repository has been archived by the owner on Dec 27, 2022. It is now read-only.

Running the Watcher Agent

lusis edited this page Mar 15, 2011 · 3 revisions

The watcher agent daemon is installed as part of the Noah gem. It has some additional requirements that are not hardcoded into the gemspec. For now, simply

gem install eventmachine --pre
gem install em-http-request --pre
gem install em-hiredis

More information is here: Watcher Agent.

Running the agent

Currently the agent does not daemonize. I plan on fleshing that out soon. If you installed Noah from rubygems, you can simply run noah-watcher.rb and it will start. You can also run it from the bin directory if you checked out from github.

$ bin/noah-watcher.rb 
D, [2011-03-15T07:43:47.085464 #13408] DEBUG -- : Initializing with 0 registered watches
D, [2011-03-15T07:43:47.085563 #13408] DEBUG -- : [Noah::Agents::HttpAgent, Noah::Agents::DummyAgent] agents registered
I, [2011-03-15T07:43:47.085622 #13408]  INFO -- : Callback: Succeed callback
D, [2011-03-15T07:43:47.085959 #13408] DEBUG -- : Starting up

You can see here that the agent has started up, found 0 watches and registered the following notification methods - Http and Dummy. The Http agent will POST the raw JSON of an operation to a given url. The Dummy simply echos back if it processed a message. Let's assume we have one record in Noah - an application called my_sexy_application.

If we register a watch against that entry, we see the following in the agent log:

D, [2011-03-15T07:47:37.609742 #13602] DEBUG -- : Found new watches
D, [2011-03-15T07:47:37.609840 #13602] DEBUG -- : Current watch count: 0
D, [2011-03-15T07:47:37.611268 #13602] DEBUG -- : New watch count: 1
I, [2011-03-15T07:47:37.611447 #13602]  INFO -- : http: Worker initiated
D, [2011-03-15T07:47:37.611507 #13602] DEBUG -- : http: got event - //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL215X3NleHlfYXBwbGljYXRpb258aHR0cDovL2xvY2FsaG9zdDozMDAwL3dlYmhvb2s=
D, [2011-03-15T07:47:37.611598 #13602] DEBUG -- : http: Found 0 possible matches for //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL215X3NleHlfYXBwbGljYXRpb258aHR0cDovL2xvY2FsaG9zdDozMDAwL3dlYmhvb2s=
I, [2011-03-15T07:47:37.611689 #13602]  INFO -- : dummy: Worker initiated
D, [2011-03-15T07:47:37.611745 #13602] DEBUG -- : dummy: got event -  //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL215X3NleHlfYXBwbGljYXRpb258aHR0cDovL2xvY2FsaG9zdDozMDAwL3dlYmhvb2s=
D, [2011-03-15T07:47:37.611822 #13602] DEBUG -- : dummy: Found 0 possible matches for //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL215X3NleHlfYXBwbGljYXRpb258aHR0cDovL2xvY2FsaG9zdDozMDAwL3dlYmhvb2s=

Notice that the agent immediately saw the new watch. It also attempted to fire off the watch creation event itself against any registered watchers.

Now if we update my_sexy_application in any way, we'll see it get fired to the registered watcher:

I, [2011-03-15T07:49:26.462597 #13602]  INFO -- : http: Worker initiated
D, [2011-03-15T07:49:26.462756 #13602] DEBUG -- : http: got event - //noah/application/my_sexy_application
D, [2011-03-15T07:49:26.462955 #13602] DEBUG -- : http: Found 1 possible matches for //noah/application/my_sexy_application
I, [2011-03-15T07:49:26.463179 #13602]  INFO -- : http: Sending message to (http://localhost:3000/webhook) for pattern (//noah/application/my_sexy_application)
I, [2011-03-15T07:49:26.464138 #13602]  INFO -- : dummy: Worker initiated
D, [2011-03-15T07:49:26.464275 #13602] DEBUG -- : dummy: got event -  //noah/application/my_sexy_application
D, [2011-03-15T07:49:26.464480 #13602] DEBUG -- : dummy: Found 1 possible matches for //noah/application/my_sexy_application
E, [2011-03-15T07:49:26.464759 #13602] ERROR -- : http: Something went wrong with http://localhost:3000/webhook

Ignore the last line for a minute. It's simply telling you that attempting to notify the http endpoint failed. This is because it's not actually there right now.

What's exactly happening here? The watcher agent process has done the following:

  • Sent the pattern and message to each of the registered workers (Http and Dummy)
  • The registered workers each, independently, evaluated the event pattern against the pattern with which they were created
  • In the event of a pattern match (exact or higher level), the worker attempts to notify any endpoints of the event.

Let's add another http endpoint for //noah/application and see what the logs look like. We'll also add a dummy endpoint for //noah/application/my_sexy_app:

Request

curl -XPUT -d'{"endpoint":"dummy://dummyendpoint"}' http://localhost:5678/a/my_sexy_application/watch

Response

"Ly9ub2FoL2FwcGxpY2F0aW9uL215X3NleHlfYXBwfGR1bW15Oi8vZHVtbXllbmRwb2ludA=="

Log output

D, [2011-03-15T10:11:43.525180 #3471] DEBUG -- : Found new watches
D, [2011-03-15T10:11:43.525335 #3471] DEBUG -- : Current watch count: 1
D, [2011-03-15T10:11:43.528204 #3471] DEBUG -- : New watch count: 2
I, [2011-03-15T10:11:43.528452 #3471]  INFO -- : http: Worker initiated
D, [2011-03-15T10:11:43.528525 #3471] DEBUG -- : http: got event - //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL215X3NleHlfYXBwbGljYXRpb258ZHVtbXk6Ly9kdW1teWVuZHBvaW50
D, [2011-03-15T10:11:43.528672 #3471] DEBUG -- : http: Found 0 possible matches for //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL215X3NleHlfYXBwbGljYXRpb258ZHVtbXk6Ly9kdW1teWVuZHBvaW50
I, [2011-03-15T10:11:43.528786 #3471]  INFO -- : dummy: Worker initiated
D, [2011-03-15T10:11:43.528857 #3471] DEBUG -- : dummy: got event -  //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL215X3NleHlfYXBwbGljYXRpb258ZHVtbXk6Ly9kdW1teWVuZHBvaW50
D, [2011-03-15T10:11:43.528991 #3471] DEBUG -- : dummy: Found 0 possible matches for //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL215X3NleHlfYXBwbGljYXRpb258ZHVtbXk6Ly9kdW1teWVuZHBvaW50

Request

curl -XPUT -d'{"pattern":"//noah/application/","endpoint":"http://localhost:3001/webhook2"}' http://localhost:5678/w/

Response

{"action":"create","result":"success","id":"3","pattern":"//noah/application/","name":"Ly9ub2FoL2FwcGxpY2F0aW9uL3xodHRwOi8vbG9jYWxob3N0OjMwMDEvd2ViaG9vazI=","endpoint":"http://localhost:3001/webhook2","created_at":"2011-03-15 14:06:55 UTC","updated_at":"2011-03-15 14:06:55 UTC"}

Log output

D, [2011-03-15T10:12:39.309124 #3471] DEBUG -- : Found new watches
D, [2011-03-15T10:12:39.309281 #3471] DEBUG -- : Current watch count: 2
D, [2011-03-15T10:12:39.312886 #3471] DEBUG -- : New watch count: 3
I, [2011-03-15T10:12:39.313245 #3471]  INFO -- : http: Worker initiated
D, [2011-03-15T10:12:39.313323 #3471] DEBUG -- : http: got event - //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL3xodHRwOi8vbG9jYWxob3N0OjMwMDEvd2ViaG9vazI=
D, [2011-03-15T10:12:39.313506 #3471] DEBUG -- : http: Found 0 possible matches for //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL3xodHRwOi8vbG9jYWxob3N0OjMwMDEvd2ViaG9vazI=
I, [2011-03-15T10:12:39.313627 #3471]  INFO -- : dummy: Worker initiated
D, [2011-03-15T10:12:39.313696 #3471] DEBUG -- : dummy: got event -  //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL3xodHRwOi8vbG9jYWxob3N0OjMwMDEvd2ViaG9vazI=
D, [2011-03-15T10:12:39.313863 #3471] DEBUG -- : dummy: Found 0 possible matches for //noah/watcher/Ly9ub2FoL2FwcGxpY2F0aW9uL3xodHRwOi8vbG9jYWxob3N0OjMwMDEvd2ViaG9vazI=

Notice in the above examples that the watcher count increased immediately. As it stand we now have the following watches in place

Now let's modify //noah/application/my_sexy_application (via an ruby api) and see what happens:

a = Noah::Application.find(:name => 'my_sexy_application').first
a.save #This is essentially a noop. It just updates the `updated_at` timestamp

Log output

I, [2011-03-15T10:22:33.779671 #3824]  INFO -- : http: Worker initiated
D, [2011-03-15T10:22:33.779956 #3824] DEBUG -- : http: got event - //noah/application/my_sexy_application
D, [2011-03-15T10:22:33.780450 #3824] DEBUG -- : http: Found 3 possible matches for //noah/application/my_sexy_application
I, [2011-03-15T10:22:33.780814 #3824]  INFO -- : http: Sending message to (http://localhost:3000/webhook) for pattern (//noah/application/my_sexy_application)
I, [2011-03-15T10:22:33.782483 #3824]  INFO -- : dummy: Worker initiated
D, [2011-03-15T10:22:33.782707 #3824] DEBUG -- : dummy: got event -  //noah/application/my_sexy_application
D, [2011-03-15T10:22:33.783376 #3824] DEBUG -- : dummy: Found 3 possible matches for //noah/application/my_sexy_application
E, [2011-03-15T10:22:33.783878 #3824] ERROR -- : http: Something went wrong with http://localhost:3000/webhook
I, [2011-03-15T10:22:33.784376 #3824]  INFO -- : http: Sending message to (http://localhost:3001/webhook2) for pattern (//noah/application)
I, [2011-03-15T10:22:33.785511 #3824]  INFO -- : dummy: Sending message to: dummy://dummyendpoint for pattern: //noah/application/my_sexy_application
D, [2011-03-15T10:22:33.785733 #3824] DEBUG -- : dummy: message received: {"id":"1","name":"my_sexy_application","created_at":"2011-03-15 13:56:17 UTC","updated_at":"2011-03-15 14:22:33 UTC","configurations":[],"action":"update","pubcategory":"//noah/application/my_sexy_application"}
E, [2011-03-15T10:22:33.786097 #3824] ERROR -- : http: Something went wrong with http://localhost:3001/webhook2

Notice that the dummy agent got the message and doing what a dummy does, parroted it back to us.

Also notice the fact that notifications to both http endpoints were attempted (and failed because those endpoints aren't available.

The timing is interesting as well

  • 2011-03-15T10:22:33.779671 - http worker notified of message
  • 2011-03-15T10:22:33.780450 - event evaluated by http worker
  • 2011-03-15T10:22:33.780814 - event sent to http://localhost:3000/webhook
  • 2011-03-15T10:22:33.782483 - dummy worker notified of message
  • 2011-03-15T10:22:33.783376 - event evaluated by dummy worker
  • 2011-03-15T10:22:33.783878 - http worker finishes http://localhost:3000/webhoook call
  • 2011-03-15T10:22:33.784376 - event sent to http://localhost:3001/webhook2
  • 2011-03-15T10:22:33.785511 - event sent to dummy endpoint
  • 2011-03-15T10:22:33.785733 - dummy endpoint response
  • 2011-03-15T10:22:33.786097 - http worker finishes http://localhost:3001/webhook2 call

This is not amazingly dramatic and a better display would be talking to a remote endpoint with actual latency. There is still some work to be done tightening up the iterators. At this point though, no single worker class (http, dummy, whatever) processes endpoint calls synchronously.

External changes

Please note that changes outside of requests to the Noah Web API are noticed by the watcher agent as well. Here, I'll delete a watcher using the Ruby API:

Noah::Watcher[1].delete

Log output

D, [2011-03-15T10:43:13.945885 #3824] DEBUG -- : Found new watches
D, [2011-03-15T10:43:13.946181 #3824] DEBUG -- : Current watch count: 3
D, [2011-03-15T10:43:13.979275 #3824] DEBUG -- : New watch count: 2