GitHub user ottobackwards opened a pull request:
https://github.com/apache/metron/pull/873
METRON-1367 Stellar should have some instrumentation of function calls
This PR introduces the ability through a new `magic` command for a stellar
shell user to view the timing information for the last statement the shell
executed. The information provided is the total execution time, and the
execution time per stellar function.
At this point, only the stellar function execution has been timed, but it
is possible in the future to add timing to other parts of stellar, for example
to time how long lambdas take, or matches.
For example:
```bash
Stellar, Go!
Please note that functions are loading lazily in the background and will be
unavailable until loaded fully.
[Stellar]>>> Functions loaded, you may refer to functions now...
[Stellar]>>> hex:="91IMOR3F41BMUSJCCG======"
[Stellar]>>> if( STARTS_WITH(TO_UPPER(DECODE(hex,'BASE32HEX')), "HELLO"))
THEN TO_LOWER("OK") ELSE TO_LOWER("FFFF")
ok
[Stellar]>>> %timing
->execute : 113ms : 113017132
-->if( STARTS_WITH(TO_UPPER(DECODE(hex,'BASE32HEX')), "HELLO")) THEN
TO_LOWER("OK") ELSE TO_LOWER("FFFF") : 112ms : 112998881ns
--->DECODE : 8ms : 8572968ns
--->TO_UPPER : 0ms : 20018ns
--->STARTS_WITH : 0ms : 30586ns
--->TO_LOWER : 0ms : 19085ns
```
## StackWatch
A set of utility classes under the new package stellar.common.timing have
been added. These provide the `StackWatch` functionality.
StackWatch provides an abstraction over the Apache Commons StopWatch class
that allows callers to
create multiple named and possibly nested timing operations.
Since Stellar operations are executed in a queue and in isolation ( even a
Stellar statement that is nested such as TO_UPPER(TO_STRING()) is executed as
TO_STRING(), TO_UPPER, the benefit of the support for nested timing operations
is not utilized.
This class may be more generally useful to this and other projects, but I
am not sure where it would live since we wouldn't want it in common.
StackWatch uses a combination of `Deque` and a custom Tree implementation
to create, start and end timing operations.
A `Visitor` pattern is also implemented to allow for retrieving the results
after the completion of the operation.
See the StackWatch tests for examples of nested function timings.
The StackWatch is optionally available from the Stellar `Context` object.
## Testing
To test:
- Run the Stellar Shell, either from full_dev or using mvn exec ( here run
from metron-stellar/stellar-common after a mvn package )
```
> % mvn exec:java
-Dexec.mainClass="org.apache.metron.stellar.common.shell.StellarShell"
```
- run some stellar statements
- run the %timing function
- in full dev verify that data is processed normally through storm, and
that it shows in kibana
- [x] Is there a JIRA ticket associated with this PR? If not one needs to
be created at [Metron
Jira](https://issues.apache.org/jira/browse/METRON/?selectedTab=com.atlassian.jira.jira-projects-plugin:summary-panel).
- [x] Does your PR title start with METRON-XXXX where XXXX is the JIRA
number you are trying to resolve? Pay particular attention to the hyphen "-"
character.
- [x] Has your PR been rebased against the latest commit within the target
branch (typically master)?
### For code changes:
- [ ] Have you included steps to reproduce the behavior or problem that is
being changed or addressed?
- [x] Have you included steps or a guide to how the change may be verified
and tested manually?
- [x] Have you ensured that the full suite of tests and checks have been
executed in the root metron folder via:
```
mvn -q clean integration-test install && build_utils/verify_licenses.sh
```
- [x] Have you written or updated unit tests and or integration tests to
verify your changes?
- [ ] If adding new dependencies to the code, are these dependencies
licensed in a way that is compatible for inclusion under [ASF
2.0](http://www.apache.org/legal/resolved.html#category-a)?
- [ ] Have you verified the basic functionality of the build by building
and running locally with Vagrant full-dev environment or the equivalent?
### For documentation related changes:
- [x] Have you ensured that format looks appropriate for the output in
which it is rendered by building and verifying the site-book? If not then run
the following commands and the verify changes via
`site-book/target/site/index.html`:
```
cd site-book
mvn site
```
You can merge this pull request into a Git repository by running:
$ git pull https://github.com/ottobackwards/metron stellar_timing
Alternatively you can review and apply these changes as the patch at:
https://github.com/apache/metron/pull/873.patch
To close this pull request, make a commit to your master/trunk branch
with (at least) the following in the commit message:
This closes #873
----
commit 6d434941aeb492c8e836b59b56149f0efcceec2a
Author: Otto Fowler <[email protected]>
Date: 2017-12-17T05:42:19Z
initial StackWatch implementation
commit 2b21590cbc31001b20e135d68c34f304d3a8ac59
Author: Otto Fowler <[email protected]>
Date: 2017-12-17T07:00:30Z
integration with stackwatch, shell can time last stellar statement run
commit 0dcb5e394983d27aae1b2b7afa3c417f39649144
Author: Otto Fowler <[email protected]>
Date: 2017-12-17T14:53:56Z
add link to lang javadoc
commit c8303ffadbf642f087a82c71ce7ada37ce00808a
Author: Otto Fowler <[email protected]>
Date: 2017-12-17T15:04:10Z
readme
----
---
