Mir

Merge lp:~kdub/mir/anw-logger into lp:mir

anw-logger
Merge into development-branch

Proposed by Kevin DuBois on 2016-07-06

Status:	Merged
Merged at revision:	3589
Proposed branch:	lp:~kdub/mir/anw-logger
Merge into:	lp:mir
Diff against target:	1511 lines (+574/-110) 17 files modified src/platforms/android/client/android_client_platform.cpp (+14/-35) src/platforms/android/common/CMakeLists.txt (+1/-0) src/platforms/android/common/mir_native_window.cpp (+55/-6) src/platforms/android/common/native_window_report.cpp (+170/-0) src/platforms/android/include/mir_native_window.h (+7/-1) src/platforms/android/include/native_window_report.h (+81/-0) src/platforms/android/server/display.cpp (+7/-1) src/platforms/android/server/display.h (+3/-0) src/platforms/android/server/platform.cpp (+55/-34) src/platforms/android/server/platform.h (+3/-0) tests/unit-tests/client/android/test_android_native_window.cpp (+27/-28) tests/unit-tests/graphics/android/CMakeLists.txt (+1/-0) tests/unit-tests/graphics/android/test_anw_logger.cpp (+107/-0) tests/unit-tests/graphics/android/test_display.cpp (+31/-0) tests/unit-tests/graphics/android/test_display_buffer.cpp (+3/-1) tests/unit-tests/graphics/android/test_display_hotplug.cpp (+2/-0) tests/unit-tests/graphics/android/test_platform.cpp (+7/-4)
To merge this branch:	bzr merge lp:~kdub/mir/anw-logger
Related bugs:	Link a bug report

Reviewer	Review Type	Date Requested	Status
Mir CI Bot	continuous-integration		Needs Fixing on 2016-07-12
Andreas Pokorny (community)		2016-07-06	Approve on 2016-07-12
Alan Griffiths			Approve on 2016-07-12
Chris Halse Rogers			Approve on 2016-07-12
Review via email: mp+299343@code.launchpad.net

Commit Message

android: add loggers for ANativeWindow events. The logging can be turned on for the server context with "--report-fb-native-window log" (or MIR_SERVER_REPORT_FB_NATIVE_WINDOW=log of course). The logging can be turned on for the client context with MIR_CLIENT_ANDROID_WINDOW_REPORT=log

Description of the Change

logging this information is helpful in diagnosing android driver problems.
sample log:
[2016-07-11 05:48:52.454842] <DEBUG> AndroidNativeWindow: addr (0xb5e02844): query: NATIVE_WINDOW_DEFAULT_HEIGHT: result: 0x200
[2016-07-11 05:48:52.455548] <DEBUG> AndroidNativeWindow: addr (0xb5e02844): perform: NATIVE_WINDOW_SET_BUFFERS_DIMENSIONS:
[2016-07-11 05:48:52.456375] <DEBUG> AndroidNativeWindow: addr (0xb5e02844): dequeueBuffer: 0xb5e05b40, fence: none
[2016-07-11 05:48:52.457877] <DEBUG> AndroidNativeWindow: addr (0xb5e02844): perform: NATIVE_WINDOW_SET_BUFFERS_TRANSFORM:
[2016-07-11 05:48:52.459220] <DEBUG> AndroidNativeWindow: addr (0xb5e02844): queueBuffer: 0xb5e05b40, fence: 32
[2016-07-11 05:48:52.469637] <DEBUG> AndroidNativeWindow: addr (0xb5e02844): query: NATIVE_WINDOW_TRANSFORM_HINT: result: 0x0
^CSignal 2 received. Good night.

Mir CI Bot (mir-ci-bot) wrote on 2016-07-06:

Click here to trigger a rebuild:
https://mir-jenkins.ubuntu.com/job/mir-ci/1235/rebuild

review: Needs Fixing (continuous-integration)

Andreas Pokorny (andreas-pokorny) wrote on 2016-07-07:

Why logger and not report? It kind of stands out next to HwcReport and DisplayReport.

Looks fine.

review: Needs Information

Kevin DuBois (kdub) wrote on 2016-07-07:

ci failure was somewhat strange, looks unrelated and device-setup specific:
19:59:49 Failed to set up camera device

Kevin DuBois (kdub) wrote on 2016-07-07:

> Why logger and not report? It kind of stands out next to HwcReport and
> DisplayReport.
>
> Looks fine.

the option is called report to line up with the hwc-report, is that what is being referred to?

Mir CI Bot (mir-ci-bot) wrote on 2016-07-07:

Click here to trigger a rebuild:
https://mir-jenkins.ubuntu.com/job/mir-ci/1246/rebuild

review: Needs Fixing (continuous-integration)

Kevin DuBois (kdub) wrote on 2016-07-07:

^failure needs fixing

Kevin DuBois (kdub) wrote on 2016-07-07:

> ^failure needs fixing
poking around a bit more, not so sure if this is pre-existing smoke test problem or not. Will keep investigating

Mir CI Bot (mir-ci-bot) wrote on 2016-07-07:

Click here to trigger a rebuild:
https://mir-jenkins.ubuntu.com/job/mir-ci/1248/rebuild

review: Approve (continuous-integration)

Kevin DuBois (kdub) wrote on 2016-07-08:

previous CI failure was similar to LP: #1597768, could not reproduce on my device.

Andreas Pokorny (andreas-pokorny) wrote on 2016-07-08:

> > Why logger and not report? It kind of stands out next to HwcReport and
> > DisplayReport.
> >
> > Looks fine.
>
> the option is called report to line up with the hwc-report, is that what is
> being referred to?

I was referring to the class names.. ConsoleNativeWindowLogger, NullNativeWindowLogger

Alan Griffiths (alan-griffiths) wrote on 2016-07-08:

Can we justify this design?

+ std::cout << win << type << ": " << buf << ", fence: ";

Should we be using std::cout directly?

We have a logging facility that provides timestamps and log levels (and can be redirected to other outputs).

In the server where, AFAICS, this code could be running we have a "reports" infrastructure that can provide logs (using the logging facility) or other analysis of system behavior. That could also be an alternative design.

~~~~

- return self->queueBuffer(buffer, -1);
+ return self->queueBufferDeprecated(buffer);

How is this related to adding a logger?

review: Needs Information

Kevin DuBois (kdub) wrote on 2016-07-11:

IMO, writing to stdout is sufficient for the intented purposes. I don't mind reworking to use the common/ logging facilities though.

Its useful to know whether a device is using a deprecated function or not, and splitting the queueBuffer entry points to the MirNativeWindow lets us distinguish what hook the driver is calling.

Mir CI Bot (mir-ci-bot) wrote on 2016-07-11:

Click here to trigger a rebuild:
https://mir-jenkins.ubuntu.com/job/mir-ci/1259/rebuild

review: Needs Fixing (continuous-integration)

Kevin DuBois (kdub) wrote on 2016-07-11:

^ #1573293, retriggering

Mir CI Bot (mir-ci-bot) wrote on 2016-07-11:

Click here to trigger a rebuild:
https://mir-jenkins.ubuntu.com/job/mir-ci/1261/rebuild

review: Needs Fixing (continuous-integration)

Chris Halse Rogers (raof) wrote on 2016-07-12:

Looks good to me.

review: Approve

Alan Griffiths (alan-griffiths) wrote on 2016-07-12:

review: Approve

Andreas Pokorny (andreas-pokorny) wrote on 2016-07-12:

oh sure

review: Approve

Mir CI Bot (mir-ci-bot) wrote on 2016-07-12:

FAILED: Autolanding.
More details in the following jenkins job:
https://mir-jenkins.ubuntu.com/job/mir-autolanding/394/
Executed test runs:
    FAILURE: https://mir-jenkins.ubuntu.com/job/build-mir/1483/console
    None: https://mir-jenkins.ubuntu.com/job/generic-land-mp/422/console
    SUCCESS: https://mir-jenkins.ubuntu.com/job/build-0-fetch/1535
    SUCCESS: https://mir-jenkins.ubuntu.com/job/build-1-sourcepkg/release=vivid+overlay/1526
    SUCCESS: https://mir-jenkins.ubuntu.com/job/build-1-sourcepkg/release=xenial+overlay/1526
    SUCCESS: https://mir-jenkins.ubuntu.com/job/build-1-sourcepkg/release=yakkety/1526
    FAILURE: https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=amd64,compiler=clang,platform=mesa,release=vivid+overlay/1498/console
    FAILURE: https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=amd64,compiler=gcc,platform=mesa,release=xenial+overlay/1498/console
    FAILURE: https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=cross-armhf,compiler=gcc,platform=android,release=vivid+overlay/1498/console
        deb: https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=cross-armhf,compiler=gcc,platform=android,release=vivid+overlay/1498/artifact/output/*zip*/output.zip
    SUCCESS: https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=i386,compiler=gcc,platform=android,release=vivid+overlay/1498
        deb: https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=i386,compiler=gcc,platform=android,release=vivid+overlay/1498/artifact/output/*zip*/output.zip
    FAILURE: https://mir-jenkins.ubuntu.com/job/build-2-binpkg-mir/arch=i386,compiler=gcc,platform=mesa,release=xenial+overlay/1498/console

