Adds histograms for tracking Software Reporter logs uploads in SRT Fetcher.

chrome/browser/safe_browsing/srt_fetcher_win.cc

 // Copyright 2015 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "chrome/browser/safe_browsing/srt_fetcher_win.h"
 
 #include <stdint.h>
 
 #include <algorithm>
 #include <memory>
@@ skipping 39 matching lines @@
 #include "net/http/http_status_code.h"
 #include "net/url_request/url_fetcher.h"
 #include "net/url_request/url_fetcher_delegate.h"
 #include "net/url_request/url_request_context_getter.h"
 
 using content::BrowserThread;
 
 namespace safe_browsing {
 
 const wchar_t kSoftwareRemovalToolRegistryKey[] =
     L"Software\\Google\\Software Removal Tool";

[grt (UTC plus 2), 2016/09/16 15:59:20]

is this key used by Google Chrome, Google Chrome SxS, and Chromium? do you want
all three touching the same key? what would happen if beta and dev could be
installed alongside stable, and someone had stable, beta, dev, and canary all
running. would your metrics be sensible in this case?

[ftirelo, 2016/09/16 19:26:55]

Good catch! Thanks for noticing the issue!

The SwReporter component is only enabled for Google Chrome and Google Chrome
SxS, even though different forks of Chromium can remove this #ifdef:
https://cs.chromium.org/chromium/src/chrome/browser/chrome_browser_main.cc?l=666.
Even though the problem is not relevant today for the stable channel, it can
affect the stats for the Canary population, so the bug needs to be fixed. I
opened a bug to track this
(https://bugs.chromium.org/p/chromium/issues/detail?id=647763), but we will only
be able to change Chromium once the change in the CCT/SRT reaches most users.

 
 const wchar_t kCleanerSubKey[] = L"Cleaner";
 
 const wchar_t kEndTimeValueName[] = L"EndTime";
 const wchar_t kStartTimeValueName[] = L"StartTime";
 
 const char kExtendedSafeBrowsingEnabledSwitch[] =
     "extended-safebrowsing-enabled";
 
 const base::Feature kSwReporterExtendedSafeBrowsingFeature{
@@ skipping 34 matching lines @@
   SW_REPORTER_NO_LOCAL_STATE = 9,
   SW_REPORTER_NO_PROMPT_NEEDED = 10,
   SW_REPORTER_NO_PROMPT_FIELD_TRIAL = 11,
   SW_REPORTER_ALREADY_PROMPTED = 12,
   SW_REPORTER_RAN_DAILY = 13,
   SW_REPORTER_ADDED_TO_MENU = 14,
 
   SW_REPORTER_MAX,
 };
 
+// Used to send UMA information if Software Reporter logs uploads are enabled.

[Joe Mason, 2016/09/16 14:57:13]

"if" makes it sound like this is only sent if uploads are enabled. How about
"Used to send UMA information showing whether Software Reporter logs uploads are
enabled, or the reason why not."

[ftirelo, 2016/09/16 15:34:42]

Done.

+// Replicated in the histograms.xml file, so the order MUST NOT CHANGE.
+enum SwReporterLogsUploadsEnabled {
+  REPORTER_LOGS_UPLOADS_ENABLED = 0,
+  REPORTER_LOGS_UPLOADS_SBER_DISABLED = 1,
+  REPORTER_LOGS_UPLOADS_RECENTLY_SENT_LOGS = 2,
+  REPORTER_LOGS_UPLOADS_MAX,
+};
+
+// Used to send UMA information about the result of Software Reporter attempt to
+// uppload logs, when logs are enabled. Replicated in the histograms.xml file,

[Joe Mason, 2016/09/16 14:57:13]

Typos: "Reporter's attempt". "upload" logs.

[ftirelo, 2016/09/16 15:34:42]

Done.

+// so the order MUST NOT CHANGE.
+enum SwReporterLogsUploadsResult {

[grt (UTC plus 2), 2016/09/16 15:59:20]

...LogsUploadResult?

[ftirelo, 2016/09/16 19:26:55]

Done.

+  REPORTER_LOGS_UPLOADS_RESULT_SUCCESS = 0,

[grt (UTC plus 2), 2016/09/16 15:59:20]

it appears that the only value used is REPORTER_LOGS_UPLOADS_RESULT_MAX. if the
values can't be defined in a central place accessible both here and by the
reporter(s), then what do you think about defining the max here with a comment
pointing the reader toward the definitive location for the values (which should
also have a comment indicating that the max here must be updated in lock-step).

[grt (UTC plus 2), 2016/09/16 15:59:20]

...LOGS_UPLOAD_RESULT...?

[ftirelo, 2016/09/16 19:26:55]

Since there is no central place accessible by Chromium and by the reporter, I
will use the histogram enum sent in this CL as the definitive location. I'll
also change the reporter to use the histogram enum as a source.

[ftirelo, 2016/09/16 19:26:55]

Done.

+  REPORTER_LOGS_UPLOADS_RESULT_REQUEST_FAILED = 1,
+  REPORTER_LOGS_UPLOADS_RESULT_INVALID_RESPONSE = 2,
+  REPORTER_LOGS_UPLOADS_RESULT_TIMED_OUT = 3,
+  REPORTER_LOGS_UPLOADS_RESULT_INTERNAL_ERROR = 4,
+  REPORTER_LOGS_UPLOADS_RESULT_REPORT_TOO_LARGE = 5,
+  REPORTER_LOGS_UPLOADS_RESULT_NO_NETWORK = 6,
+  REPORTER_LOGS_UPLOADS_RESULT_MAX,
+};
+
 const char kRunningTimeErrorMetricName[] =
     "SoftwareReporter.RunningTimeRegistryError";
 
 SwReporterTestingDelegate* g_testing_delegate_ = nullptr;
 
 const wchar_t kScanTimesSubKey[] = L"ScanTimes";
 const wchar_t kFoundUwsValueName[] = L"FoundUws";
 const wchar_t kMemoryUsedValueName[] = L"MemoryUsed";
+const wchar_t kLogsUploadResultValueName[] = L"LogsUploadResult";
 
 const char kFoundUwsMetricName[] = "SoftwareReporter.FoundUwS";
 const char kFoundUwsReadErrorMetricName[] =
     "SoftwareReporter.FoundUwSReadError";
 const char kScanTimesMetricName[] = "SoftwareReporter.UwSScanTimes";
 const char kMemoryUsedMetricName[] = "SoftwareReporter.MemoryUsed";
+const char kLogsUploadEnabledMetricName[] =
+    "SoftwareReporter.LogsUploadEnabled";
+const char kLogsUploadsResultMetricName[] = "SoftwareReporter.LogsUploadResult";

[grt (UTC plus 2), 2016/09/16 15:59:20]

Uploads -> Upload

[ftirelo, 2016/09/16 19:26:55]

Done.

 
 // Reports metrics about the software reporter via UMA (and sometimes Rappor).
 class UMAHistogramReporter {
  public:
   UMAHistogramReporter() : UMAHistogramReporter(std::string()) {}
 
   explicit UMAHistogramReporter(const std::string& suffix)
       : suffix_(suffix),
         registry_key_(suffix.empty() ? kSoftwareRemovalToolRegistryKey
                                      : base::StringPrintf(
@@ skipping 179 matching lines @@
     base::win::RegKey reporter_key(HKEY_CURRENT_USER, registry_key_.c_str(),
                                    KEY_ENUMERATE_SUB_KEYS);
     if (reporter_key.Valid())
       reporter_key.DeleteKey(kScanTimesSubKey);
   }
 
   void RecordReporterStep(SwReporterUmaValue value) {
     RecordEnumerationHistogram("SoftwareReporter.Step", value, SW_REPORTER_MAX);
   }
 
+  void RecordLogsUploadEnabled(SwReporterLogsUploadsEnabled value) {
+    RecordEnumerationHistogram(kLogsUploadEnabledMetricName, value,
+                               REPORTER_LOGS_UPLOADS_MAX);
+  }
+
+  void RecordLogsUploadResult() {
+    base::win::RegKey reporter_key(HKEY_CURRENT_USER, registry_key_.c_str(),
+                                   KEY_QUERY_VALUE | KEY_SET_VALUE);

[grt (UTC plus 2), 2016/09/16 15:59:21]

combining the RegKey ctor with KEY_SET_VALUE will cause the ctor to create the
key if it doesn't exist. since you're just pulling data out here, i think it
makes sense to use the default ctor and explicitly call Open with the args you
care about.

[ftirelo, 2016/09/16 19:26:55]

Thanks for the hint! Fixed here and in the other places where the same issue
occurred. About using KEY_QUERY_VALUE, KEY_SET_VALUE, I'll leave it to when this
refactoring bug is handled:
https://bugs.chromium.org/p/chromium/issues/detail?id=641081&desc=2

+    DWORD logs_upload_result = 0;
+    if (reporter_key.Valid() &&
+        reporter_key.ReadValueDW(kLogsUploadResultValueName,
+                                 &logs_upload_result) == ERROR_SUCCESS) {
+      RecordEnumerationHistogram(
+          kLogsUploadsResultMetricName,
+          static_cast<SwReporterLogsUploadsResult>(logs_upload_result),

[grt (UTC plus 2), 2016/09/16 15:59:20]

cast this to a Sample rather than the enum since that's what
RecordEnumerationHistogram takes?

[ftirelo, 2016/09/16 19:26:55]

Done.

+          REPORTER_LOGS_UPLOADS_RESULT_MAX);
+      reporter_key.DeleteValue(kLogsUploadResultValueName);
+    }
+  }
+
  private:
   using Sample = base::HistogramBase::Sample;
 
   static constexpr base::HistogramBase::Flags kUmaHistogramFlag =
       base::HistogramBase::kUmaTargetedHistogramFlag;
 
   // Helper functions to record histograms with an optional suffix added to the
   // histogram name. The UMA_HISTOGRAM macros can't be used because they
   // require a constant string.
 
@@ skipping 336 matching lines @@
     if (g_testing_delegate_)
       g_testing_delegate_->NotifyLaunchReady();
 
     // Add switches for users who opted into extended Safe Browsing reporting.
     // The invocation object is changed locally right before the actual process
     // is launched because user status can change between this and the next run
     // for this ReporterRunner object. For example, the ReporterDone() callback
     // schedules the next run for a few days later, and the user might have
     // changed settings in the meantime.
     PrefService* local_state = g_browser_process->local_state();
-    if (next_invocation.flags & SwReporterInvocation::FLAG_SEND_REPORTER_LOGS &&
+    if (next_invocation.supported_behaviours &
+            SwReporterInvocation::REPORTER_BEHAVIOUR_SEND_REPORTER_LOGS &&

[grt (UTC plus 2), 2016/09/16 15:59:20]

wdyt about moving the enum out of SwReporterInvocation and use an enum class
instead so that this could be something like:
SwReporterBehaviour::SEND_REPORTER_LOGS
?

[ftirelo, 2016/09/16 19:26:55]

Done.

         local_state && ShouldSendReporterLogs(*local_state)) {
+      next_invocation.logs_upload_enabled = true;
       AddSwitchesForExtendedReporterUser(&next_invocation);
       // Set the local state value before the first attempt to run the
       // reporter, because we only want to upload logs once in the window
       // defined by |kDaysBetweenReporterLogsSent|. If we set with other local
       // state values after the reporter runs, we could send logs again too
       // quickly (for example, if Chrome stops before the reporter finishes).
       local_state->SetInt64(prefs::kSwReporterLastTimeSentReport,
                             base::Time::Now().ToInternalValue());
     }
 
@@ skipping 42 matching lines @@
 
     // If the reporter failed to launch, do not process the results. (The exit
     // code itself doesn't need to be logged in this case because
     // SW_REPORTER_FAILED_TO_START is logged in |LaunchAndWaitForExit|.)
     if (exit_code == kReporterFailureExitCode)
       return;
 
     UMAHistogramReporter uma(finished_invocation.suffix);
     uma.ReportVersion(version);
     uma.ReportExitCode(exit_code);
-    uma.ReportFoundUwS(finished_invocation.flags &
-                       SwReporterInvocation::FLAG_LOG_TO_RAPPOR);
+    uma.ReportFoundUwS(finished_invocation.supported_behaviours &
+                       SwReporterInvocation::REPORTER_BEHAVIOUR_LOG_TO_RAPPOR);
 
     PrefService* local_state = g_browser_process->local_state();
     if (local_state) {
-      if (finished_invocation.flags &
-          SwReporterInvocation::FLAG_LOG_EXIT_CODE_TO_PREFS)
+      if (finished_invocation.supported_behaviours &
+          SwReporterInvocation::REPORTER_BEHAVIOUR_LOG_EXIT_CODE_TO_PREFS)
         local_state->SetInteger(prefs::kSwReporterLastExitCode, exit_code);
       local_state->SetInt64(prefs::kSwReporterLastTimeTriggered,
                             base::Time::Now().ToInternalValue());
     }
     uma.ReportRuntime(reporter_running_time);
     uma.ReportScanTimes();
     uma.ReportMemoryUsage();
+    if (finished_invocation.logs_upload_enabled)
+      uma.RecordLogsUploadResult();
 
-    if (!(finished_invocation.flags &
-          SwReporterInvocation::FLAG_TRIGGER_PROMPT))
+    if (!(finished_invocation.supported_behaviours &
+          SwReporterInvocation::REPORTER_BEHAVIOUR_TRIGGER_PROMPT))
       return;
 
     if (!IsInSRTPromptFieldTrialGroups()) {
       // Knowing about disabled field trial is more important than reporter not
       // finding anything to remove, so check this case first.
       RecordReporterStepHistogram(SW_REPORTER_NO_PROMPT_FIELD_TRIAL);
       return;
     }
 
     if (exit_code != kSwReporterPostRebootCleanupNeeded &&
@@ skipping 58 matching lines @@
           FROM_HERE,
           base::Bind(&ReporterRunner::TryToRun, base::Unretained(this)),
           next_trigger - now);
     }
   }
 
   // Returns true if the experiment to send reporter logs is enabled, the user
   // opted into Safe Browsing extended reporting, and logs have been sent at
   // least |kSwReporterLastTimeSentReport| days ago.
   bool ShouldSendReporterLogs(const PrefService& local_state) {
-    if (!base::FeatureList::IsEnabled(kSwReporterExtendedSafeBrowsingFeature) ||
-        !SafeBrowsingExtendedReportingEnabled()) {
+    if (!base::FeatureList::IsEnabled(kSwReporterExtendedSafeBrowsingFeature))
+      return false;
+
+    UMAHistogramReporter uma;
+    if (!SafeBrowsingExtendedReportingEnabled()) {
+      uma.RecordLogsUploadEnabled(REPORTER_LOGS_UPLOADS_SBER_DISABLED);
       return false;
     }
 
     const base::Time now = base::Time::Now();
     const base::Time last_time_sent_logs = base::Time::FromInternalValue(
         local_state.GetInt64(prefs::kSwReporterLastTimeSentReport));
-    // Send the logs if the last send was in the future. This is intended as a
-    // measure for failure recovery, in case the time in local state is
-    // incorrectly set to the future.
-    if (last_time_sent_logs > now)
+    const base::Time next_time_send_logs =
+        last_time_sent_logs +
+        base::TimeDelta::FromDays(kDaysBetweenReporterLogsSent);
+    // Send the logs if the last send is the future or if the interval has
+    // passed. The former is intended as a measure for failure recovery, in
+    // case the time in local state is incorrectly set to the future.
+    if (last_time_sent_logs > now || next_time_send_logs <= now) {
+      uma.RecordLogsUploadEnabled(REPORTER_LOGS_UPLOADS_ENABLED);
       return true;
-    // Otherwise, send them if the interval has passed.
-    return last_time_sent_logs +
-               base::TimeDelta::FromDays(kDaysBetweenReporterLogsSent) <=
-           now;
+    }
+    uma.RecordLogsUploadEnabled(REPORTER_LOGS_UPLOADS_RECENTLY_SENT_LOGS);
+    return false;
   }
 
   void AddSwitchesForExtendedReporterUser(SwReporterInvocation* invocation) {
     invocation->command_line.AppendSwitch(kExtendedSafeBrowsingEnabledSwitch);
     invocation->command_line.AppendSwitchASCII(
         kChromeVersionSwitch, version_info::GetVersionNumber());
     invocation->command_line.AppendSwitchNative(
         kChromeChannelSwitch, base::IntToString16(ChannelAsInt()));
   }
 
@@ skipping 37 matching lines @@
 
 SwReporterInvocation SwReporterInvocation::FromCommandLine(
     const base::CommandLine& command_line) {
   SwReporterInvocation invocation;
   invocation.command_line = command_line;
   return invocation;
 }
 
 bool SwReporterInvocation::operator==(const SwReporterInvocation& other) const {
   return command_line.argv() == other.command_line.argv() &&
-         suffix == other.suffix && flags == other.flags;
+         suffix == other.suffix &&
+         supported_behaviours == other.supported_behaviours &&
+         logs_upload_enabled == other.logs_upload_enabled;
 }
 
 void RunSwReporters(const SwReporterQueue& invocations,
                     const base::Version& version,
                     scoped_refptr<base::TaskRunner> main_thread_task_runner,
                     scoped_refptr<base::TaskRunner> blocking_task_runner) {
   DCHECK(!invocations.empty());
   DCHECK(version.IsValid());
   ReporterRunner::ScheduleInvocations(invocations, version,
                                       std::move(main_thread_task_runner),
@@ skipping 16 matching lines @@
                                     KEY_QUERY_VALUE);
 
   return srt_cleaner_key.Valid() && srt_cleaner_key.GetValueCount() > 0;
 }
 
 void SetSwReporterTestingDelegate(SwReporterTestingDelegate* delegate) {
   g_testing_delegate_ = delegate;
 }
 
 }  // namespace safe_browsing