Using ZnLogEvents to build a live updating requests per second monitor for an HTTP server
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
This is really cool, and could enable live instrumentation for server health monitoring. Esteban A. Maringolo 2014-06-16 12:29 GMT-03:00 Sven Van Caekenberghe <sven@stfx.eu>:
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
Very nice example! Doru On Mon, Jun 16, 2014 at 5:29 PM, Sven Van Caekenberghe <sven@stfx.eu> wrote:
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
-- www.tudorgirba.com "Every thing has its own flow"
I was thinking of getting statistics of the usage of our REST API. With this technique I could do it without modifying my current classes, in an orthogonal way. This opens up many possibilities. Regards! Esteban A. Maringolo 2014-06-16 17:33 GMT-03:00 Tudor Girba <tudor@tudorgirba.com>:
Very nice example!
Doru
On Mon, Jun 16, 2014 at 5:29 PM, Sven Van Caekenberghe <sven@stfx.eu> wrote:
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
-- www.tudorgirba.com
"Every thing has its own flow"
Sven, this is a nice example and the video is great. It shows again what we can do if we model problem domains properly. I really need to have a look at your and Doruâs code. well done, Norbert Am 16.06.2014 um 17:29 schrieb Sven Van Caekenberghe <sven@stfx.eu>:
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
participants (4)
-
Esteban A. Maringolo -
Norbert Hartl -
Sven Van Caekenberghe -
Tudor Girba