review: Needs Fixing (continuous-integration)

Kevin DuBois (kdub) wrote on 2016-07-12:

^LP: #1602199, seems to be an ongoing CI storm, will retrigger once problem is resolved.

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk

Subscribers

People subscribed via source and target branches

to all changes:

Emanuele Antonio Faraone

Gerry Boland

Kevin DuBois

Mir development team

 === modified file 'src/platforms/android/client/android_client_platform.cpp'
 --- src/platforms/android/client/android_client_platform.cpp	2016-05-03 06:55:25 +0000
 +++ src/platforms/android/client/android_client_platform.cpp	2016-07-11 12:50:47 +0000
@@ -23,6 +23,8 @@
  #include "gralloc_registrar.h"
  #include "android_client_buffer_factory.h"
  #include "egl_native_surface_interpreter.h"
++#include "native_window_report.h"
++#include "mir/logging/dumb_console_logger.h"
  #include "mir/weak_egl.h"
  #include <EGL/egl.h>
@@ -33,18 +35,6 @@
  namespace mcla=mir::client::android;
  namespace mga=mir::graphics::android;
--namespace
--{
--
--struct EmptyDeleter
--{
--    void operator()(void*)
--    {
--    }
--};
--
--}
--
  mcla::AndroidClientPlatform::AndroidClientPlatform(
      ClientContext* const context)
      : context{context}
@@ -62,35 +52,24 @@
      gralloc_module_t* gr_dev = (gralloc_module_t*) hw_module;
      /* we use an empty deleter because hw_get_module does not give us the ownership of the ptr */
--    EmptyDeleter empty_del;
--    auto gralloc_dev = std::shared_ptr<gralloc_module_t>(gr_dev, empty_del);
++    auto gralloc_dev = std::shared_ptr<gralloc_module_t>(gr_dev, [](auto){});
      auto registrar = std::make_shared<mcla::GrallocRegistrar>(gralloc_dev);
      return std::make_shared<mcla::AndroidClientBufferFactory>(registrar);
+ }
--namespace
--{
--struct MirNativeWindowDeleter
--{
--    MirNativeWindowDeleter(mga::MirNativeWindow* window)
--     : window(window) {}
--
--    void operator()(void*)
--    {
--        delete window;
--    }
--
--private:
--    mga::MirNativeWindow *window;
--};
--}
--
  std::shared_ptr<void> mcla::AndroidClientPlatform::create_egl_native_window(EGLNativeSurface *surface)
+ {
--    auto anativewindow_interpreter = std::make_shared<mcla::EGLNativeSurfaceInterpreter>(*surface);
--    auto mir_native_window = new mga::MirNativeWindow(anativewindow_interpreter);
--    MirNativeWindowDeleter deleter = MirNativeWindowDeleter(mir_native_window);
--    return std::shared_ptr<void>(mir_native_window, deleter);
++    auto log = getenv("MIR_CLIENT_ANDROID_WINDOW_REPORT");
++    std::shared_ptr<mga::NativeWindowReport> report;
++    char const* on_val = "log";
++    if (log && !strncmp(log, on_val, strlen(on_val)))
++        report = std::make_shared<mga::ConsoleNativeWindowReport>(
++            std::make_shared<mir::logging::DumbConsoleLogger>());
++    else
++        report = std::make_shared<mga::NullNativeWindowReport>();
++
++    return std::make_shared<mga::MirNativeWindow>(
++        std::make_shared<mcla::EGLNativeSurfaceInterpreter>(*surface), report);
+ }
  std::shared_ptr<EGLNativeDisplayType>
 === modified file 'src/platforms/android/common/CMakeLists.txt'
 --- src/platforms/android/common/CMakeLists.txt	2016-05-03 06:55:25 +0000
 +++ src/platforms/android/common/CMakeLists.txt	2016-07-11 12:50:47 +0000
@@ -14,4 +14,5 @@
    syncfence.cpp
    egl_sync_fence.cpp
    egl_sync_extensions.cpp
++  native_window_report.cpp
+ )
 === modified file 'src/platforms/android/common/mir_native_window.cpp'
 --- src/platforms/android/common/mir_native_window.cpp	2016-01-29 08:18:22 +0000
 +++ src/platforms/android/common/mir_native_window.cpp	2016-07-11 12:50:47 +0000
@@ -19,6 +19,7 @@
  #include "mir_native_window.h"
  #include "android_driver_interpreter.h"
  #include "sync_fence.h"
++#include "native_window_report.h"
  #define MIR_LOG_COMPONENT "AndroidWindow"
  #include "mir/uncaught.h"
@@ -88,7 +89,7 @@
                         struct ANativeWindowBuffer* buffer)
+ {
      auto self = static_cast<mga::MirNativeWindow*>(window);
--    return self->queueBuffer(buffer, -1);
++    return self->queueBufferDeprecated(buffer);
+ }
  int queueBuffer_static(struct ANativeWindow* window,
@@ -115,7 +116,8 @@
  int cancelBuffer_deprecated_static(struct ANativeWindow* window,
                          struct ANativeWindowBuffer* buffer)
+ {
--    return cancelBuffer_static(window, buffer, -1);
++    auto self = static_cast<mga::MirNativeWindow*>(window);
++    return self->cancelBufferDeprecated(buffer);
+ }
  int cancelBuffer_static(struct ANativeWindow* window,
@@ -126,8 +128,12 @@
+ }
+ }
--mga::MirNativeWindow::MirNativeWindow(std::shared_ptr<AndroidDriverInterpreter> const& interpreter)
-- : driver_interpreter(interpreter), sync_ops(std::make_shared<mga::RealSyncFileOps>())
++mga::MirNativeWindow::MirNativeWindow(
++    std::shared_ptr<AndroidDriverInterpreter> const& interpreter,
++    std::shared_ptr<NativeWindowReport> const& report) :
++    driver_interpreter(interpreter),
++    report(report),
++    sync_ops(std::make_shared<mga::RealSyncFileOps>())
+ {
      ANativeWindow::query = &query_static;
      ANativeWindow::perform = &perform_static;
@@ -177,6 +183,8 @@
          *fence_fd = buffer->copy_fence();
          *buffer_to_driver = buffer->anwb();
+     }
++
++    report->buffer_event(mga::BufferEvent::Dequeue, this, *buffer_to_driver, *fence_fd);
      return 0;
+ }
  catch (std::exception const& e)
@@ -199,6 +207,7 @@
          *buffer_to_driver = buffer->anwb();
          buffer->ensure_available_for(mga::BufferAccess::write);
+     }
++    report->buffer_event(mga::BufferEvent::Dequeue, this, *buffer_to_driver);
      return 0;
+ }
  catch (std::exception const& e)
@@ -210,6 +219,7 @@
  int mga::MirNativeWindow::queueBuffer(struct ANativeWindowBuffer* buffer, int fence)
  try
+ {
++    report->buffer_event(mga::BufferEvent::Queue, this, buffer, fence);
      driver_interpreter->driver_returns_buffer(buffer, fence);
      return 0;
+ }
@@ -219,9 +229,23 @@
      return -1;
+ }
++int mga::MirNativeWindow::queueBufferDeprecated(struct ANativeWindowBuffer* buffer)
++try
++{
++    report->buffer_event(mga::BufferEvent::Queue, this, buffer);
++    driver_interpreter->driver_returns_buffer(buffer, -1);
++    return 0;
++}
++catch (std::exception const& e)
++{
++    MIR_LOG_DRIVER_BOUNDARY_EXCEPTION(e);
++    return -1;
++}
++
  int mga::MirNativeWindow::cancelBuffer(struct ANativeWindowBuffer* buffer, int fence)
  try
+ {
++    report->buffer_event(mga::BufferEvent::Cancel, this, buffer, fence);
      mga::SyncFence sync_fence(sync_ops, mir::Fd(fence));
      sync_fence.wait();
@@ -234,10 +258,24 @@
      return -1;
+ }
++int mga::MirNativeWindow::cancelBufferDeprecated(struct ANativeWindowBuffer* buffer)
++try
++{
++    report->buffer_event(mga::BufferEvent::Cancel, this, buffer);
++    cancelled_buffers.push_back(buffer);
++    return 0;
++}
++catch (std::exception const& e)
++{
++    MIR_LOG_DRIVER_BOUNDARY_EXCEPTION(e);
++    return -1;
++}
++
  int mga::MirNativeWindow::query(int key, int* value) const
  try
