Details

    • Sub-task
    • Status: Closed
    • Major
    • Resolution: Fixed
    • 0.6
    • 0.7
    • metrics
    • None

    Attachments

      1. FALCON-676.patch
        1.0 kB
        Ajay Yadav
      2. FALCON-676-v1.patch
        2 kB
        Ajay Yadav
      3. FALCON-676-v2.patch
        2 kB
        Ajay Yadav
      4. FALCON-676-v3.patch
        3 kB
        Ajay Yadav
      5. FALCON-676-v4.patch
        3 kB
        Ajay Yadav
      6. FALCON-676-v5.patch
        3 kB
        Ajay Yadav

      Activity

        ajayyadava Ajay Yadav added a comment -

        Assigning it to myself. Will upload a patch shortly.

        ajayyadava Ajay Yadav added a comment - Assigning it to myself. Will upload a patch shortly.
        ajayyadava Ajay Yadav added a comment -

        svenkat Can you please review the submitted patch?

        ajayyadava Ajay Yadav added a comment - svenkat Can you please review the submitted patch?
        bvellanki Balu Vellanki added a comment - - edited

        After applying patch and running end2end, the generated metrics in falcon.application.log looks like this.

        2014-11-18 20:50:48,182 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.graph.execute.calls, count=3 (metrics:104)
        2014-11-18 20:50:48,182 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.graph.getNew.calls, count=3 (metrics:104)
        2014-11-18 20:50:48,183 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.graph.hasDeletions.calls, count=3 (metrics:104)
        2014-11-18 20:50:48,183 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.vertex.execute.calls, count=8 (metrics:104)
        2014-11-18 20:50:48,183 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.vertex.getNew.calls, count=8 (metrics:104)
        2014-11-18 20:50:48,183 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.vertex.hasDeletions.calls, count=8 (metrics:104)
        2014-11-18 20:50:48,184 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.stores.getSlice.calls, count=9 (metrics:104)
        2014-11-18 20:50:48,184 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.stores.getSlice.entries-returned, count=52 (metrics:104)
        2014-11-18 20:50:48,184 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.sys.CachedKeyColumnValueStore.misses, count=8 (metrics:104)
        2014-11-18 20:50:48,184 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.sys.CachedKeyColumnValueStore.retrievals, count=8 (metrics:104)
        2014-11-18 20:50:48,185 INFO  - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.tx.begin, count=1 (metrics:104)
        2014-11-18 20:50:48,185 INFO  - [metrics-logger-reporter-thread-1:] ~ type=HISTOGRAM, name=com.thinkaurelius.titan.stores.getSlice.entries-histogram, count=9, min=1, max=11, mean=5.777777777777778, stddev=5.044248650140518, median=4.0, p75=11.0, p95=11.0, p98=11.0, p999=11.0 (metrics:108)
        2014-11-18 20:50:48,185 INFO  - [metrics-logger-reporter-thread-1:] ~ type=TIMER, name=com.thinkaurelius.titan.query.graph.execute.time, count=3, min=0.03362, max=10.229743, mean=3.4533063333333334, stddev=5.868650667575326, median=0.09655599999999999, p75=10.229743, p95=10.229743, p98=10.229743, p999=10.229743, mean_rate=10.229743, m1=0.025108012233780237, m5=0.10426436607026719, m15=0.42281285383122813, rate_unit=0.5339290625928143, duration_unit=events/second (metrics:108)
        
        2014-11-18 20:53:48,192 INFO  - [metrics-logger-reporter-thread-1:] ~ type=TIMER, name=com.thinkaurelius.titan.stores.getSlice.time, count=9, min=0.347985, max=1.3848669999999998, mean=0.8925124444444444, stddev=0.4509201914402678, median=0.828805, p75=1.334384, p95=1.3848669999999998, p98=1.3848669999999998, p999=1.3848669999999998, mean_rate=1.3848669999999998, m1=0.030051778950274975, m5=0.01692641259269143, m15=0.7078332975634773, rate_unit=1.3187384419305865, duration_unit=events/second (metrics:108)
        

        ajayyadava What are we collecting above metrics for?
        I suggest writing the logs into a separate file. It should not be going into falcon.application.log.

        bvellanki Balu Vellanki added a comment - - edited After applying patch and running end2end, the generated metrics in falcon.application.log looks like this. 2014-11-18 20:50:48,182 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.graph.execute.calls, count=3 (metrics:104) 2014-11-18 20:50:48,182 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.graph.getNew.calls, count=3 (metrics:104) 2014-11-18 20:50:48,183 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.graph.hasDeletions.calls, count=3 (metrics:104) 2014-11-18 20:50:48,183 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.vertex.execute.calls, count=8 (metrics:104) 2014-11-18 20:50:48,183 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.vertex.getNew.calls, count=8 (metrics:104) 2014-11-18 20:50:48,183 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.query.vertex.hasDeletions.calls, count=8 (metrics:104) 2014-11-18 20:50:48,184 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.stores.getSlice.calls, count=9 (metrics:104) 2014-11-18 20:50:48,184 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.stores.getSlice.entries-returned, count=52 (metrics:104) 2014-11-18 20:50:48,184 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.sys.CachedKeyColumnValueStore.misses, count=8 (metrics:104) 2014-11-18 20:50:48,184 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.sys.CachedKeyColumnValueStore.retrievals, count=8 (metrics:104) 2014-11-18 20:50:48,185 INFO - [metrics-logger-reporter-thread-1:] ~ type=COUNTER, name=com.thinkaurelius.titan.tx.begin, count=1 (metrics:104) 2014-11-18 20:50:48,185 INFO - [metrics-logger-reporter-thread-1:] ~ type=HISTOGRAM, name=com.thinkaurelius.titan.stores.getSlice.entries-histogram, count=9, min=1, max=11, mean=5.777777777777778, stddev=5.044248650140518, median=4.0, p75=11.0, p95=11.0, p98=11.0, p999=11.0 (metrics:108) 2014-11-18 20:50:48,185 INFO - [metrics-logger-reporter-thread-1:] ~ type=TIMER, name=com.thinkaurelius.titan.query.graph.execute.time, count=3, min=0.03362, max=10.229743, mean=3.4533063333333334, stddev=5.868650667575326, median=0.09655599999999999, p75=10.229743, p95=10.229743, p98=10.229743, p999=10.229743, mean_rate=10.229743, m1=0.025108012233780237, m5=0.10426436607026719, m15=0.42281285383122813, rate_unit=0.5339290625928143, duration_unit=events/second (metrics:108) 2014-11-18 20:53:48,192 INFO - [metrics-logger-reporter-thread-1:] ~ type=TIMER, name=com.thinkaurelius.titan.stores.getSlice.time, count=9, min=0.347985, max=1.3848669999999998, mean=0.8925124444444444, stddev=0.4509201914402678, median=0.828805, p75=1.334384, p95=1.3848669999999998, p98=1.3848669999999998, p999=1.3848669999999998, mean_rate=1.3848669999999998, m1=0.030051778950274975, m5=0.01692641259269143, m15=0.7078332975634773, rate_unit=1.3187384419305865, duration_unit=events/second (metrics:108) ajayyadava What are we collecting above metrics for? I suggest writing the logs into a separate file. It should not be going into falcon.application.log.
        ajayyadava Ajay Yadav added a comment -

        Thanks bvellanki for reviewing this. These changes are to capture graph db metrics. You are right that they should be logged separately. Will make the changes and submit another patch.

        ajayyadava Ajay Yadav added a comment - Thanks bvellanki for reviewing this. These changes are to capture graph db metrics. You are right that they should be logged separately. Will make the changes and submit another patch.
        ajayyadava Ajay Yadav added a comment -

        Addressed the review comments.

        ajayyadava Ajay Yadav added a comment - Addressed the review comments.
        sowmyaramesh Sowmya Ramesh added a comment -

        ajayyadava: From http://thinkaurelius.github.io/titan/wikidoc/0.4.0/Titan-Performance-and-Monitoring.html the property to enable for metrics is

        # Required
        metrics.enable-basic-metrics = true
        

        I am not sure where *.falcon.graph.metrics.enabled = true is used. I know that falcon use prefix "falcon.graph." to get graph configuration, but I couldn't find any titan doc for "metrics.enabled" property. Also, can you please add comment for *.falcon.graph.metrics.slf4j.interval so that it will be informative to the user if he wants to change the config value.

        sowmyaramesh Sowmya Ramesh added a comment - ajayyadava : From http://thinkaurelius.github.io/titan/wikidoc/0.4.0/Titan-Performance-and-Monitoring.html the property to enable for metrics is # Required metrics.enable-basic-metrics = true I am not sure where *.falcon.graph.metrics.enabled = true is used. I know that falcon use prefix "falcon.graph." to get graph configuration, but I couldn't find any titan doc for "metrics.enabled" property. Also, can you please add comment for *.falcon.graph.metrics.slf4j.interval so that it will be informative to the user if he wants to change the config value.
        ajayyadava Ajay Yadav added a comment -

        sowmyaramesh It's confusing isn't it? I used the 0.5.0 configurations and they happened to work. It's tested by me and Balu(see comments above). I have added the necessary documentation for the configs.

        ajayyadava Ajay Yadav added a comment - sowmyaramesh It's confusing isn't it? I used the 0.5.0 configurations and they happened to work. It's tested by me and Balu(see comments above). I have added the necessary documentation for the configs.
        ajayyadava Ajay Yadav added a comment -

        Moving it out of scope of 0.6.1

        ajayyadava Ajay Yadav added a comment - Moving it out of scope of 0.6.1

        ajayyadava Where this metrics will be logged ? I think they will be still logged in falcon.application.log . Can you please document some important metrics that titan will emit like no of transactions begin, no of transaction committed etc , it will be very helpful for the users.

        pavan kumar pavan kumar kolamuri added a comment - ajayyadava Where this metrics will be logged ? I think they will be still logged in falcon.application.log . Can you please document some important metrics that titan will emit like no of transactions begin, no of transaction committed etc , it will be very helpful for the users.
        ajayyadava Ajay Yadav added a comment -

        pavan kumar Thanks for the review. The metrics will be logged where all metrics are being logged, using the METRIC logger, which is used to log all the metrics for falcon and I have tested this behavior. Also, what is being emitted is not in control of falcon so I don't think it makes sense to document particular instances of the metrics as it might change over time. I will however document that titan metrics are getting logged in the operations.twiki.

        ajayyadava Ajay Yadav added a comment - pavan kumar Thanks for the review. The metrics will be logged where all metrics are being logged, using the METRIC logger, which is used to log all the metrics for falcon and I have tested this behavior. Also, what is being emitted is not in control of falcon so I don't think it makes sense to document particular instances of the metrics as it might change over time. I will however document that titan metrics are getting logged in the operations.twiki.
        ajayyadava Ajay Yadav added a comment -

        Added documentation.

        ajayyadava Ajay Yadav added a comment - Added documentation.

        ajayyadava I have applied this patch and run , titan metrics are coming in both application.log and metric.log , please check if i am missing something and if possible we should avoid this since titan metric logs are huge.

        pavan kumar pavan kumar kolamuri added a comment - ajayyadava I have applied this patch and run , titan metrics are coming in both application.log and metric.log , please check if i am missing something and if possible we should avoid this since titan metric logs are huge.

        I think its because the Logger initialized in MetadataMappingService.java is a classname which defaults to appender file->application.log, can we try changing it to LoggerFactory.getLogger("METRIC");

        shaik.idris Shaik Idris Ali added a comment - I think its because the Logger initialized in MetadataMappingService.java is a classname which defaults to appender file->application.log, can we try changing it to LoggerFactory.getLogger("METRIC");
        ajayyadava Ajay Yadav added a comment -

        Titan db doesn't use that logger for logging metrics. It seems more of an issue with log4j.xml in Pavan's environment. Will check this today.

        ajayyadava Ajay Yadav added a comment - Titan db doesn't use that logger for logging metrics. It seems more of an issue with log4j.xml in Pavan's environment. Will check this today.
        ajayyadava Ajay Yadav added a comment -

        It was because additivity="false" was not set on the metric logger and hence ALL metrics were getting introduced in multiple files.

        ajayyadava Ajay Yadav added a comment - It was because additivity="false" was not set on the metric logger and hence ALL metrics were getting introduced in multiple files.

        Routing the metrics to log isn't very useful. Perhaps we should try the graphite bridge as the default. Also can we fix the additivity in the logger configs while we are at it (perhaps in a different jira)

        sriksun Srikanth Sundarrajan added a comment - Routing the metrics to log isn't very useful. Perhaps we should try the graphite bridge as the default. Also can we fix the additivity in the logger configs while we are at it (perhaps in a different jira)
        ajayyadava Ajay Yadav added a comment -

        sriksun
        Makes sense. Will do the necessary changes.

        ajayyadava Ajay Yadav added a comment - sriksun Makes sense. Will do the necessary changes.
        ajayyadava Ajay Yadav added a comment -

        Added sample comments to show how to enable metrics through graphite and other mechanisms. By default these properties are commented. If someone needs, they can uncomment the properties and provide appropriate values (like graphite host etc.) and enable metrics for titan db.

        ajayyadava Ajay Yadav added a comment - Added sample comments to show how to enable metrics through graphite and other mechanisms. By default these properties are commented. If someone needs, they can uncomment the properties and provide appropriate values (like graphite host etc.) and enable metrics for titan db.
        ajayyadava Ajay Yadav added a comment -

        Had to rebase the patch. Uploading the rebased patch. Will commit it shortly.

        ajayyadava Ajay Yadav added a comment - Had to rebase the patch. Uploading the rebased patch. Will commit it shortly.
        ajayyadava Ajay Yadav added a comment -

        Committed to master. Thanks bvellanki for diligent review and testing. Thanks sowmyaramesh, pavan kumar and sriksun for the review and excellent suggestions.

        ajayyadava Ajay Yadav added a comment - Committed to master. Thanks bvellanki for diligent review and testing. Thanks sowmyaramesh , pavan kumar and sriksun for the review and excellent suggestions.

        People

          ajayyadava Ajay Yadav
          svenkat Venkatesh Seetharam
          Votes:
          0 Vote for this issue
          Watchers:
          7 Start watching this issue

          Dates

            Created:
            Updated:
            Resolved: