TabManager: Add more logs to understand how it works when memory is low.

chrome/browser/memory/tab_manager_delegate_chromeos.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/memory/tab_manager_delegate_chromeos.h"
 
 #include <math.h>
 #include <stdint.h>
 
 #include <algorithm>
@@ skipping 103 matching lines @@
     default:
       return os << "NOT_IMPLEMENTED_ERROR";
   }
   return os;
 }
 
 // TabManagerDelegate::Candidate implementation.
 std::ostream& operator<<(
     std::ostream& out, const TabManagerDelegate::Candidate& candidate) {
   if (candidate.app()) {
-    out << "app " << candidate.app()->pid() << " ("
-        << candidate.app()->process_name() << ")"
-        << ", process_state " << candidate.app()->process_state()
-        << ", is_focused " << candidate.app()->is_focused()
-        << ", lastActivityTime " << candidate.app()->last_activity_time();
+    const auto& app = candidate.app();

[teravest, 2017/05/18 20:11:55]

nit: Mind using the type explicitly here? It's not obvious that the type of app
is arc::ArcProcess

[Yusuke Sato, 2017/05/18 20:27:36]

Also, const auto& failed git-cl try. FYI.

[cylee1, 2017/05/18 21:10:30]

Done.

+    out << "app " << app->process_name() << " (" << app->pid() << ")"

[Yusuke Sato, 2017/05/18 20:24:51]

How about moving this to c/b/c/arc/process/arc_process.h and .cc? Either
ToString() or operator<< seems fine to me.

[cylee1, 2017/05/18 21:10:30]

Done.

+        << ", process_state: " << app->process_state()

[Yusuke Sato, 2017/05/18 20:24:51]

Can you stringify the state number?

[Yusuke Sato, 2017/05/18 20:31:39]

nvm, it's already done in the mojo-generated operator<<.

[cylee1, 2017/05/18 21:10:30]

It's already printed like
ProcessState::PERSISTENT

+        << ", is_focused: " << app->is_focused()
+        << ", last_activity_time: " << app->last_activity_time();

[Yusuke Sato, 2017/05/18 20:24:51]

Can you also dump packages_ vector?

[cylee1, 2017/05/18 21:10:30]

Done.

   } else if (candidate.tab()) {
-    out << "tab " << candidate.tab()->renderer_handle;
+    const auto& tab = candidate.tab();

[teravest, 2017/05/18 20:11:55]

nit: Mind using the type explicitly here? It's not obvious that the type of tab
is TabStats*

[cylee1, 2017/05/18 21:10:30]

Done.

+    out << "tab " << tab->title << " (" << tab->renderer_handle << ")"

[Yusuke Sato, 2017/05/18 20:24:52]

How did you select the variables to dump?
https://chromium.googlesource.com/chromium/src/+/3f7781da5e43f9c32b5e4654e08b...
checks more. What are we trying to understand from the new log?

[cylee1, 2017/05/18 21:10:30]

I tried to select most relevant fields from my experience of reading system logs
from feedback report.
I understand your point here, but I'm little afraid to over spam the log if I
add more fields. I'd like to keep it simple for now. If to add more fields, 
https://chromium.googlesource.com/chromium/src/+/3f7781da5e43f9c32b5e4654e08b...
would be my top consideration.

[Yusuke Sato, 2017/05/18 21:42:49]

Acknowledged.

+        << ", oom_score: " << tab->oom_score
+        << ", is_discarded: " << tab->is_discarded
+        << ", discard_count: " << tab->discard_count
+        << ", last_active: " << tab->last_active;
   }
   out << ", process_type " << candidate.process_type();
   return out;
 }
 
 TabManagerDelegate::Candidate& TabManagerDelegate::Candidate::operator=(
     TabManagerDelegate::Candidate&& other) {
   tab_ = other.tab_;
   app_ = other.app_;
   process_type_ = other.process_type_;
@@ skipping 443 matching lines @@
     const std::vector<arc::ArcProcess>& arc_processes) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   VLOG(2) << "LowMemoryKillImpl";
 
   const std::vector<TabManagerDelegate::Candidate> candidates =
       GetSortedCandidates(tab_list, arc_processes);
 
   int target_memory_to_free_kb = mem_stat_->TargetMemoryToFreeKB();
   const TimeTicks now = TimeTicks::Now();
 
+  MEMORY_LOG(ERROR) << "List of all low memory kill candidates:";

[Yusuke Sato, 2017/05/18 20:24:51]

Mention that the list is sorted?

[cylee1, 2017/05/18 21:10:30]

Done.

+  for (auto it = candidates.rbegin(); it != candidates.rend(); ++it) {
+    MEMORY_LOG(ERROR) << *it;
+  }
   // Kill processes until the estimated amount of freed memory is sufficient to
   // bring the system memory back to a normal level.
   // The list is sorted by descending importance, so we go through the list
   // backwards.
   for (auto it = candidates.rbegin(); it != candidates.rend(); ++it) {
     MEMORY_LOG(ERROR) << "Target memory to free: " << target_memory_to_free_kb
                       << " KB";
     if (target_memory_to_free_kb <= 0)
       break;
     // Never kill selected tab, foreground app, and important apps regardless of
     // whether they're in the active window. Since the user experience would be
     // bad.
     ProcessType process_type = it->process_type();
     if (process_type <= ProcessType::IMPORTANT_APP) {
       MEMORY_LOG(ERROR) << "Skipped killing " << *it;

[Yusuke Sato, 2017/05/18 20:24:52]

Using *it inside the second loop might be too spammy. It'll end up dumping many
of the candidates twice. Can you change L617, L622, etc., to

 << it->ToShortString();

or something like that to only dump a process name and its PID?

[cylee1, 2017/05/18 21:10:30]

Done.

       continue;
     }
     if (it->app()) {
       if (IsRecentlyKilledArcProcess(it->app()->process_name(), now)) {
         MEMORY_LOG(ERROR) << "Avoided killing " << *it << " too often";
         continue;
       }
       int estimated_memory_freed_kb =
           mem_stat_->EstimatedMemoryFreedKB(it->app()->pid());
       if (KillArcProcess(it->app()->nspid())) {
@@ skipping 151 matching lines @@
     priority += priority_increment;
   }
 
   if (oom_scores_to_change.size()) {
     GetDebugDaemonClient()->SetOomScoreAdj(
         oom_scores_to_change, base::Bind(&OnSetOomScoreAdj));
   }
 }
 
 }  // namespace memory