+ {
      *value = driver_interpreter->driver_requests_info(key);
++    report->query_event(this, key, *value);
      return 0;
+ }
  catch (std::exception const& e)
@@ -256,13 +294,24 @@
      switch(key)
+     {
          case NATIVE_WINDOW_SET_BUFFERS_FORMAT:
--            driver_interpreter->dispatch_driver_request_format(va_arg(args, int));
++        {
++            auto format = va_arg(args, int);
++            driver_interpreter->dispatch_driver_request_format(format);
++            report->perform_event(this, key, {format});
              break;
++        }
          case NATIVE_WINDOW_SET_BUFFER_COUNT:
--            driver_interpreter->dispatch_driver_request_buffer_count(va_arg(args, int));
++        {
++            auto count = va_arg(args, int);
++            driver_interpreter->dispatch_driver_request_buffer_count(count);
++            report->perform_event(this, key, {count});
              break;
++        }
          default:
++        {
++            report->perform_event(this, key, {});
              break;
++        }
+     }
      va_end(args);
 === added file 'src/platforms/android/common/native_window_report.cpp'
 --- src/platforms/android/common/native_window_report.cpp	1970-01-01 00:00:00 +0000
 +++ src/platforms/android/common/native_window_report.cpp	2016-07-11 12:50:47 +0000
@@ -0,0 +1,170 @@
++/*
++ * Copyright © 2016 Canonical Ltd.
++ *
++ * This program is free software: you can redistribute it and/or modify it
++ * under the terms of the GNU Lesser General Public License version 3,
++ * as published by the Free Software Foundation.
++ *
++ * This program is distributed in the hope that it will be useful,
++ * but WITHOUT ANY WARRANTY; without even the implied warranty of
++ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
++ * GNU Lesser General Public License for more details.
++ *
++ * You should have received a copy of the GNU Lesser General Public License
++ * along with this program.  If not, see <http://www.gnu.org/licenses/>.
++ *
++ * Authored by: Kevin DuBois <kevin.dubois@canonical.com>
++ */
++
++#include "mir/logging/logger.h"
++#include "native_window_report.h"
++#include <sstream>
++
++#define CASE_KEY(var) case var: return out << #var;
++namespace mga = mir::graphics::android;
++
++namespace
++{
++
++struct NativePerformKey
++{
++    int key;
++};
++
++struct NativeQueryKey
++{
++    int key;
++};
++
++std::ostream& operator<<(std::ostream& out, NativeQueryKey key)
++{
++    switch (key.key)
++    {
++        CASE_KEY(NATIVE_WINDOW_WIDTH)
++        CASE_KEY(NATIVE_WINDOW_HEIGHT)
++        CASE_KEY(NATIVE_WINDOW_FORMAT)
++        CASE_KEY(NATIVE_WINDOW_MIN_UNDEQUEUED_BUFFERS)
++        CASE_KEY(NATIVE_WINDOW_QUEUES_TO_WINDOW_COMPOSER)
++        CASE_KEY(NATIVE_WINDOW_CONCRETE_TYPE)
++        CASE_KEY(NATIVE_WINDOW_DEFAULT_WIDTH)
++        CASE_KEY(NATIVE_WINDOW_DEFAULT_HEIGHT)
++        CASE_KEY(NATIVE_WINDOW_TRANSFORM_HINT)
++        CASE_KEY(NATIVE_WINDOW_CONSUMER_RUNNING_BEHIND)
++        CASE_KEY(NATIVE_WINDOW_CONSUMER_USAGE_BITS)
++        CASE_KEY(NATIVE_WINDOW_STICKY_TRANSFORM)
++        CASE_KEY(NATIVE_WINDOW_DEFAULT_DATASPACE)
++        CASE_KEY(NATIVE_WINDOW_BUFFER_AGE)
++        default: return out << "unknown query key: " << key.key;
++    }
++}
++
++std::ostream& operator<<(std::ostream& out, NativePerformKey key)
++{
++    switch (key.key)
++    {
++        CASE_KEY(NATIVE_WINDOW_SET_USAGE)
++        CASE_KEY(NATIVE_WINDOW_CONNECT)
++        CASE_KEY(NATIVE_WINDOW_DISCONNECT)
++        CASE_KEY(NATIVE_WINDOW_SET_CROP)
++        CASE_KEY(NATIVE_WINDOW_SET_BUFFER_COUNT)
++        CASE_KEY(NATIVE_WINDOW_SET_BUFFERS_GEOMETRY)
++        CASE_KEY(NATIVE_WINDOW_SET_BUFFERS_TRANSFORM)
++        CASE_KEY(NATIVE_WINDOW_SET_BUFFERS_TIMESTAMP)
++        CASE_KEY(NATIVE_WINDOW_SET_BUFFERS_DIMENSIONS)
++        CASE_KEY(NATIVE_WINDOW_SET_BUFFERS_FORMAT)
++        CASE_KEY(NATIVE_WINDOW_SET_SCALING_MODE)
++        CASE_KEY(NATIVE_WINDOW_LOCK)
++        CASE_KEY(NATIVE_WINDOW_UNLOCK_AND_POST)
++        CASE_KEY(NATIVE_WINDOW_API_CONNECT)
++        CASE_KEY(NATIVE_WINDOW_API_DISCONNECT)
++        CASE_KEY(NATIVE_WINDOW_SET_BUFFERS_USER_DIMENSIONS)
++        CASE_KEY(NATIVE_WINDOW_SET_POST_TRANSFORM_CROP)
++        CASE_KEY(NATIVE_WINDOW_SET_BUFFERS_STICKY_TRANSFORM)
++        CASE_KEY(NATIVE_WINDOW_SET_SIDEBAND_STREAM)
++        CASE_KEY(NATIVE_WINDOW_SET_BUFFERS_DATASPACE)
++        CASE_KEY(NATIVE_WINDOW_SET_SURFACE_DAMAGE)
++        default: return out << "unknown perform key: " << key.key;
++    }
++}
++
++std::ostream& operator<<(std::ostream& out, mga::BufferEvent type)
++{
++    switch (type)
++    {
++        case mga::BufferEvent::Queue: return out << "queueBuffer";
++        case mga::BufferEvent::Dequeue: return out << "dequeueBuffer";
++        case mga::BufferEvent::Cancel: return out << "cancelBuffer";
++        default: return out;
++    }
++}
++
++std::ostream& operator<<(std::ostream& out, ANativeWindow const* window)
++{
++    return out << "addr (" << static_cast<void const*>(window) << "): ";
++}
++}
++
++mga::ConsoleNativeWindowReport::ConsoleNativeWindowReport(
++    std::shared_ptr<mir::logging::Logger> const& logger) :
++    logger(logger)
++{
++}
++
++void mga::ConsoleNativeWindowReport::buffer_event(
++    BufferEvent type, ANativeWindow const* win, ANativeWindowBuffer* buf, int fence) const
++{
++    std::stringstream str;
++
++    str << win << type << ": " << buf << ", fence: ";
++    if ( fence > 0 )
++        str << fence;
++    else
++        str << "none";
++
++    logger->log(mir::logging::Severity::debug, str.str(), component_name);
++}
++
++void mga::ConsoleNativeWindowReport::buffer_event(
++    BufferEvent type, ANativeWindow const* win, ANativeWindowBuffer* buf) const
++{
++    std::stringstream str;
++    str << win << type << "_deprecated: " << buf;
++    logger->log(mir::logging::Severity::debug, str.str(), component_name);
++}
++
++void mga::ConsoleNativeWindowReport::query_event(ANativeWindow const* win, int type, int result) const
++{
++    std::stringstream str;
++    str << std::hex << win << "query: " << NativeQueryKey{type} << ": result: 0x" << result;
++    logger->log(mir::logging::Severity::debug, str.str(), component_name);
++}
++
++void mga::ConsoleNativeWindowReport::perform_event(
++    ANativeWindow const* win, int type, std::vector<int> const& args) const
++{
++    std::stringstream str;
++    str << std::hex << win << "perform: " << NativePerformKey{type} << ": ";
++    for (auto i = 0u; i < args.size(); i++)
++    {
++        if (i != 0u)
++            str << ", ";
++        str <<  "0x" << args[i];
++    }
++    logger->log(mir::logging::Severity::debug, str.str(), component_name);
++}
++
++void mga::NullNativeWindowReport::buffer_event(mga::BufferEvent, ANativeWindow const*, ANativeWindowBuffer*, int) const
++{
++}
++
++void mga::NullNativeWindowReport::buffer_event(mga::BufferEvent, ANativeWindow const*, ANativeWindowBuffer*) const
++{
++}
++
++void mga::NullNativeWindowReport::query_event(ANativeWindow const*, int, int) const
++{
++}
++
++void mga::NullNativeWindowReport::perform_event(ANativeWindow const*, int, std::vector<int> const&) const
++{
++}
 === modified file 'src/platforms/android/include/mir_native_window.h'
 --- src/platforms/android/include/mir_native_window.h	2015-02-22 07:46:25 +0000
 +++ src/platforms/android/include/mir_native_window.h	2016-07-11 12:50:47 +0000
