Dump touchpad event logs for touch log source

ui/events/ozone/evdev/input_device_factory_evdev.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 "ui/events/ozone/evdev/input_device_factory_evdev.h"
 
 #include <fcntl.h>
 #include <linux/input.h>
+#include <locale>
 
+#include "base/bind.h"
+#include "base/command_line.h"
+#include "base/files/file_util.h"
+#include "base/process/launch.h"
 #include "base/stl_util.h"
 #include "base/strings/stringprintf.h"
 #include "base/thread_task_runner_handle.h"
 #include "base/threading/worker_pool.h"
 #include "base/time/time.h"
 #include "base/trace_event/trace_event.h"
 #include "ui/events/devices/device_data_manager.h"
 #include "ui/events/devices/device_util_linux.h"
 #include "ui/events/ozone/evdev/device_event_dispatcher_evdev.h"
 #include "ui/events/ozone/evdev/event_converter_evdev_impl.h"
 #include "ui/events/ozone/evdev/event_device_info.h"
 #include "ui/events/ozone/evdev/tablet_event_converter_evdev.h"
 #include "ui/events/ozone/evdev/touch_event_converter_evdev.h"
 
 #if defined(USE_EVDEV_GESTURES)
 #include "ui/events/ozone/evdev/libgestures_glue/event_reader_libevdev_cros.h"
 #include "ui/events/ozone/evdev/libgestures_glue/gesture_interpreter_libevdev_cros.h"
 #include "ui/events/ozone/evdev/libgestures_glue/gesture_property_provider.h"
 #endif
 
 #ifndef EVIOCSCLOCKID
 #define EVIOCSCLOCKID _IOW('E', 0xa0, int)
 #endif
 
 namespace ui {
 
 namespace {
 
+// Binary paths.
+const char kGzipCommand[] = "/bin/gzip";
+const char kDateCommand[] = "/bin/date";
+
+// Touch event log paths.
+const char kTouchpadGestureLogPath[] =
+    "/var/log/xorg/touchpad_activity_log.txt";
+const char kTouchpadEvdevLogPath[] = "/var/log/xorg/cmt_input_events.dat";

[spang, 2015/02/02 21:43:16]

Are you planning to make a ChromeOS change to create /var/log/xorg & make it
writable by chronos? Otherwise I don't think you'll be able to write into this
directory.

[Shecky Lin, 2015/02/03 08:20:14]

Yeah, sorry, this is probably the problem I am running into. Thanks.

Do you know where I can add it back though? We were using these directories for
touch event logs in the old X11 world.

Or it might be better to just write to a new directory that we have access to.
What directories do we currently have permission to dump log files on Chrome?
Would it work if I write to "/var/log/gesture/"?

[Shecky Lin, 2015/02/03 11:29:22]

Just got a second thought on this. Could we instead dump it to a temporary file?
Looks like temporary file is an even better candidate for the purpose.

[spang, 2015/02/03 16:31:20]

Yep, /tmp would work. If you want to use /var/log that's probably OK too, it
would just need to be created with proper permissions during startup.

[Shecky Lin, 2015/02/10 08:21:22]

I decided to use /home/chronos/user/log/ directly. Thanks.

+
 typedef base::Callback<void(scoped_ptr<EventConverterEvdev>)>
     OpenInputDeviceReplyCallback;
 
 struct OpenInputDeviceParams {
   // Unique identifier for the new device.
   int id;
 
   // Device path to open.
   base::FilePath path;
 
@@ skipping 98 matching lines @@
     // Therefore, the property name indices we output here shouldn't be treated
     // as unique identifiers of the properties.
     std::sort(names.begin(), names.end());
     for (size_t j = 0; j < names.size(); ++j) {
       status->append(base::StringPrintf("\t%s (%zu):", names[j].c_str(), j));
       GesturesProp* property = provider->GetProperty(ids[i], names[j]);
       status->append("\t" + DumpGesturePropertyValue(property) + '\n');
     }
   }
 }
+
+// Compress dumped event logs in place.
+void CompressDumpedLog(scoped_ptr<std::vector<std::string>> log_paths) {
+  for (size_t i = 0; i < log_paths->size(); ++i) {
+    // Zip the file.
+    base::CommandLine command = base::CommandLine(base::FilePath(kGzipCommand));
+    command.AppendArg("-f");
+    command.AppendArg((*log_paths)[i]);
+    std::string output;
+    base::GetAppOutput(command, &output);
+
+    // Replace the original file with the zipped one.
+    base::Move(base::FilePath((*log_paths)[i] + ".gz"),
+               base::FilePath((*log_paths)[i]));
+  }
+}
+
+// Get the current time in a string.
+//
+// This is done by calling out to the 'date' binary so that the time format
+// can be fully compatible with the X11 behavior.
+std::string GetCurrentTimeForLogging() {
+  base::CommandLine command = base::CommandLine(base::FilePath(kDateCommand));
+  command.AppendArg("+%Y%m%d-%H%M%S");

[spang, 2015/02/02 21:43:16]

Does it make sense for this to be in local time with no UTC offset? You cannot
even tell what time it actually represents.

[Shecky Lin, 2015/02/03 08:20:14]

I was just trying to do exactly the same thing in the inputcontrol script to
prevent any possible regression. I think the dates are just used to dedup the
file name. Their values are not actually used.

[spang, 2015/02/03 16:31:20]

Ok, "we don't actually care about the exact time" is a totally reasonable
answer.

+  std::string output;
+  base::GetAppOutput(command, &output);

[spang, 2015/02/02 21:43:16]

Can't you use just "strftime" or similar? Should not be necessary to fork the
browser just to format a date.

[Shecky Lin, 2015/02/03 08:20:14]

Good idea. Will do. Thanks.

[Shecky Lin, 2015/02/10 08:21:22]

Done.

+  return output;
+}
+
+// Canonize the device name for logging.
+std::string GetCanonicalDeviceName(const std::string& name) {
+  std::locale loc;
+  std::string ret(name);
+  for (size_t i = 0; i < ret.size(); ++i)
+    if (!std::isalpha(ret[i], loc))
+      ret[i] = '_';
+  return ret;
+}
+
+std::string GenerateEventLogName(GesturePropertyProvider* provider,
+                                 const base::FilePath& out_dir,
+                                 const std::string& prefix,
+                                 const std::string& now,
+                                 int id) {
+  return out_dir.MaybeAsASCII() + "/" + prefix + now + "." +
+         std::to_string(id) + "." +
+         GetCanonicalDeviceName(provider->GetDeviceNameById(id));
+}
+
+// Dump touch event logs.
+void DumpTouchEventLog(GesturePropertyProvider* provider,

[spang, 2015/02/02 21:43:17]

Can you move this function somewhere inside libgestures_glue (probably a new
file)? It will save on #ifdefs and be a bit more organized.

[Shecky Lin, 2015/02/03 08:20:14]

Yeah, make sense, will do.

[Shecky Lin, 2015/02/10 08:21:22]

Done.

+                       const base::FilePath& out_dir,
+                       scoped_ptr<std::vector<base::FilePath>> log_paths,
+                       const GetTouchEventLogReply& reply) {
+  // Get device ids.
+  std::vector<int> ids;
+  provider->GetDeviceIdsByType(DT_ALL, &ids);
+
+  // Get current time stamp.
+  std::string now = GetCurrentTimeForLogging();
+
+  // Dump event logs for gesture devices.
+  scoped_ptr<std::vector<std::string>> log_paths_to_be_compressed(

[spang, 2015/02/02 21:43:17]

I don't think you need a new vector here.

You should be able to do

  std::vector<base::FilePaths>* log_paths_to_be_compressed = log_paths.get();
  base::WorkerPool::PostTaskAndReply(FROM_HERE,
    base::Bind(&CompressDumpedLog, log_paths_to_be_compressed),
    base::Bind(reply, base::Passed(&log_paths));

below. This is OK because the reply closure outlives the task closure.

[Shecky Lin, 2015/02/03 08:20:14]

No, this is not for recording the pointer. As said in the comment below, I do
this because we only compress touchpad and mouse logs and not the touchscreen
logs. So I need 2 separate vectors for each of them.

We don't have touchscreen logs for now but I will add it at the next patch. So
we are going to have two vectors anyway.

[spang, 2015/02/03 16:31:20]

Ah, ok.

+      new std::vector<std::string>);
+  for (size_t i = 0; i < ids.size(); ++i) {
+    // First, see if the device actually uses the gesture library by checking
+    // if it has any gesture property.
+    std::vector<std::string> names = provider->GetPropertyNamesById(ids[i]);
+    if (names.size() == 0)
+      continue;
+
+    // Set the logging properties to dump event logs. This needs to be done
+    // synchronously for now or we might have race conditions on the debug
+    // buffer. If the performance becomes a concern then, we can fork and
+    // synchronize it.
+    //
+    // TODO(sheckylin): Make sure this has no performance impact for user
+    // feedbacks.
+    GesturesProp* property = provider->GetProperty(ids[i], "Logging Notify");
+    property->SetIntValue(std::vector<int>(1, 1));
+    property = provider->GetProperty(ids[i], "Dump Debug Log");
+    property->SetBoolValue(std::vector<bool>(1, true));
+
+    // Rename/move the file to another place since each device's log is
+    // always dumped using the same name.
+    std::string gesture_log_filename = GenerateEventLogName(
+        provider, out_dir, "touchpad_activity_", now, ids[i]);
+    base::Move(base::FilePath(kTouchpadGestureLogPath),
+               base::FilePath(gesture_log_filename));
+    std::string evdev_log_filename = GenerateEventLogName(
+        provider, out_dir, "cmt_input_events_", now, ids[i]);
+    base::Move(base::FilePath(kTouchpadEvdevLogPath),
+               base::FilePath(evdev_log_filename));
+
+    // Historically, we compress touchpad/mouse logs with gzip before tarring
+    // them up. We DONT compress touchscreen logs though.
+    log_paths_to_be_compressed->push_back(gesture_log_filename);
+    log_paths->push_back(base::FilePath(gesture_log_filename));
+    log_paths_to_be_compressed->push_back(evdev_log_filename);
+    log_paths->push_back(base::FilePath(evdev_log_filename));
+  }
+
+  // Compress touchpad/mouse logs on another thread and return.
+  base::WorkerPool::PostTaskAndReply(
+      FROM_HERE,
+      base::Bind(&CompressDumpedLog, base::Passed(&log_paths_to_be_compressed)),
+      base::Bind(reply, base::Passed(&log_paths)), true /* task_is_slow */);
+}
+
 #endif
 
 scoped_ptr<EventConverterEvdev> CreateConverter(
     const OpenInputDeviceParams& params,
     int fd,
     InputDeviceType type,
     const EventDeviceInfo& devinfo) {
 #if defined(USE_EVDEV_GESTURES)
   // Touchpad or mouse: use gestures library.
   // EventReaderLibevdevCros -> GestureInterpreterLibevdevCros -> DispatchEvent
@@ skipping 241 matching lines @@
 
 void InputDeviceFactoryEvdev::GetTouchDeviceStatus(
     const GetTouchDeviceStatusReply& reply) {
   scoped_ptr<std::string> status(new std::string);
 #if defined(USE_EVDEV_GESTURES)
   DumpTouchDeviceStatus(gesture_property_provider_.get(), status.get());
 #endif
   reply.Run(status.Pass());
 }
 
+void InputDeviceFactoryEvdev::GetTouchEventLog(
+    const base::FilePath& out_dir,
+    const GetTouchEventLogReply& reply) {
+  scoped_ptr<std::vector<base::FilePath>> log_paths(
+      new std::vector<base::FilePath>);
+#if defined(USE_EVDEV_GESTURES)
+  DumpTouchEventLog(gesture_property_provider_.get(), out_dir, log_paths.Pass(),
+                    reply);
+#else
+  reply.Run(log_paths.Pass());
+#endif
+}
+
 base::WeakPtr<InputDeviceFactoryEvdev> InputDeviceFactoryEvdev::GetWeakPtr() {
   return weak_ptr_factory_.GetWeakPtr();
 }
 
 void InputDeviceFactoryEvdev::NotifyDeviceChange(
     const EventConverterEvdev& converter) {
   if (converter.HasTouchscreen())
     NotifyTouchscreensUpdated();
 
   if (converter.HasKeyboard())
@@ skipping 83 matching lines @@
   std::vector<int> ids;
   gesture_property_provider_->GetDeviceIdsByType(type, &ids);
   for (size_t i = 0; i < ids.size(); ++i) {
     SetGestureBoolProperty(gesture_property_provider_.get(), ids[i], name,
                            value);
   }
 #endif
 }
 
 }  // namespace ui