[Pharo-dev] Using ZnLogEvents to build a live updating requests per second monitor for an HTTP server

Sven Van Caekenberghe sven at stfx.eu
Mon Jun 16 11:29:58 EDT 2014


Hi,

Here is a concrete example of how cool object logging can be. In the current development version, Zinc HTTP Components announces a number of ZnLogEvent objects while either ZnClient or ZnServer operates. One of those is ZnServerTransactionEvent, which signals the completion of a single HTTP transaction (request/response pair) by the server. By subscribing to this specific event through Zinc's Announcer, we can simply count the number of transactions. If we report and reset this counter every second, we get a rudimentary live updating requests per second monitor, in about ten lines of code in a workspace !

Here is the setup:

| transactionCount transactionsPerSecond |
transactionCount := 0.
transactionsPerSecond := 0 asValueHolder inspectWithLabel: 'HTTP req/s'.
ZnLogEvent announcer 
  when: ZnServerTransactionEvent 
  do: [ :each | transactionCount := transactionCount + 1 ]
  for: #transactionCountDemo.
[ [
  1 second asDelay wait.
  transactionsPerSecond value: transactionCount.
  transactionCount := 0 ] repeat ] 
    forkAt: Processor userBackgroundPriority 
    named: #transactionCountDemo.

Then we start the server:
		
ZnServer startDefaultOn: 8080.

In a terminal, we use ab (the Apache Benchmark tool) to generate some load on the server (10K requests for 1K random data, using 4 concurrent threads):

$ ab -k -n 10240 -c 4 http://localhost:8080/random/1024

Here is a short 2 minute screencast showing this little demo in action (be sure to select the HD version):

  https://www.youtube.com/watch?v=gaUxPNq6_7c

It starts by showing how a AnnouncementSpy can be used to monitor the server starting up and handling a single request - the logging from the client is visible as well. The lines in the AnnouncementSpy are not just text, but full, detailed objects. We inspect and explore the same transaction from both the client and server perspective. 

Next is the demo of the live updating requests per second monitor with the load described above. You can see that both our counter and ab report approximately the same number: about 800-900 req/s.

And finally, here is the cleanup code:

ZnLogEvent announcer unsubscribe: #transactionCountDemo.
ZnServer stopDefault.
Process allInstances select: [ :each | each name = #transactionCountDemo ] thenDo: #terminate.

Note that by using other data elements in the ZnServerTransactionEvent we could track bytes transferring in or out, rates of failure, slow requests and so. There are lots of possibilities with object logging left to explore, as well as lots to learn. 

Sven




More information about the Pharo-dev mailing list