@@ -32,21 +32,27 @@
+ {
  class AndroidDriverInterpreter;
  class SyncFileOps;
++class NativeWindowReport;
  class MirNativeWindow : public ANativeWindow
+ {
  public:
--    explicit MirNativeWindow(std::shared_ptr<AndroidDriverInterpreter> const& interpreter);
++    explicit MirNativeWindow(
++        std::shared_ptr<AndroidDriverInterpreter> const& interpreter,
++        std::shared_ptr<NativeWindowReport> const& report);
      int query(int key, int* value) const;
      int perform(int key, va_list args );
      int dequeueBuffer(struct ANativeWindowBuffer** buffer, int* fence);
      int dequeueBufferAndWait(struct ANativeWindowBuffer** buffer);
      int queueBuffer(struct ANativeWindowBuffer* buffer, int fence);
++    int queueBufferDeprecated(struct ANativeWindowBuffer* buffer);
      int cancelBuffer(struct ANativeWindowBuffer* buffer, int fence);
++    int cancelBufferDeprecated(struct ANativeWindowBuffer* buffer);
      int setSwapInterval(int interval);
  private:
      std::shared_ptr<AndroidDriverInterpreter> const driver_interpreter;
++    std::shared_ptr<NativeWindowReport> const report;
      std::shared_ptr<SyncFileOps> const sync_ops;
      std::vector<struct ANativeWindowBuffer*> cancelled_buffers;
  };
 === added file 'src/platforms/android/include/native_window_report.h'
 --- src/platforms/android/include/native_window_report.h	1970-01-01 00:00:00 +0000
 +++ src/platforms/android/include/native_window_report.h	2016-07-11 12:50:47 +0000
@@ -0,0 +1,81 @@
++/*
++ * Copyright © 2016 Canonical Ltd.
++ *
++ * This program is free software: you can redistribute it and/or modify it
++ * under the terms of the GNU Lesser General Public License version 3,
++ * as published by the Free Software Foundation.
++ *
++ * This program is distributed in the hope that it will be useful,
++ * but WITHOUT ANY WARRANTY; without even the implied warranty of
++ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
++ * GNU Lesser General Public License for more details.
++ *
++ * You should have received a copy of the GNU Lesser General Public License
++ * along with this program.  If not, see <http://www.gnu.org/licenses/>.
++ *
++ * Authored by: Kevin DuBois <kevin.dubois@canonical.com>
++ */
++
++#ifndef MIR_GRAPHICS_ANDROID_NATIVE_WINDOW_REPORT_H_
++#define MIR_GRAPHICS_ANDROID_NATIVE_WINDOW_REPORT_H_
++#include <system/window.h>
++#include <vector>
++#include <memory>
++
++namespace mir
++{
++namespace logging
++{
++class Logger;
++}
++namespace graphics
++{
++namespace android
++{
++enum class BufferEvent
++{
++    Queue,
++    Dequeue,
++    Cancel
++};
++class NativeWindowReport
++{
++public:
++    NativeWindowReport() = default;
++    virtual ~NativeWindowReport() = default;
++
++    virtual void buffer_event(BufferEvent type, ANativeWindow const* win, ANativeWindowBuffer* buf, int fence) const = 0;
++    virtual void buffer_event(BufferEvent type, ANativeWindow const* win, ANativeWindowBuffer* buf) const = 0;
++    virtual void query_event(ANativeWindow const* win, int type, int result) const = 0;
++    virtual void perform_event(ANativeWindow const* win, int type, std::vector<int> const& args) const = 0;
++
++private:
++    NativeWindowReport(NativeWindowReport const&) = delete;
++    NativeWindowReport& operator=(NativeWindowReport const&) = delete;
++};
++
++class NullNativeWindowReport : public NativeWindowReport
++{
++    void buffer_event(BufferEvent type, ANativeWindow const* win, ANativeWindowBuffer* buf, int fence) const override;
++    void buffer_event(BufferEvent type, ANativeWindow const* win, ANativeWindowBuffer* buf) const override;
++    void query_event(ANativeWindow const* win, int type, int result) const override;
++    void perform_event(ANativeWindow const* win, int type, std::vector<int> const& args) const override;
++};
++
++class ConsoleNativeWindowReport : public NativeWindowReport
++{
++public:
++    ConsoleNativeWindowReport(std::shared_ptr<logging::Logger> const&);
++    void buffer_event(BufferEvent type, ANativeWindow const* win, ANativeWindowBuffer* buf, int fence) const override;
++    void buffer_event(BufferEvent type, ANativeWindow const* win, ANativeWindowBuffer* buf) const override;
++    void query_event(ANativeWindow const* win, int type, int result) const override;
++    void perform_event(ANativeWindow const* win, int type, std::vector<int> const& args) const override;
++private:
++    std::shared_ptr<logging::Logger> const logger;
++    std::string const component_name = "AndroidNativeWindow";
++};
++
++}
++}
++}
++#endif /* MIR_GRAPHICS_ANDROID_NATIVE_WINDOW_REPORT_H_ */
 === modified file 'src/platforms/android/server/display.cpp'
 --- src/platforms/android/server/display.cpp	2016-06-28 18:35:12 +0000
 +++ src/platforms/android/server/display.cpp	2016-07-11 12:50:47 +0000
@@ -117,13 +117,14 @@
      std::shared_ptr<mgl::ProgramFactory> const& gl_program_factory,
      mga::PbufferGLContext const& gl_context,
      geom::Displacement displacement,
++    std::shared_ptr<mga::NativeWindowReport> const& report,
      mga::OverlayOptimization overlay_option)
+ {
      std::shared_ptr<mga::FramebufferBundle> fbs{display_buffer_builder.create_framebuffers(config)};
      auto cache = std::make_shared<mga::InterpreterCache>();
      mga::DeviceQuirks quirks(mga::PropertiesOps{}, gl_context);
      auto interpreter = std::make_shared<mga::ServerRenderWindow>(fbs, config.current_format, cache, quirks);
--    auto native_window = std::make_shared<mga::MirNativeWindow>(interpreter);
++    auto native_window = std::make_shared<mga::MirNativeWindow>(interpreter, report);
      return std::unique_ptr<mga::ConfigurableDisplayBuffer>(new mga::DisplayBuffer(
          name,
          display_buffer_builder.create_layer_list(),
@@ -143,8 +144,10 @@
      std::shared_ptr<mgl::ProgramFactory> const& gl_program_factory,
      std::shared_ptr<GLConfig> const& gl_config,
      std::shared_ptr<DisplayReport> const& display_report,
++    std::shared_ptr<NativeWindowReport> const& native_window_report,
      mga::OverlayOptimization overlay_option) :
      display_report{display_report},
++    native_window_report{native_window_report},
      display_buffer_builder{display_buffer_builder},
      hwc_config{display_buffer_builder->create_hwc_configuration()},
      hotplug_subscription{hwc_config->subscribe_to_config_changes(
@@ -169,6 +172,7 @@
              gl_program_factory,
              gl_context,
              geom::Displacement{0,0},
++            native_window_report,
              overlay_option),
              [this] { on_hotplug(); }), //Recover from exception by forcing a configuration change
      overlay_option(overlay_option)
@@ -187,6 +191,7 @@
                  gl_program_factory,
                  gl_context,
                  geom::Displacement{0,0},
++                native_window_report,
                  overlay_option));
+     }
@@ -254,6 +259,7 @@
                  gl_program_factory,
                  gl_context,
                  config.external().top_left - origin,
++                native_window_report,
                  overlay_option));
      if ((!config.external().connected) && displays.display_present(mga::DisplayName::external))
          displays.remove(mga::DisplayName::external);
 === modified file 'src/platforms/android/server/display.h'
 --- src/platforms/android/server/display.h	2016-02-01 22:53:06 +0000
 +++ src/platforms/android/server/display.h	2016-07-11 12:50:47 +0000
@@ -46,6 +46,7 @@
  class ConfigurableDisplayBuffer;
  class DisplayChangePipe;
  class DisplayDevice;
++class NativeWindowReport;
  class Display : public graphics::Display
