Sometimes, the metric data will be duplicated. This behavior doesn't always happen. ### Steps: 1. Modify the advanced_telemetry.js and reset gaia AT.REPORT_URL = 'https://incoming-telemetry-mozilla-org-koge918u861h.runscope.net/submit/telemetry'; AT.REPORT_INTERVAL = 1 * 60 * 1000; AT.REPORT_TIMEOUT = 20 * 1000; AT.RETRY_INTERVAL = 20 * 1000; AT.MERGE_INTERVAL = 1 * 60 * 1000; 2. Install app in device via Web IDE. The app id is app://5e19fab8-6b47-ae4a-ae34-c4abf48fda8a/manifest.webapp 3. Perform 1 action and gather logs for 1 minute. Actual result: The metric data is duplicated. Expected result: The metrics should not be duplicated. I extract the logs here: 2000 09-30 13:08:28.450 1748 1748 I GeckoConsole: Content JS LOG: [AdvancedTelemetry] Telemetry URL is: https://incoming-telemetry-mozilla-org-koge918u861h.runscope.net/submit/telemetry/ 2690 09-30 13:09:15.690 2776 2776 I ToDo : Content JS INFO: telemetry|mylinear|5 2787 09-30 13:09:28.500 1748 1748 I GeckoConsole: Content JS LOG: [AdvancedTelemetry]TOOLS_HUD_WARNINGS":{},"DEVTOOLS_HUD_ERRORS":{}},"addonHistograms":{"DEVTOOLS_HUD_CUSTOM_5E19FAB8-6B47-AE4A-AE34-C4ABF48FDA8A/MANIFEST_MYCOUNT":{"min":1,"max":2,"histogram_type":4,"sum":0,"sum_squares_lo":0,"sum_squares_hi":0,"ranges":[0,1,2],"counts":[0,0,0],"log_sum":null,"log_sum_squares":null},"DEVTOOLS_HUD_CUSTOM_5E19FAB8-6B47-AE4A-AE34-C4ABF48FDA8A/MANIFEST_MYLINEAR":{"min":5,"max":1000,"histogram_type":1,"sum":10,"sum_squares_lo":25,"sum_squares_hi":0,"ranges":[0,5,105,204,304,403,503,602,702,801,901,1000],"counts":[0,2,0,0,0,0,0,0,0,0,0,0],"log_sum":null,"log_sum_squares":null},"DEVTOOLS_HUD_CUSTOM_5E19FAB8-6B47-AE4A-AE34-C4ABF48FDA8A/MANIFEST_MYEXP":{"min":1,"max":500,"histogram_type":0,"sum":0,"log_sum":0,"log_sum_squares":0,"ranges":[0,1,8,63,500],"counts":[0,0,0,0,0]}}}} 2789 09-30 13:09:28.510 1748 1748 I GeckoConsole: Content JS LOG: [AdvancedTelemetry] Telemetry URL is: https://incoming-telemetry-mozilla-org-koge918u861h.runscope.net/ From the log, we can see line 2000: the data is sent to server. line 2690: trigger one action for histogram type = linear. Call add(5). line 2787: From the payload, we can see the count is 2 and sum is 10. line 2789: The data is sent to server. There is only one add action between line 2000(09-30 13:08:28) & line 2789(09-30 13:09:28.510). Not sure why the metric is duplicated. Build ID 20150930005445 Gaia Revision fa63936cbd0347353b00f2ddd0e0d0bddfa4192c Gaia Date 2015-09-30 02:06:23 Gecko Revision https://hg.mozilla.org/mozilla-central/rev/891ee0d0ba3ec42b6484cf0205b3c95e21c58f74 Gecko Version 44.0a1 Device Name aries Firmware(Release) 4.4.2

Hi Russ, Can you take a look at this? btw, my test app is in https://github.com/gerrycfchang/firefoxos-quick-start.git

Hi Gerry, I will try and reproduce this. (NI to myself) Since you're saying it's intermittent, is it still reproducible when the merge_interval is less than the report interval? Thanks, -tamara

Clearing NI as Tamara is looking into this.

Hi Gerry, Do you have instructions to get the timestamps into my logs? I can reproduce the problem. It seems to occur when the REPORT_INTERVAL and MERGE_INTERVALS line up. At this point, I'm not sure if this is intermittent because it's coincidental or if there is something else going on with the events being sent back from Gecko->Gaia. Timestamps would help me tremendously. thanks, -tamara

I have a fix and am preparing a patch.

Comment on attachment 8668485 [details] [gaia] tamarahills:bugfix/1209860-intermittent-data-duplication > mozilla-b2g:master Hi Russ, We have a merge interval (more frequent) and a transmit interval (less frequent). What was missing was after a merge, there was no call to clear out the gecko metrics; hence when there was a transmit, the old metrics would be added again to the previously merged metrics. So, I fixed this by making a call to clearPayload() after merging. This clears out the metrics in gecko. I modified clearPayload() to take a flag showing whether the asyncStorage shoudl be cleared out or not. It should be cleared out after a transmit (since we're starting over) and not cleared after a merge. I added a test for this. Thanks for your feedback. -tamara

Canceling ni for gchang as |adb logcat -v threadtime| was his irc suggestion to get the timestamps in teh logs. This helped. Thanks

Comment on attachment 8668485 [details] [gaia] tamarahills:bugfix/1209860-intermittent-data-duplication > mozilla-b2g:master f+ on the fix. I've left a comment in the PR about the merging logic, something I just noticed, not related to this fix.

Comment on attachment 8668485 [details] [gaia] tamarahills:bugfix/1209860-intermittent-data-duplication > mozilla-b2g:master Hi Marshall, This is a pretty simple patch that makes sure we call clearPayload() to wipe out the gecko metrics after a merge. This avoids the duplication. Essentially in a merge case, we need to merge, save to async storage, and clear the gecko metrics. In a transmit case, we need to merge, transmit, and clear the gecko metrics and delete the asyncStorage. Thanks, -tamara

try run: https://treeherder.mozilla.org/#/jobs?repo=gaia&revision=809a51d26c1d4b92aa5f4400d8b8a6c63262ce68

Verified @ Build ID 20151018193102 Gaia Revision 29e70d226211bc5a256b2818f4bcb7a7c98b1f1a Gaia Date 2015-10-19 02:20:31 Gecko Revision https://hg.mozilla.org/mozilla-central/rev/d1a89632277fbaaf470c90a35573776048988f2d Gecko Version 44.0a1 Device Name aries Firmware(Release) 4.4.2 Verify result: The metric data is not duplicated.