+ {
@@ -55,6 +56,7 @@
          std::shared_ptr<gl::ProgramFactory> const& gl_program_factory,
          std::shared_ptr<GLConfig> const& gl_config,
          std::shared_ptr<DisplayReport> const& display_report,
++        std::shared_ptr<NativeWindowReport> const& native_window_report,
          OverlayOptimization overlay_option);
      ~Display() noexcept;
@@ -85,6 +87,7 @@
      geometry::Point const origin{0,0};
      std::shared_ptr<DisplayReport> const display_report;
++    std::shared_ptr<NativeWindowReport> const native_window_report;
      std::shared_ptr<DisplayComponentFactory> const display_buffer_builder;
      std::mutex mutable configuration_mutex;
      bool mutable configuration_dirty{false};
 === modified file 'src/platforms/android/server/platform.cpp'
 --- src/platforms/android/server/platform.cpp	2016-05-03 06:55:25 +0000
 +++ src/platforms/android/server/platform.cpp	2016-07-11 12:50:47 +0000
@@ -27,6 +27,7 @@
  #include "ipc_operations.h"
  #include "sync_fence.h"
  #include "native_buffer.h"
++#include "native_window_report.h"
  #include "mir/graphics/platform_ipc_package.h"
  #include "mir/graphics/buffer_ipc_message.h"
@@ -38,6 +39,7 @@
  #include "mir/abnormal_exit.h"
  #include "mir/assert_module_entry_point.h"
  #include "mir/libname.h"
++#include "mir/logging/dumb_console_logger.h"
  #include <boost/throw_exception.hpp>
  #include <stdexcept>
@@ -50,49 +52,60 @@
  namespace
+ {
--
--    char const* const hwc_log_opt = "hwc-report";
--    char const* const hwc_overlay_opt = "disable-overlays";
--
--    std::shared_ptr<mga::HwcReport> make_hwc_report(mo::Option const& options)
--    {
--        if (!options.is_set(hwc_log_opt))
--            return std::make_shared<mga::NullHwcReport>();
--
--        auto opt = options.get<std::string>(hwc_log_opt);
--        if (opt == mo::log_opt_value)
--            return std::make_shared<mga::HwcFormattedLogger>();
--        else if (opt == mo::off_opt_value)
--            return std::make_shared<mga::NullHwcReport>();
--        else
--            throw mir::AbnormalExit(
--                    std::string("Invalid hwc-report option: " + opt + " (valid options are: \"" +
--                        mo::off_opt_value + "\" and \"" + mo::log_opt_value + "\")"));
--    }
--
--    mga::OverlayOptimization should_use_overlay_optimization(mo::Option const& options)
--    {
--        if (!options.is_set(hwc_overlay_opt))
--            return mga::OverlayOptimization::enabled;
--
--        if (options.get<bool>(hwc_overlay_opt))
--            return mga::OverlayOptimization::disabled;
--        else
--            return mga::OverlayOptimization::enabled;
--    }
--
++char const* const hwc_log_opt = "hwc-report";
++char const* const hwc_overlay_opt = "disable-overlays";
++char const* const fb_native_window_report_opt = "report-fb-native-window";
++
++std::shared_ptr<mga::HwcReport> make_hwc_report(mo::Option const& options)
++{
++    if (!options.is_set(hwc_log_opt))
++        return std::make_shared<mga::NullHwcReport>();
++
++    auto opt = options.get<std::string>(hwc_log_opt);
++    if (opt == mo::log_opt_value)
++        return std::make_shared<mga::HwcFormattedLogger>();
++    else if (opt == mo::off_opt_value)
++        return std::make_shared<mga::NullHwcReport>();
++    else
++        throw mir::AbnormalExit(
++                std::string("Invalid hwc-report option: " + opt + " (valid options are: \"" +
++                    mo::off_opt_value + "\" and \"" + mo::log_opt_value + "\")"));
++}
++
++std::shared_ptr<mga::NativeWindowReport> make_native_window_report(mo::Option const& options)
++{
++    if (options.is_set(fb_native_window_report_opt) &&
++        options.get<std::string>(fb_native_window_report_opt) == mo::log_opt_value)
++        return std::make_shared<mga::ConsoleNativeWindowReport>(
++            std::make_shared<mir::logging::DumbConsoleLogger>());
++    else
++        return std::make_shared<mga::NullNativeWindowReport>();
++}
++
++mga::OverlayOptimization should_use_overlay_optimization(mo::Option const& options)
++{
++    if (!options.is_set(hwc_overlay_opt))
++        return mga::OverlayOptimization::enabled;
++
++    if (options.get<bool>(hwc_overlay_opt))
++        return mga::OverlayOptimization::disabled;
++    else
++        return mga::OverlayOptimization::enabled;
++}
+ }
  mga::Platform::Platform(
      std::shared_ptr<graphics::GraphicBufferAllocator> const& buffer_allocator,
      std::shared_ptr<mga::DisplayComponentFactory> const& display_buffer_builder,
      std::shared_ptr<mg::DisplayReport> const& display_report,
++    std::shared_ptr<mga::NativeWindowReport> const& native_window_report,
      mga::OverlayOptimization overlay_option,
      std::shared_ptr<mga::DeviceQuirks> const& quirks) :
      buffer_allocator(buffer_allocator),
      display_buffer_builder(display_buffer_builder),
      display_report(display_report),
      quirks(quirks),
++    native_window_report(native_window_report),
      overlay_option(overlay_option)
+ {
+ }
@@ -130,7 +143,7 @@
+ {
      auto const program_factory = std::make_shared<mir::gl::DefaultProgramFactory>();
      return mir::make_module_ptr<mga::Display>(
--            display_buffer_builder, program_factory, gl_config, display_report, overlay_option);
++            display_buffer_builder, program_factory, gl_config, display_report, native_window_report, overlay_option);
+ }
  mir::UniqueModulePtr<mg::PlatformIpcOperations> mga::Platform::make_ipc_operations() const
@@ -160,7 +173,9 @@
      return mir::make_module_ptr<mga::Platform>(
          component_factory->the_buffer_allocator(),
--        component_factory, display_report, overlay_option, quirks);
++        component_factory, display_report,
++        make_native_window_report(*options),
++        overlay_option, quirks);
+ }
  mir::UniqueModulePtr<mg::Platform> create_guest_platform(
@@ -180,7 +195,10 @@
      //TODO: remove nullptr parameter once platform classes are sorted.
      //      mg::NativePlatform cannot create a display anyways, so it doesnt need a  display builder
      auto const buffer_allocator = std::make_shared<mga::GraphicBufferAllocator>(sync_factory, quirks);
--    return mir::make_module_ptr<mga::Platform>(buffer_allocator, nullptr, display_report, mga::OverlayOptimization::disabled, quirks);
++    return mir::make_module_ptr<mga::Platform>(
++        buffer_allocator, nullptr, display_report,
++        std::make_shared<mga::NullNativeWindowReport>(),
++        mga::OverlayOptimization::disabled, quirks);
+ }
  void add_graphics_platform_options(
@@ -191,6 +209,9 @@
          (hwc_log_opt,
           boost::program_options::value<std::string>()->default_value(std::string{mo::off_opt_value}),
           "[platform-specific] How to handle the HWC logging report. [{log,off}]")
++        (fb_native_window_report_opt,
++         boost::program_options::value<std::string>()->default_value(std::string{mo::off_opt_value}),
++         "[platform-specific] whether to log the EGLNativeWindowType backed by the framebuffer [{log,off}]")
          (hwc_overlay_opt,
           boost::program_options::value<bool>()->default_value(false),
           "[platform-specific] Whether to disable overlay optimizations [{on,off}]");
 === modified file 'src/platforms/android/server/platform.h'
 --- src/platforms/android/server/platform.h	2016-05-03 06:55:25 +0000
 +++ src/platforms/android/server/platform.h	2016-07-11 12:50:47 +0000
@@ -34,6 +34,7 @@
  class FramebufferFactory;
  class DisplayComponentFactory;
  class CommandStreamSyncFactory;
++class NativeWindowReport;
  class Platform : public graphics::Platform
+ {
@@ -42,6 +43,7 @@
          std::shared_ptr<graphics::GraphicBufferAllocator> const& buffer_allocator,
          std::shared_ptr<DisplayComponentFactory> const& display_buffer_builder,
          std::shared_ptr<DisplayReport> const& display_report,
++        std::shared_ptr<NativeWindowReport> const& native_window_report,
          OverlayOptimization overlay_option,
          std::shared_ptr<DeviceQuirks> const& quirks);
@@ -59,6 +61,7 @@
      std::shared_ptr<DisplayReport> const display_report;
      std::shared_ptr<PlatformIpcOperations> const ipc_operations;
      std::shared_ptr<DeviceQuirks> const quirks;
++    std::shared_ptr<NativeWindowReport> const native_window_report;
      OverlayOptimization const overlay_option;
  };
 === modified file 'tests/unit-tests/client/android/test_android_native_window.cpp'
 --- tests/unit-tests/client/android/test_android_native_window.cpp	2016-01-29 08:18:22 +0000
 +++ tests/unit-tests/client/android/test_android_native_window.cpp	2016-07-11 12:50:47 +0000
@@ -18,6 +18,7 @@
  #include "mir_native_window.h"
  #include "android_driver_interpreter.h"
++#include "native_window_report.h"
  #include "mir/egl_native_surface.h"
  #include "mir/test/doubles/mock_android_native_buffer.h"
  #include "mir/test/doubles/stub_android_native_buffer.h"
@@ -26,11 +27,19 @@
  #include <gtest/gtest.h>
  #include <memory>
++using namespace testing;
  namespace mga=mir::graphics::android;
  namespace mtd=mir::test::doubles;
  namespace
+ {
++struct MockReport : mga::NativeWindowReport
++{
++    MOCK_CONST_METHOD4(buffer_event, void(mga::BufferEvent, ANativeWindow const*, ANativeWindowBuffer*, int));
++    MOCK_CONST_METHOD3(buffer_event, void(mga::BufferEvent, ANativeWindow const*, ANativeWindowBuffer*));
++    MOCK_CONST_METHOD3(query_event, void(ANativeWindow const*, int, int));
++    MOCK_CONST_METHOD3(perform_event, void(ANativeWindow const*, int, std::vector<int> const&));
++};
  class MockAndroidDriverInterpreter : public mga::AndroidDriverInterpreter
+ {
@@ -38,7 +47,6 @@
      MockAndroidDriverInterpreter()
       : buffer(std::make_shared<mtd::StubAndroidNativeBuffer>())
+     {
--        using namespace testing;
          ON_CALL(*this, driver_requests_buffer())
              .WillByDefault(Return(buffer.get()));
+     }
@@ -52,12 +60,13 @@
      std::shared_ptr<mir::graphics::NativeBuffer> buffer;
  };
--class AndroidNativeWindowTest : public ::testing::Test
++class AndroidNativeWindowTest : public ::Test
+ {
  protected:
      std::shared_ptr<MockAndroidDriverInterpreter> const mock_driver_interpreter =
--        std::make_shared<testing::NiceMock<MockAndroidDriverInterpreter>>();
--    mga::MirNativeWindow mir_native_window{mock_driver_interpreter};
++        std::make_shared<NiceMock<MockAndroidDriverInterpreter>>();
++    std::shared_ptr<MockReport> const mock_report = std::make_shared<NiceMock<MockReport>>();
++    mga::MirNativeWindow mir_native_window{mock_driver_interpreter, mock_report};
      ANativeWindow& window = mir_native_window;
      int const failure_code{-1};
  };
@@ -66,8 +75,6 @@
  TEST_F(AndroidNativeWindowTest, native_window_swapinterval)
+ {
--    using namespace testing;
--
      ASSERT_NE(nullptr, window.setSwapInterval);
      EXPECT_CALL(*mock_driver_interpreter, sync_to_display(true))
          .Times(1);
@@ -87,17 +94,17 @@
  /* Query hook tests */
  TEST_F(AndroidNativeWindowTest, native_window_query_hook)
+ {
--    using namespace testing;
--
      int returned_width;
      int const width = 271828;
++    int key = NATIVE_WINDOW_WIDTH;
      ASSERT_NE(nullptr, window.query);
      EXPECT_CALL(*mock_driver_interpreter, driver_requests_info(NATIVE_WINDOW_WIDTH))
          .Times(1)
          .WillOnce(Return(width));
++    EXPECT_CALL(*mock_report, query_event(_, key, width));
--    window.query(&window, NATIVE_WINDOW_WIDTH ,&returned_width);
++    window.query(&window, key, &returned_width);
      EXPECT_EQ(width, returned_width);
+ }
@@ -106,12 +113,14 @@
  TEST_F(AndroidNativeWindowTest, native_window_perform_hook_callable)
+ {
      int const format = 4;
++    int const key = NATIVE_WINDOW_SET_BUFFERS_FORMAT;
      EXPECT_CALL(*mock_driver_interpreter, dispatch_driver_request_format(format))
          .Times(1);
      ASSERT_NE(nullptr, window.perform);
--    window.perform(&window, NATIVE_WINDOW_SET_BUFFERS_FORMAT, format);
++    EXPECT_CALL(*mock_report, perform_event(_, key, _));
++    window.perform(&window, key, format);
+ }
  TEST_F(AndroidNativeWindowTest, native_window_perform_hook_calls_set_buffer)
@@ -138,13 +147,12 @@
      int fence_fd;
      ASSERT_NE(nullptr, window.dequeueBuffer);
++    EXPECT_CALL(*mock_report, buffer_event(mga::BufferEvent::Dequeue, _, _, _));
      window.dequeueBuffer(&window, &returned_buffer, &fence_fd);
+ }
  TEST_F(AndroidNativeWindowTest, native_window_dequeue_returns_right_buffer)
+ {
--    using namespace testing;
--
      int fake_fd = 4948;
      auto mock_buffer = std::make_shared<NiceMock<mtd::MockAndroidNativeBuffer>>();
      EXPECT_CALL(*mock_buffer, copy_fence())
@@ -164,7 +172,6 @@
  TEST_F(AndroidNativeWindowTest, native_window_dequeue_returns_previously_cancelled_buffer)
+ {
--    using namespace testing;
      ANativeWindowBuffer buffer;
      int fence_fd = 33;
@@ -190,8 +197,6 @@
  TEST_F(AndroidNativeWindowTest, native_window_dequeue_deprecated_returns_right_buffer)
+ {
--    using namespace testing;
--
      ANativeWindowBuffer* returned_buffer;
      auto mock_buffer = std::make_shared<NiceMock<mtd::MockAndroidNativeBuffer>>();
@@ -202,6 +207,7 @@
          .Times(1);
      EXPECT_CALL(*mock_buffer, copy_fence())
          .Times(0);
++    EXPECT_CALL(*mock_report, buffer_event(mga::BufferEvent::Dequeue, _, _));
      window.dequeueBuffer_DEPRECATED(&window, &returned_buffer);
      EXPECT_EQ(mock_buffer->anwb(), returned_buffer);
@@ -209,7 +215,6 @@
  TEST_F(AndroidNativeWindowTest, native_window_dequeue_deprecated_returns_previously_cancelled_buffer)
+ {
--    using namespace testing;
      ANativeWindowBuffer buffer;
      auto rc = window.cancelBuffer_DEPRECATED(&window, &buffer);
@@ -235,10 +240,10 @@
  TEST_F(AndroidNativeWindowTest, native_window_queue_passes_buffer_back)
+ {
--    using namespace testing;
      ANativeWindowBuffer buffer;
      int fence_fd = 33;
++    EXPECT_CALL(*mock_report, buffer_event(mga::BufferEvent::Queue, _, &buffer, fence_fd));
      EXPECT_CALL(*mock_driver_interpreter, driver_returns_buffer(&buffer, fence_fd))
          .Times(1);
@@ -255,9 +260,9 @@
  TEST_F(AndroidNativeWindowTest, native_window_queue_deprecated_passes_buffer_back)
+ {
--    using namespace testing;
      ANativeWindowBuffer buffer;
++    EXPECT_CALL(*mock_report, buffer_event(mga::BufferEvent::Queue, _, &buffer));
      EXPECT_CALL(*mock_driver_interpreter, driver_returns_buffer(&buffer,_))
          .Times(1);
@@ -268,11 +273,14 @@
  TEST_F(AndroidNativeWindowTest, native_window_cancel_hooks_callable)
+ {
      ANativeWindowBuffer* tmp = nullptr;
++    int fence_fd = -1;
++    EXPECT_CALL(*mock_report, buffer_event(mga::BufferEvent::Cancel, _, tmp));
++    EXPECT_CALL(*mock_report, buffer_event(mga::BufferEvent::Cancel, _, tmp, fence_fd));
      ASSERT_NE(nullptr, window.cancelBuffer_DEPRECATED);
      ASSERT_NE(nullptr, window.cancelBuffer);
      window.cancelBuffer_DEPRECATED(&window, tmp);
--    window.cancelBuffer(&window, tmp, -1);
++    window.cancelBuffer(&window, tmp, fence_fd);
+ }
  /* lock hook tests */
@@ -315,7 +323,6 @@
  TEST_F(AndroidNativeWindowTest, native_window_cancel_hook_does_not_call_driver_interpreter)
+ {
--    using namespace testing;
      ANativeWindowBuffer buffer;
      int fence_fd = 33;
@@ -328,8 +335,6 @@
  TEST_F(AndroidNativeWindowTest, returns_error_on_dequeue_buffer_failure)
+ {
--    using namespace testing;
--
      EXPECT_CALL(*mock_driver_interpreter, driver_requests_buffer())
          .WillOnce(Throw(std::runtime_error("")))
          .WillOnce(Throw(std::runtime_error("")));
@@ -340,8 +345,6 @@
  TEST_F(AndroidNativeWindowTest, returns_error_on_queue_buffer_failure)
+ {
--    using namespace testing;
--
      EXPECT_CALL(*mock_driver_interpreter, driver_returns_buffer(_, _))
          .WillOnce(Throw(std::runtime_error("")))
          .WillOnce(Throw(std::runtime_error("")));
@@ -352,8 +355,6 @@
  TEST_F(AndroidNativeWindowTest, returns_error_on_query_failure)
+ {
--    using namespace testing;
--
      EXPECT_CALL(*mock_driver_interpreter, driver_requests_info(_))
          .WillOnce(Throw(std::runtime_error("")));
@@ -362,8 +363,6 @@
  TEST_F(AndroidNativeWindowTest, returns_error_on_perform_failure)
+ {
--    using namespace testing;
--
      EXPECT_CALL(*mock_driver_interpreter, dispatch_driver_request_format(_))
          .WillOnce(Throw(std::runtime_error("")));
 === modified file 'tests/unit-tests/graphics/android/CMakeLists.txt'
 --- tests/unit-tests/graphics/android/CMakeLists.txt	2016-05-03 06:55:25 +0000
 +++ tests/unit-tests/graphics/android/CMakeLists.txt	2016-07-11 12:50:47 +0000
@@ -32,6 +32,7 @@
    ${CMAKE_CURRENT_SOURCE_DIR}/test_display_hotplug.cpp
    ${CMAKE_CURRENT_SOURCE_DIR}/test_egl_sync_extensions.cpp
    ${CMAKE_CURRENT_SOURCE_DIR}/test_egl_sync_fence.cpp
++  ${CMAKE_CURRENT_SOURCE_DIR}/test_anw_logger.cpp
    $<TARGET_OBJECTS:mirplatformgraphicsandroidobjects>
+ )
 === added file 'tests/unit-tests/graphics/android/test_anw_logger.cpp'
 --- tests/unit-tests/graphics/android/test_anw_logger.cpp	1970-01-01 00:00:00 +0000
 +++ tests/unit-tests/graphics/android/test_anw_logger.cpp	2016-07-11 12:50:47 +0000
@@ -0,0 +1,107 @@
++/*
++ * Copyright © 2014 Canonical Ltd.
++ *
++ * This program is free software: you can redistribute it and/or modify
++ * it under the terms of the GNU General Public License version 3 as
++ * published by the Free Software Foundation.
++ *
++ * This program is distributed in the hope that it will be useful,
++ * but WITHOUT ANY WARRANTY; without even the implied warranty of
++ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
++ * GNU General Public License for more details.
++ *
++ * You should have received a copy of the GNU General Public License
++ * along with this program.  If not, see <http://www.gnu.org/licenses/>.
++ *
++ * Authored by: Kevin DuBois <kevin.dubois@canonical.com>
++ */
++
++#include "native_window_report.h"
++#include "mir/logging/logger.h"
++#include <system/window.h>
++#include <iostream>
++#include <gmock/gmock.h>
++#include <gtest/gtest.h>
++
++using namespace testing;
++namespace mga = mir::graphics::android;
++namespace ml = mir::logging;
++
++namespace
++{
++
++struct MockLogger : ml::Logger
++{
++    MOCK_METHOD3(log, void(ml::Severity, std::string const&, std::string const&));
++};
++
++struct ANWLogger : Test
++{
++    std::shared_ptr<MockLogger> mock_logger = std::make_shared<MockLogger>();
++    mga::ConsoleNativeWindowReport report{mock_logger};
++    ANativeWindow anw;
++    ANativeWindowBuffer anwb;
++    int dummy_fd = 421;
++    int dummy_cleared_fd = -421;
++
++};
++}
++
++TEST_F(ANWLogger, logs_buffer_events)
++{
++    std::stringstream expected1;
++    std::stringstream expected2;
++    std::stringstream expected3;
++    std::stringstream expected4;
++    std::stringstream expected5;
++    expected1 << "addr (" << &anw << "): queueBuffer: " << &anwb << ", fence: " << dummy_fd;
++    expected2 << "addr (" << &anw << "): dequeueBuffer: " << &anwb << ", fence: none";
++    expected3 << "addr (" << &anw << "): cancelBuffer: " << &anwb << ", fence: none";
++    expected4 << "addr (" << &anw << "): dequeueBuffer_deprecated: " << &anwb;
++    expected5 << "addr (" << &anw << "): cancelBuffer_deprecated: " << &anwb;
++
++    InSequence seq;
++    EXPECT_CALL(*mock_logger, log(_,StrEq(expected1.str()),_));
++    EXPECT_CALL(*mock_logger, log(_,StrEq(expected2.str()),_));
++    EXPECT_CALL(*mock_logger, log(_,StrEq(expected3.str()),_));
++    EXPECT_CALL(*mock_logger, log(_,StrEq(expected4.str()),_));
++    EXPECT_CALL(*mock_logger, log(_,StrEq(expected5.str()),_));
++
++    report.buffer_event(mga::BufferEvent::Queue, &anw, &anwb, dummy_fd);
++    report.buffer_event(mga::BufferEvent::Dequeue, &anw, &anwb, dummy_cleared_fd);
++    report.buffer_event(mga::BufferEvent::Cancel, &anw, &anwb, dummy_cleared_fd);
++    report.buffer_event(mga::BufferEvent::Dequeue, &anw, &anwb);
++    report.buffer_event(mga::BufferEvent::Cancel, &anw, &anwb);
++}
++
++TEST_F(ANWLogger, logs_perform_events)
++{
++    std::stringstream expected1;
++    std::stringstream expected2;
++    expected1 << "addr (" << &anw << "): perform: NATIVE_WINDOW_SET_USAGE: 0x734, 0x858";
++    expected2 << "addr (" << &anw << "): perform: NATIVE_WINDOW_SET_BUFFERS_TIMESTAMP: 0x313";
++
++    InSequence seq;
++    EXPECT_CALL(*mock_logger, log(_,StrEq(expected1.str()),_));
++    EXPECT_CALL(*mock_logger, log(_,StrEq(expected2.str()),_));
++
++    report.perform_event(&anw, NATIVE_WINDOW_SET_USAGE, {0x734, 0x858} );
++    report.perform_event(&anw, NATIVE_WINDOW_SET_BUFFERS_TIMESTAMP, {0x313} );
++}
++
++TEST_F(ANWLogger, logs_query_events)
++{
++    unsigned int width = 0x380;
++    unsigned int type = 0x2;
++    std::stringstream expected1;
++    std::stringstream expected2;
++    expected1 << "addr (" << &anw << "): query: NATIVE_WINDOW_WIDTH: result: 0x380";
++    expected2 << "addr (" << &anw << "): query: NATIVE_WINDOW_CONCRETE_TYPE: result: 0x2";
++
++    InSequence seq;
++    EXPECT_CALL(*mock_logger, log(_,StrEq(expected1.str()),_));
++    EXPECT_CALL(*mock_logger, log(_,StrEq(expected2.str()),_));
++
++    report.query_event(&anw, NATIVE_WINDOW_WIDTH, width);
++    report.query_event(&anw, NATIVE_WINDOW_CONCRETE_TYPE, type);
++}
 === modified file 'tests/unit-tests/graphics/android/test_display.cpp'
 --- tests/unit-tests/graphics/android/test_display.cpp	2016-06-28 18:35:12 +0000
 +++ tests/unit-tests/graphics/android/test_display.cpp	2016-07-11 12:50:47 +0000
@@ -34,6 +34,7 @@
  #include "mir/test/doubles/stub_display_configuration.h"
  #include "mir/test/doubles/stub_renderable.h"
  #include "mir_native_window.h"
++#include "native_window_report.h"
  #include "mir/test/doubles/stub_driver_interpreter.h"
  #include <gtest/gtest.h>
@@ -63,6 +64,7 @@
            dummy_context{mock_egl.fake_egl_context},
            dummy_config{mock_egl.fake_configs[0]},
            null_display_report{mir::report::null_display_report()},
++          null_anw_report(std::make_shared<mga::NullNativeWindowReport>()),
            stub_db_factory{std::make_shared<mtd::StubDisplayBuilder>()},
            stub_gl_config{std::make_shared<mtd::StubGLConfig>()},
            stub_gl_program_factory{std::make_shared<mtd::StubGLProgramFactory>()}
@@ -77,6 +79,7 @@
      EGLConfig const dummy_config;
      std::shared_ptr<mg::DisplayReport> const null_display_report;
++    std::shared_ptr<mga::NativeWindowReport> const null_anw_report;
      std::shared_ptr<mtd::StubDisplayBuilder> const stub_db_factory;
      std::shared_ptr<mtd::StubGLConfig> const stub_gl_config;
      std::shared_ptr<mtd::StubGLProgramFactory> const stub_gl_program_factory;
@@ -132,6 +135,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::disabled);
+ }
@@ -181,6 +185,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::disabled);
      EXPECT_EQ(correct_config, selected_config);
+ }
@@ -210,6 +215,7 @@
          stub_gl_program_factory,
          mock_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::disabled);
+ }
@@ -233,6 +239,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          mock_display_report,
++        null_anw_report,
          mga::OverlayOptimization::disabled);
+ }
@@ -261,6 +268,7 @@
              stub_gl_program_factory,
              stub_gl_config,
              mock_display_report,
++            null_anw_report,
              mga::OverlayOptimization::disabled);
      }, std::runtime_error);
+ }
@@ -288,6 +296,7 @@
              stub_gl_program_factory,
              stub_gl_config,
              mock_display_report,
++            null_anw_report,
              mga::OverlayOptimization::disabled);
      }, std::runtime_error);
+ }
@@ -306,6 +315,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::disabled);
+ }
@@ -323,6 +333,7 @@
              stub_gl_program_factory,
              stub_gl_config,
              null_display_report,
++            null_anw_report,
              mga::OverlayOptimization::disabled);});
+ }
@@ -341,6 +352,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::disabled);
+ }
@@ -365,6 +377,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::disabled);
      auto configuration = display.configuration();
@@ -427,6 +440,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto config = display.configuration();
@@ -478,6 +492,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto config = display.configuration();
@@ -527,6 +542,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto config = display.configuration();
      config->for_each_output([](mg::UserDisplayConfigurationOutput const& c){
@@ -552,6 +568,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto config = display.configuration();
@@ -575,6 +592,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto scale = 4.2f;
@@ -598,6 +616,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto form_factor = mir_form_factor_tablet;
@@ -630,6 +649,7 @@
              stub_gl_program_factory,
              stub_gl_config,
              null_display_report,
++            null_anw_report,
              mga::OverlayOptimization::enabled);
          EXPECT_THAT(subscription.use_count(), Gt(use_count_before));
+     }
@@ -679,6 +699,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto config = display.configuration();
@@ -722,6 +743,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto group_count = 0;
@@ -803,6 +825,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      //hotplug external away
@@ -842,6 +865,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto configuration = display.configuration();
@@ -883,6 +907,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      vsync_fn(mga::DisplayName::primary);
@@ -896,6 +921,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      int num_cards = 0;
@@ -918,6 +944,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto config = display.configuration();
@@ -964,6 +991,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      //hotplug external back
@@ -1000,6 +1028,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::disabled);
      display.for_each_display_sync_group([](mg::DisplaySyncGroup& group) {
@@ -1035,6 +1064,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      auto db_count = 0;
@@ -1063,6 +1093,7 @@
          stub_gl_program_factory,
          stub_gl_config,
          null_display_report,
++        null_anw_report,
          mga::OverlayOptimization::enabled);
      int const virtual_output_width{1234};
 === modified file 'tests/unit-tests/graphics/android/test_display_buffer.cpp'
 --- tests/unit-tests/graphics/android/test_display_buffer.cpp	2016-05-03 06:55:25 +0000
 +++ tests/unit-tests/graphics/android/test_display_buffer.cpp	2016-07-11 12:50:47 +0000
@@ -18,6 +18,7 @@
  #include "src/platforms/android/server/display_buffer.h"
  #include "src/platforms/android/server/gl_context.h"
++#include "native_window_report.h"
  #include "android_format_conversion-inl.h"
  #include "mir/test/doubles/mock_display_device.h"
  #include "mir/test/doubles/mock_display_report.h"
@@ -59,7 +60,8 @@
          std::make_shared<testing::NiceMock<mtd::StubBuffer>>()};
      std::shared_ptr<ANativeWindow> native_window{
          std::make_shared<mg::android::MirNativeWindow>(
--            std::make_shared<mtd::StubDriverInterpreter>())};
++            std::make_shared<mtd::StubDriverInterpreter>(),
++            std::make_shared<mga::NullNativeWindowReport>())};
      std::shared_ptr<mtd::MockDisplayDevice> mock_display_device{
          std::make_shared<testing::NiceMock<mtd::MockDisplayDevice>>()};
      geom::Size const display_size{433,232};
 === modified file 'tests/unit-tests/graphics/android/test_display_hotplug.cpp'
 --- tests/unit-tests/graphics/android/test_display_hotplug.cpp	2016-05-03 06:55:25 +0000
 +++ tests/unit-tests/graphics/android/test_display_hotplug.cpp	2016-07-11 12:50:47 +0000
@@ -30,6 +30,7 @@
  #include "mir/test/doubles/mock_egl.h"
  #include "mir/test/doubles/mock_gl.h"
  #include "mir/test/auto_unblock_thread.h"
++#include "native_window_report.h"
  #include <gtest/gtest.h>
  namespace mga=mir::graphics::android;
@@ -128,6 +129,7 @@
          std::make_shared<mir::gl::DefaultProgramFactory>(),
          std::make_shared<mtd::StubGLConfig>(),
          mir::report::null_display_report(),
++        std::make_shared<mga::NullNativeWindowReport>(),
          mga::OverlayOptimization::enabled};
  };
 === modified file 'tests/unit-tests/graphics/android/test_platform.cpp'
 --- tests/unit-tests/graphics/android/test_platform.cpp	2016-06-29 15:50:53 +0000
 +++ tests/unit-tests/graphics/android/test_platform.cpp	2016-07-11 12:50:47 +0000
@@ -33,6 +33,7 @@
  #include "mir/test/doubles/null_gl_context.h"
  #include "mir_test_framework/executable_path.h"
  #include "mir/shared_library.h"
++#include "native_window_report.h"
  #include <system/window.h>
  #include <gtest/gtest.h>
@@ -90,6 +91,7 @@
      std::shared_ptr<mtd::MockBuffer> mock_buffer;
      std::shared_ptr<native_handle_t> native_buffer_handle;
      std::shared_ptr<mg::DisplayReport> stub_display_report;
++    std::shared_ptr<mga::NativeWindowReport> anw_report = std::make_shared<mga::NullNativeWindowReport>();
      testing::NiceMock<mtd::MockEGL> mock_egl;
      mtd::NullGLContext context;
      std::shared_ptr<mga::DeviceQuirks> quirks;
@@ -107,7 +109,7 @@
          .WillOnce(Return(fake_fence));
      mga::Platform platform(stub_buffer_allocator, stub_display_builder,
--        stub_display_report, mga::OverlayOptimization::enabled, quirks);
++        stub_display_report, anw_report, mga::OverlayOptimization::enabled, quirks);
      mtd::MockBufferIpcMessage mock_ipc_msg;
      int offset = 0;
@@ -140,7 +142,7 @@
          .WillOnce(Return(-1));
      mga::Platform platform(stub_buffer_allocator, stub_display_builder,
--        stub_display_report, mga::OverlayOptimization::enabled, quirks);
++        stub_display_report, anw_report, mga::OverlayOptimization::enabled, quirks);
      mtd::MockBufferIpcMessage mock_ipc_msg;
      int offset = 0;
@@ -181,7 +183,7 @@
          .WillOnce(Return(-1));
      mga::Platform platform(stub_buffer_allocator, stub_display_builder,
--        stub_display_report, mga::OverlayOptimization::enabled, quirks);
++        stub_display_report, anw_report, mga::OverlayOptimization::enabled, quirks);
      mtd::MockBufferIpcMessage mock_ipc_msg;
      int offset = 0;
@@ -217,7 +219,7 @@
      int fake_fence{33};
      mga::Platform platform(stub_buffer_allocator, stub_display_builder,
--        stub_display_report, mga::OverlayOptimization::enabled, quirks);
++        stub_display_report, anw_report, mga::OverlayOptimization::enabled, quirks);
      auto ipc_ops = platform.make_ipc_operations();
      mtd::MockBufferIpcMessage mock_ipc_msg;
@@ -247,6 +249,7 @@
          std::make_shared<mtd::StubBufferAllocator>(),
          std::make_shared<mtd::StubDisplayBuilder>(),
          mr::null_display_report(),
++        std::make_shared<mga::NullNativeWindowReport>(),
          mga::OverlayOptimization::enabled,
          std::make_shared<mga::DeviceQuirks>(mga::PropertiesOps{}, context));
      EXPECT_EQ(EGL_DEFAULT_DISPLAY, platform.egl_native_display());