Merge lp:~phablet-team/media-hub/add-logger into lp:media-hub

[Jim Hodapp]

Add a proper logger to media-hub that includes traces, timestamps and other conveniences and no longer rely on cout/cerr.

Add a proper logger to media-hub that includes traces, timestamps and other conveniences and no longer rely on cout/cerr.

[Konrad Zapałowicz (kzapalowicz)]

Not many issues compared to the length of the diff and frankly I'm mostly concerned about the own noncopyable class.

There is also one thing which is not bad however I would like to highlight it. I did not like the need to create stringstream in so many cases to log a line as basically this is repeating.

review: Needs Fixing (code)

[Alfonso Sanchez-Beato (alfonsosanchezbeato)]

I have some concerns with this MP:

* I do not really like moving to the printf way of doing things. Why should be drop type safeness? It would be better to use the boost logger more "natively" with "<<" operators, changing the wrapper class to something similar to what Qt does (qDebug() << message, etc.). Even more, using printf way in the end we need to resort to using stringstream in several places where it was not needed before.

* I still see cout and cerr being used in many places. But please do not change that yet until we have an agreement on how the class Logger should be used.

* I do not think we should introduce functions in the Utils namespace that we do not use. Specially taking into account that I would prefer to avoid using the only one that seems to be used, Sprintf :)

* Line sizes in new files are > 100 in many cases

There are also a couple of inline comments.

review: Needs Fixing

[Jim Hodapp (jhodapp)]

> Not many issues compared to the length of the diff and frankly I'm mostly
> concerned about the own noncopyable class.

I am using this same logger which comes from aethercast. It relies on it's own noncopyable class, so just maintaing consistency. Really, this logger should be brought into a standard library for everyone to use, but that's out of the scope of this story.

>
> There is also one thing which is not bad however I would like to highlight it.
> I did not like the need to create stringstream in so many cases to log a line
> as basically this is repeating.

[Jim Hodapp (jhodapp)]

> I have some concerns with this MP:
>
> * I do not really like moving to the printf way of doing things. Why should be
> drop type safeness? It would be better to use the boost logger more "natively"
> with "<<" operators, changing the wrapper class to something similar to what
> Qt does (qDebug() << message, etc.). Even more, using printf way in the end we
> need to resort to using stringstream in several places where it was not needed
> before.

Boost still maintains complete type safety with using the printf style. See the Boost::Log docs about this if you have any questions. This private Boost::Log interface implementation comes from tvoss and we're starting to standardize on it. Not sure why it doesn't use streams but that's outside anything I can really control without rewriting the private logger interface.

>
> * I still see cout and cerr being used in many places. But please do not
> change that yet until we have an agreement on how the class Logger should be
> used.

There are some that will need to remain, but otherwise I've made sure that all superfluous ones have now been removed.

>
> * I do not think we should introduce functions in the Utils namespace that we
> do not use. Specially taking into account that I would prefer to avoid using
> the only one that seems to be used, Sprintf :)

Fixed

>
> * Line sizes in new files are > 100 in many cases

I tried not to do that, any specific ones?

>
> There are also a couple of inline comments.

[Jim Hodapp (jhodapp)]

Replied/addressed inline comments.

[Konrad Zapałowicz (kzapalowicz)]

Thanks for fixes & explanations, ack.

review: Approve (code)

[Alfonso Sanchez-Beato (alfonsosanchezbeato)]

Thanks for the changes. LGTM, although I do not agree with how the Logger is designed. As discussed, we need to rethink it and come back to this when we do so.

review: Approve

[lp:~phablet-team/media-hub/add-logger]

194. By Jim Hodapp on 2016-04-06

Merged with prereq to get this to build in a silo until silo 51 lands

195. By Jim Hodapp on 2016-04-07

Make sure everything is licensed under LGPL v3

Unmerged revisions

=== modified file 'CMakeLists.txt'
--- CMakeLists.txt	2015-12-16 16:55:51 +0000
+++ CMakeLists.txt	2016-04-06 19:07:29 +0000
@@ -43,7 +43,7 @@
 include(GNUInstallDirs)
 
 find_package(PkgConfig)
-find_package(Boost COMPONENTS filesystem system program_options REQUIRED)
+find_package(Boost COMPONENTS filesystem log system thread program_options REQUIRED)
 find_package(GLog)
 pkg_check_modules(DBUS dbus-1 REQUIRED)
 pkg_check_modules(DBUS_CPP dbus-cpp REQUIRED)

=== renamed file 'debian/gen-debian-files.sh' => 'debian/bileto_pre_release_hook'
--- debian/gen-debian-files.sh	2015-11-22 21:01:02 +0000
+++ debian/bileto_pre_release_hook	2016-04-06 19:07:29 +0000
@@ -16,6 +16,7 @@
 #
 # Authored by: Michi Henning <[e-mail]>
 #              Thomas Voß <[e-mail]>
+#              Robert Bruce Park <[e-mail]>
 
 #
 # Script to generate debian files for dual landing in Vivid (gcc 4.9 ABI)
@@ -24,79 +25,47 @@
 # This script is called from debian/rules and generates:
 #
 # - control
-# - libtrust-store${soversion}.install.${target_arch}
-#
-# For all but control, this is a straight substition and/or renaming exercise for each file.
-# For control, if building on Wily or later, we also fix the "Replaces:" and "Conflicts:"
-# entries, so we don't end up with two packages claiming ownership of the same places
-# in the file system.
+# - libmedia-hub-client${MEDIA_HUB_SOVERSION}.install
+# - libmedia-hub-common${MEDIA_HUB_SOVERSION}.install
 #
 # Because the debian files for the different distributions are generated on the fly,
-# this allows us to keep a single source tree for both distributions. See ../HACKING
-# for more explanations.
+# this allows us to keep a single source tree for both distributions.
 #
 
 set -e  # Fail if any command fails.
 
 progname=$(basename $0)
 
-[ $# -ne 1 ] && {
-    echo "usage: $progname path-to-debian-dir" >&2
+[ $# -gt 1 ] && {
+    echo "usage: $progname [path-to-debian-dir]" >&2
     exit 1
 }
+version_dir=$(mktemp -d)
 dir=$1
-version_dir=$(mktemp -d)
+
+[ -n "$dir" ] || dir="./debian"
 
 # Dump version numbers into files and initialize vars from those files.
-
 sh ${dir}/get-versions.sh ${dir} ${version_dir}
 
-full_version=$(cat "${version_dir}"/libmedia-hub.full-version)
-major_minor=$(cat "${version_dir}"/libmedia-hub.major-minor-version)
-soversion=$(cat "${version_dir}"/libmedia-hub.soversion)
-vivid_soversion=$(cat "${version_dir}"/libmedia-hub.vivid-soversion)
-
-warning=$(mktemp -t gen-debian-files-msg.XXX)
-
-trap "rm -fr $warning $version_dir" 0 INT TERM QUIT
-
-warning_msg()
+export MEDIA_HUB_SOVERSION=$(cat "$version_dir/libmedia-hub.soversion")
+
+trap "rm -fr $version_dir" 0 INT TERM QUIT
+
+process()
 {
-    cat >$warning <<EOF
+    cat <<EOF
 # This file is autogenerated. DO NOT EDIT!
 #
 # Modifications should be made to $(basename "$1") instead.
 # This file is regenerated automatically in the clean target.
 #
 EOF
-}
-
-# Generate debian/control from debian/control.in, substituting the soversion for both libs.
-# For wily onwards, we also add an entry for the vivid versions to "Conflicts:" and "Replaces:".
-
-infile="${dir}"/control.in
-outfile="${dir}"/control
-warning_msg $infile
-cat $warning $infile \
-    | sed -e "s/@MEDIA_HUB_SOVERSION@/${soversion}/" > "$outfile"
-
-[ "$distro" != "vivid" ] && {
-    sed -i -e "/Replaces: libdbus-cpp4,/a\
-\          libdbus-cpp${vivid_soversion}," \
-        "$outfile"
-}
-
-# Generate the install files, naming them according to the soversion.
-
-# Install file for binary package
-infile="${dir}"/libmedia-hub-client.install.in
-outfile="${dir}"/libmedia-hub-client${soversion}.install
-warning_msg "$infile"
-cat $warning "$infile" >"$outfile"
-
-infile="${dir}"/libmedia-hub-common.install.in
-outfile="${dir}"/libmedia-hub-common${soversion}.install
-warning_msg "$infile"
-cat $warning "$infile" >"$outfile"
+    perl -pe 's/@([A-Z_]+)@/$ENV{$1} or die "$1 undefined"/eg' <"$1"
+}
+
+process "$dir/control.in" >"$dir/control"
+process "$dir/libmedia-hub-client.install.in" >"$dir/libmedia-hub-client${MEDIA_HUB_SOVERSION}.install"
+process "$dir/libmedia-hub-common.install.in" >"$dir/libmedia-hub-common${MEDIA_HUB_SOVERSION}.install"
 
 exit 0

=== modified file 'debian/control'
--- debian/control	2016-03-04 18:17:11 +0000
+++ debian/control	2016-04-06 19:07:29 +0000
@@ -20,9 +20,9 @@
                libboost-program-options-dev (>=1.53),
                libboost-system-dev (>=1.53),
                libdbus-1-dev,
-               libdbus-cpp-dev (>= 5.0.0),
+               libdbus-cpp-dev (>= 4.3.0),
                libgoogle-glog-dev,
-               libhybris-dev,
+               libhybris-dev (>=0.1.0+git20131207+e452e83-0ubuntu30),
                libprocess-cpp-dev,
                libproperties-cpp-dev,
                libgstreamer1.0-dev,
@@ -42,8 +42,8 @@
 Section: libdevel
 Architecture: any
 Multi-Arch: same
-Depends: libmedia-hub-common4 (= ${binary:Version}),
-         libmedia-hub-client4 (= ${binary:Version}),
+Depends: libmedia-hub-common5 (= ${binary:Version}),
+         libmedia-hub-client5 (= ${binary:Version}),
          ${misc:Depends},
          libproperties-cpp-dev,
 Suggests: libmedia-hub-doc
@@ -64,7 +64,7 @@
  .
  This package contains the runtime.
 
-Package: libmedia-hub-common4
+Package: libmedia-hub-common5
 Architecture: any
 Multi-Arch: same
 Depends: ${misc:Depends},
@@ -75,7 +75,7 @@
  .
  This package contains the common libraries.
 
-Package: libmedia-hub-client4
+Package: libmedia-hub-client5
 Architecture: any
 Multi-Arch: same
 Depends: ${misc:Depends},

=== modified file 'debian/control.in'
--- debian/control.in	2015-11-22 21:01:02 +0000
+++ debian/control.in	2016-04-06 19:07:29 +0000
@@ -12,6 +12,7 @@
                gstreamer1.0-plugins-good,
                libboost-dev (>=1.53),
                libboost-filesystem-dev (>=1.53),
+               libboost-log-dev (>=1.53),
                libboost-program-options-dev (>=1.53),
                libboost-system-dev (>=1.53),
                libdbus-1-dev,

=== modified file 'debian/get-versions.sh'
--- debian/get-versions.sh	2015-11-22 21:01:02 +0000
+++ debian/get-versions.sh	2016-04-06 19:07:29 +0000
@@ -38,7 +38,7 @@
 # Write the various version numbers into a bunch of files. This allows
 # us to easily pick them up from both gen-debian-files.sh and CMakeLists.txt.
 
-distro=$(lsb_release -c -s)
+[ -n "$SERIES" ] || SERIES="$(lsb_release -c -s)"
 
 full_version=$(cat "${dir}"/VERSION)
 
@@ -51,13 +51,15 @@
 vivid_major=$(echo $vivid_full_version | cut -d'.' -f1)
 vivid_soversion=$vivid_major
 
-if [ "$distro" = "vivid" ]
+if [ "$SERIES" = "vivid" ]
 then
     soversion=${vivid_soversion}
 else
     soversion="${major}"
 fi
-[ -n $soversion ]
+[ -n "$soversion" ]
+
+echo "Using SOVERSION $soversion in $SERIES." >&2
 
 echo ${full_version} >${output_dir}/libmedia-hub.full-version
 echo ${major} >${output_dir}/libmedia-hub.major-version

=== modified file 'debian/rules'
--- debian/rules	2015-11-22 21:01:02 +0000
+++ debian/rules	2016-04-06 19:07:29 +0000
@@ -34,5 +34,5 @@
 	dh_installdeb
 
 override_dh_auto_clean:
-	/bin/sh $(CURDIR)/debian/gen-debian-files.sh $(CURDIR)/debian
+	/bin/sh $(CURDIR)/debian/bileto_pre_release_hook
 	dh_auto_clean

=== modified file 'include/core/media/player.h'
--- include/core/media/player.h	2016-02-19 16:14:42 +0000
+++ include/core/media/player.h	2016-04-06 19:07:29 +0000
@@ -229,6 +229,29 @@
     return out;
 }
 
+inline std::ostream& operator<<(std::ostream& out, Player::Error e)
+{
+    switch (e)
+    {
+        case Player::Error::no_error:
+            return out << "Error::no_error";
+        case Player::Error::resource_error:
+            return out << "Error::resource_error";
+        case Player::Error::format_error:
+            return out << "Error::format_error";
+        case Player::Error::network_error:
+            return out << "Error::network_error";
+        case Player::Error::access_denied_error:
+            return out << "Error::access_denied_error";
+        case Player::Error::service_missing_error:
+            return out << "Error::service_missing_error";
+        default:
+            return out << "Unsupported Player error: " << e;
+    }
+
+    return out;
+}
+
 }
 }
 }

=== modified file 'src/core/media/CMakeLists.txt'
--- src/core/media/CMakeLists.txt	2015-09-04 18:46:08 +0000
+++ src/core/media/CMakeLists.txt	2016-04-06 19:07:29 +0000
@@ -18,6 +18,7 @@
   media-hub-common SHARED
 
   the_session_bus.cpp
+  util/utils.cpp
 )
 
 target_link_libraries(
@@ -42,6 +43,8 @@
 
   ${MEDIA_HUB_HEADERS}
 
+  logger/logger.cpp
+
   player.cpp
   service.cpp
   track.cpp
@@ -70,6 +73,8 @@
 
   media-hub-common
 
+  ${Boost_LDFLAGS}
+  ${Boost_LIBRARIES}
   ${DBUS_LIBRARIES}
   ${DBUS_CPP_LDFLAGS}
   ${GLog_LIBRARY}
@@ -87,6 +92,8 @@
     ${MEDIA_HUB_HEADERS}
     ${MPRIS_HEADERS}
 
+    logger/logger.cpp
+
     client_death_observer.cpp
     hashed_keyed_player_store.cpp
     hybris_client_death_observer.cpp
@@ -123,6 +130,8 @@
   media-hub-client
   media-hub-common
   call-monitor
+  ${Boost_LDFLAGS}
+  ${Boost_LIBRARIES}
   ${DBUS_LIBRARIES}
   ${DBUS_CPP_LDFLAGS}
   ${GLog_LIBRARY}

=== modified file 'src/core/media/apparmor/ubuntu.cpp'
--- src/core/media/apparmor/ubuntu.cpp	2016-02-23 14:17:04 +0000
+++ src/core/media/apparmor/ubuntu.cpp	2016-04-06 19:07:29 +0000
@@ -20,7 +20,8 @@
 
 #include <core/media/external_services.h>
 
-#include <iostream>
+#include "core/media/logger/logger.h"
+
 #include <regex>
 
 namespace apparmor = core::ubuntu::media::apparmor;
@@ -107,9 +108,9 @@
       unity_{name == unity_name},
       has_package_name_{process_context_name(str(), match_, pkg_name_)}
 {
-    std::cout << "apparmor profile name: " << name;
-    std::cout << ", is_unconfined(): " << is_unconfined();
-    std::cout << ", has_package_name(): " << has_package_name() << std::endl;
+    MH_DEBUG("apparmor profile name: %s", name);
+    MH_DEBUG("is_unconfined(): %s", (is_unconfined() ? "true" : "false"));
+    MH_DEBUG("has_package_name(): %s", (has_package_name() ? "true" : "false"));
     if (not is_unconfined() and not is_unity() and not has_package_name())
         throw std::logic_error
         {
@@ -163,8 +164,8 @@
 
     Uri parsed_uri = parse_uri(uri);
 
-    std::cout << "context.profile_name(): " << context.profile_name() << std::endl;
-    std::cout << "parsed_uri.path: " << parsed_uri.path << std::endl;
+    MH_DEBUG("context.profile_name(): %s", context.profile_name());
+    MH_DEBUG("parsed_uri.path: %s", parsed_uri.path);
 
     // All confined apps can access their own files
     if (parsed_uri.path.find(std::string(".local/share/" + context.package_name() + "/")) != std::string::npos ||

=== modified file 'src/core/media/audio/pulse_audio_output_observer.cpp'
--- src/core/media/audio/pulse_audio_output_observer.cpp	2015-03-19 00:04:12 +0000
+++ src/core/media/audio/pulse_audio_output_observer.cpp	2016-04-06 19:07:29 +0000
@@ -21,6 +21,8 @@
 
 #include <pulse/pulseaudio.h>
 
+#include "core/media/logger/logger.h"
+
 #include <cstdint>
 
 #include <map>
@@ -245,7 +247,7 @@
             std::get<1>(outputs.back()) | properties.external_output_state;
             std::get<1>(outputs.back()).changed().connect([](media::audio::OutputState state)
             {
-                std::cout << "Connection state for port changed to: " << state << std::endl;
+                MH_DEBUG("Connection state for port changed to: %s", state);
             });
         }
 
@@ -289,8 +291,8 @@
     void on_sink_event_with_index(std::int32_t index)
     {
         config.reporter->sink_event_with_index(index);
-         
-        // Update server info (active sink)    
+
+        // Update server info (active sink)
         pa::get_server_info_async(context, main_loop, Private::query_for_server_info_finished, this);
 
     }
@@ -317,15 +319,15 @@
             if (std::get<0>(active_sink) != info->index)
                 continue;
 
-            std::cout << "Checking if port is available " << " -> " << std::boolalpha << pa::is_port_available_on_sink(info, std::get<0>(element)) << std::endl;
-            bool available = pa::is_port_available_on_sink(info, std::get<0>(element));
-
+            MH_INFO("Checking if port is available -> %s",
+                    pa::is_port_available_on_sink(info, std::get<0>(element)));
+            const bool available = pa::is_port_available_on_sink(info, std::get<0>(element));
             if (available)
             {
                 std::get<1>(element) = audio::OutputState::Earpiece;
                 continue;
             }
-    
+
             audio::OutputState state;
             if (info->index == primary_sink_index)
                 state = audio::OutputState::Speaker;
@@ -386,7 +388,7 @@
         }
     }
 
-    PulseAudioOutputObserver::Configuration config;    
+    PulseAudioOutputObserver::Configuration config;
     pa::ThreadedMainLoopPtr main_loop;
     pa::ContextPtr context;
     std::int32_t primary_sink_index;

=== modified file 'src/core/media/gstreamer/engine.cpp'
--- src/core/media/gstreamer/engine.cpp	2016-02-19 16:14:42 +0000
+++ src/core/media/gstreamer/engine.cpp	2016-04-06 19:07:29 +0000
@@ -25,6 +25,8 @@
 #include "meta_data_extractor.h"
 #include "playbin.h"
 
+#include "core/media/logger/logger.h"
+
 #include <cassert>
 
 namespace media = core::ubuntu::media;
@@ -67,8 +69,8 @@
     {
         if (p.second == "playbin")
         {
-            std::cout << "State changed on playbin: "
-                      << gst_element_state_get_name(p.first.new_state) << std::endl;
+            MH_INFO("State changed on playbin: %s",
+                      gst_element_state_get_name(p.first.new_state));
             const auto status = gst_state_to_player_status(p.first);
             /*
              * When state moves to "paused" the pipeline is already set. We check that we
@@ -76,7 +78,7 @@
              */
             if (status == media::Player::PlaybackStatus::paused &&
                     !playbin.can_play_streams()) {
-                std::cerr << "** Cannot play: some codecs are missing" << std::endl;
+                MH_ERROR("** Cannot play: some codecs are missing");
                 playbin.reset();
                 const media::Player::Error e = media::Player::Error::format_error;
                 error(e);
@@ -96,20 +98,20 @@
             switch (ewi.error->code)
             {
             case GST_CORE_ERROR_FAILED:
-                std::cerr << "** Encountered a GST_CORE_ERROR_FAILED" << std::endl;
+                MH_ERROR("** Encountered a GST_CORE_ERROR_FAILED");
                 ret_error = media::Player::Error::resource_error;
                 break;
             case GST_CORE_ERROR_NEGOTIATION:
-                std::cerr << "** Encountered a GST_CORE_ERROR_NEGOTIATION" << std::endl;
+                MH_ERROR("** Encountered a GST_CORE_ERROR_NEGOTIATION");
                 ret_error = media::Player::Error::resource_error;
                 break;
             case GST_CORE_ERROR_MISSING_PLUGIN:
-                std::cerr << "** Encountered a GST_CORE_ERROR_MISSING_PLUGIN" << std::endl;
+                MH_ERROR("** Encountered a GST_CORE_ERROR_MISSING_PLUGIN");
                 ret_error = media::Player::Error::format_error;
                 break;
             default:
-                std::cerr << "** Encountered an unhandled core error: '"
-                    << ewi.debug << "' (code: " << ewi.error->code << ")" << std::endl;
+                MH_ERROR("** Encountered an unhandled core error: '%s' (code: %d)",
+                    ewi.debug, ewi.error->code);
                 ret_error = media::Player::Error::no_error;
                 break;
             }
@@ -119,36 +121,36 @@
             switch (ewi.error->code)
             {
             case GST_RESOURCE_ERROR_FAILED:
-                std::cerr << "** Encountered a GST_RESOURCE_ERROR_FAILED" << std::endl;
+                MH_ERROR("** Encountered a GST_RESOURCE_ERROR_FAILED");
                 ret_error = media::Player::Error::resource_error;
                 break;
             case GST_RESOURCE_ERROR_NOT_FOUND:
-                std::cerr << "** Encountered a GST_RESOURCE_ERROR_NOT_FOUND" << std::endl;
+                MH_ERROR("** Encountered a GST_RESOURCE_ERROR_NOT_FOUND");
                 ret_error = media::Player::Error::resource_error;
                 break;
             case GST_RESOURCE_ERROR_OPEN_READ:
-                std::cerr << "** Encountered a GST_RESOURCE_ERROR_OPEN_READ" << std::endl;
+                MH_ERROR("** Encountered a GST_RESOURCE_ERROR_OPEN_READ");
                 ret_error = media::Player::Error::resource_error;
                 break;
             case GST_RESOURCE_ERROR_OPEN_WRITE:
-                std::cerr << "** Encountered a GST_RESOURCE_ERROR_OPEN_WRITE" << std::endl;
+                MH_ERROR("** Encountered a GST_RESOURCE_ERROR_OPEN_WRITE");
                 ret_error = media::Player::Error::resource_error;
                 break;
             case GST_RESOURCE_ERROR_READ:
-                std::cerr << "** Encountered a GST_RESOURCE_ERROR_READ" << std::endl;
+                MH_ERROR("** Encountered a GST_RESOURCE_ERROR_READ");
                 ret_error = media::Player::Error::resource_error;
                 break;
             case GST_RESOURCE_ERROR_WRITE:
-                std::cerr << "** Encountered a GST_RESOURCE_ERROR_WRITE" << std::endl;
+                MH_ERROR("** Encountered a GST_RESOURCE_ERROR_WRITE");
                 ret_error = media::Player::Error::resource_error;
                 break;
             case GST_RESOURCE_ERROR_NOT_AUTHORIZED:
-                std::cerr << "** Encountered a GST_RESOURCE_ERROR_NOT_AUTHORIZED" << std::endl;
+                MH_ERROR("** Encountered a GST_RESOURCE_ERROR_NOT_AUTHORIZED");
                 ret_error = media::Player::Error::access_denied_error;
                 break;
             default:
-                std::cerr << "** Encountered an unhandled resource error: '"
-                    << ewi.debug << "' (code: " << ewi.error->code << ")" << std::endl;
+                MH_ERROR("** Encountered an unhandled resource error: '%s' (code: %d)",
+                    ewi.debug, ewi.error->code);
                 ret_error = media::Player::Error::no_error;
                 break;
             }
@@ -158,28 +160,28 @@
             switch (ewi.error->code)
             {
             case GST_STREAM_ERROR_FAILED:
-                std::cerr << "** Encountered a GST_STREAM_ERROR_FAILED" << std::endl;
+                MH_ERROR("** Encountered a GST_STREAM_ERROR_FAILED");
                 ret_error = media::Player::Error::resource_error;
                 break;
             case GST_STREAM_ERROR_CODEC_NOT_FOUND:
-                std::cerr << "** Encountered a GST_STREAM_ERROR_CODEC_NOT_FOUND" << std::endl;
+                MH_ERROR("** Encountered a GST_STREAM_ERROR_CODEC_NOT_FOUND");
                 // Missing codecs are handled later, when state switches to "paused"
                 ret_error = media::Player::Error::no_error;
                 break;
             case GST_STREAM_ERROR_DECODE:
-                std::cerr << "** Encountered a GST_STREAM_ERROR_DECODE" << std::endl;
+                MH_ERROR("** Encountered a GST_STREAM_ERROR_DECODE");
                 ret_error = media::Player::Error::format_error;
                 break;
             default:
-                std::cerr << "** Encountered an unhandled stream error: '"
-                    << ewi.debug << "' (code: " << ewi.error->code << ")" << std::endl;
+                MH_ERROR("** Encountered an unhandled stream error: '%s' code(%d)",
+                    ewi.debug, ewi.error->code);
                 ret_error = media::Player::Error::no_error;
                 break;
             }
         }
 
         if (ret_error != media::Player::Error::no_error) {
-            std::cerr << "Resetting playbin pipeline after unrecoverable error" << std::endl;
+            MH_ERROR("Resetting playbin pipeline after unrecoverable error");
             playbin.reset();
         }
         return ret_error;
@@ -201,7 +203,7 @@
 
     void on_playbin_info(const gstreamer::Bus::Message::Detail::ErrorWarningInfo& ewi)
     {
-        std::cerr << "Got a playbin info message (no action taken): " << ewi.debug << std::endl;
+        MH_DEBUG("Got a playbin info message (no action taken): %s", ewi.debug);
     }
 
     void on_tag_available(const gstreamer::Bus::Message::Detail::Tag& tag)
@@ -437,8 +439,7 @@
     if (result)
     {
         d->state = media::Engine::State::playing;
-        cout << __PRETTY_FUNCTION__ << endl;
-        cout << "Engine: playing uri: " << d->playbin.uri() << endl;
+        MH_INFO("Engine: playing uri: %s", d->playbin.uri());
         d->playback_status_changed(media::Player::PlaybackStatus::playing);
     }
 
@@ -450,7 +451,7 @@
     // No need to wait, and we can immediately return.
     if (d->state == media::Engine::State::stopped)
     {
-        std::cerr << "Current player state is already stopped - no need to change state to stopped" << std::endl;
+        MH_DEBUG("Current player state is already stopped - no need to change state to stopped");
         return true;
     }
 
@@ -458,7 +459,7 @@
     if (result)
     {
         d->state = media::Engine::State::stopped;
-        cout << __PRETTY_FUNCTION__ << endl;
+        MH_TRACE("");
         d->playback_status_changed(media::Player::PlaybackStatus::stopped);
     }
 
@@ -472,7 +473,7 @@
     if (result)
     {
         d->state = media::Engine::State::paused;
-        cout << __PRETTY_FUNCTION__ << endl;
+        MH_TRACE("");
         d->playback_status_changed(media::Player::PlaybackStatus::paused);
     }
 

=== modified file 'src/core/media/gstreamer/playbin.cpp'
--- src/core/media/gstreamer/playbin.cpp	2016-03-07 21:05:26 +0000
+++ src/core/media/gstreamer/playbin.cpp	2016-04-06 19:07:29 +0000
@@ -25,7 +25,8 @@
 #include <hybris/media/surface_texture_client_hybris.h>
 #include <hybris/media/media_codec_layer.h>
 
-#include "../util/uri_check.h"
+#include "core/media/logger/logger.h"
+#include "core/media/util/uri_check.h"
 
 #include <utility>
 
@@ -154,13 +155,13 @@
 {
     using namespace std;
 
-    cout << func << endl;
+    MH_DEBUG("%s", func);
     if (pb.pipeline)
-        cout << "pipeline:   " << GST_OBJECT_REFCOUNT(pb.pipeline) << endl;
+        MH_DEBUG("pipeline:   %d", GST_OBJECT_REFCOUNT(pb.pipeline));
     if (pb.video_sink)
-        cout << "video_sink: " << GST_OBJECT_REFCOUNT(pb.video_sink) << endl;
+        MH_DEBUG("video_sink: %d", GST_OBJECT_REFCOUNT(pb.video_sink));
     if (pb.audio_sink)
-        cout << "audio_sink: " << GST_OBJECT_REFCOUNT(pb.audio_sink) << endl;
+        MH_DEBUG("audio_sink: %d", GST_OBJECT_REFCOUNT(pb.audio_sink));
 }
 #endif
 
@@ -183,7 +184,7 @@
 
 void gstreamer::Playbin::reset()
 {
-    std::cout << "Client died, resetting pipeline" << std::endl;
+    MH_INFO("Client died, resetting pipeline");
     // When the client dies, tear down the current pipeline and get it
     // in a state that is ready for the next client that connects to the
     // service
@@ -198,19 +199,19 @@
 
 void gstreamer::Playbin::reset_pipeline()
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
-    auto ret = gst_element_set_state(pipeline, GST_STATE_NULL);
-    switch(ret)
+    MH_TRACE("");
+    const auto ret = gst_element_set_state(pipeline, GST_STATE_NULL);
+    switch (ret)
     {
     case GST_STATE_CHANGE_FAILURE:
-        std::cout << "Failed to reset the pipeline state. Client reconnect may not function properly." << std::endl;
+        MH_WARNING("Failed to reset the pipeline state. Client reconnect may not function properly.");
         break;
     case GST_STATE_CHANGE_NO_PREROLL:
     case GST_STATE_CHANGE_SUCCESS:
     case GST_STATE_CHANGE_ASYNC:
         break;
     default:
-        std::cout << "Failed to reset the pipeline state. Client reconnect may not function properly." << std::endl;
+        MH_WARNING("Failed to reset the pipeline state. Client reconnect may not function properly.");
     }
     file_type = MEDIA_FILE_TYPE_NONE;
     is_missing_audio_codec = false;
@@ -225,7 +226,7 @@
       return;
 
     gchar *desc = gst_missing_plugin_message_get_description(message);
-    std::cerr << "Missing plugin: " << desc << std::endl;
+    MH_WARNING("Missing plugin: %s", desc);
     g_free(desc);
 
     const GstStructure *msg_data = gst_message_get_structure(message);
@@ -234,13 +235,13 @@
 
     GstCaps *caps;
     if (!gst_structure_get(msg_data, "detail", GST_TYPE_CAPS, &caps, NULL)) {
-        std::cerr << __PRETTY_FUNCTION__ << ": No detail" << std::endl;
+        MH_ERROR("No detail");
         return;
     }
 
     GstStructure *caps_data = gst_caps_get_structure(caps, 0);
     if (!caps_data) {
-        std::cerr << __PRETTY_FUNCTION__ << ": No caps data" << std::endl;
+        MH_ERROR("No caps data");
         return;
     }
 
@@ -250,7 +251,7 @@
     else if (strstr(mime, "video"))
         is_missing_video_codec = true;
 
-    std::cerr << "Missing decoder for " << mime << std::endl;
+    MH_ERROR("Missing decoder for %s", mime);
 }
 
 void gstreamer::Playbin::on_new_message_async(const Bus::Message& message)
@@ -324,7 +325,7 @@
                     ::getenv("CORE_UBUNTU_MEDIA_SERVICE_AUDIO_SINK_NAME"),
                     "audio-sink");
 
-        std::cout << "audio_sink: " << ::getenv("CORE_UBUNTU_MEDIA_SERVICE_AUDIO_SINK_NAME") << std::endl;
+        MH_INFO("audio_sink: %s", ::getenv("CORE_UBUNTU_MEDIA_SERVICE_AUDIO_SINK_NAME"));
 
         g_object_set (
                     pipeline,
@@ -339,7 +340,7 @@
             ::getenv("CORE_UBUNTU_MEDIA_SERVICE_VIDEO_SINK_NAME"),
             "video-sink");
 
-        std::cout << "video_sink: " << ::getenv("CORE_UBUNTU_MEDIA_SERVICE_VIDEO_SINK_NAME") << std::endl;
+        MH_INFO("video_sink: %s", ::getenv("CORE_UBUNTU_MEDIA_SERVICE_VIDEO_SINK_NAME"));
 
         g_object_set (
                 pipeline,
@@ -404,16 +405,17 @@
 /** Sets the new audio stream role on the pulsesink in playbin */
 void gstreamer::Playbin::set_audio_stream_role(media::Player::AudioStreamRole new_audio_role)
 {
-    std::string role_str("props,media.role=" + get_audio_role_str(new_audio_role));
-    std::cout << "Audio stream role: " << role_str << std::endl;
+    const std::string role_str("props,media.role=" + get_audio_role_str(new_audio_role));
+    MH_INFO("Audio stream role: %s", role_str);
 
     GstStructure *props = gst_structure_from_string (role_str.c_str(), NULL);
-    if (audio_sink != nullptr && props != nullptr) {
+    if (audio_sink != nullptr && props != nullptr)
+    {
         g_object_set (audio_sink, "stream-properties", props, NULL);
-    } else {
-        std::cerr <<
-            "Warning: couldn't set audio stream role - couldn't get audio_sink from pipeline" <<
-            std::endl;
+    }
+    else
+    {
+        MH_WARNING("Couldn't set audio stream role - couldn't get audio_sink from pipeline");
     }
 
     gst_structure_free (props);
@@ -475,9 +477,7 @@
         {
             // First decode the URI just in case it's partially encoded already
             tmp_uri = decode_uri(uri);
-#ifdef VERBOSE_DEBUG
-            std::cout << "File URI was encoded, now decoded: " << tmp_uri << std::endl;
-#endif
+            MH_DEBUG("File URI was encoded, now decoded: %s", tmp_uri);
         }
         tmp_uri = encode_uri(tmp_uri);
     }
@@ -538,7 +538,7 @@
 
     auto ret = gst_element_set_state(pipeline, new_state);
 
-    std::cout << __PRETTY_FUNCTION__ << ": requested state change." << std::endl;
+    MH_DEBUG("Requested state change.");
 
     bool result = false; GstState current, pending;
     switch(ret)
@@ -570,15 +570,15 @@
         }
         catch (const std::exception& e)
         {
-            std::cerr << "Problem querying video dimensions: " << e.what() << std::endl;
+            MH_WARNING("Problem querying video dimensions: %s", e.what());
         }
         catch (...)
         {
-            std::cerr << "Problem querying video dimensions." << std::endl;
+            MH_WARNING("Problem querying video dimensions.");
         }
 
 #ifdef DEBUG_GST_PIPELINE
-        std::cout << "Dumping pipeline dot file" << std::endl;
+        MH_DEBUG("Dumping pipeline dot file");
         GST_DEBUG_BIN_TO_DOT_FILE((GstBin*)pipeline, GST_DEBUG_GRAPH_SHOW_ALL, "pipeline");
 #endif
     }
@@ -656,17 +656,13 @@
     // We have a URI and it is already percent encoded
     if (uri_scheme and strlen(uri_scheme) > 0 and uri_check->is_encoded())
     {
-#ifdef VERBOSE_DEBUG
-        std::cout << "Is a URI and is already percent encoded" << std::endl;
-#endif
+        MH_DEBUG("Is a URI and is already percent encoded");
         encoded_uri = uri;
     }
     // We have a URI but it's not already percent encoded
     else if (uri_scheme and strlen(uri_scheme) > 0 and !uri_check->is_encoded())
     {
-#ifdef VERBOSE_DEBUG
-        std::cout << "Is a URI and is not already percent encoded" << std::endl;
-#endif
+        MH_DEBUG("Is a URI and is not already percent encoded");
         gchar *encoded = g_uri_escape_string(uri.c_str(),
                                                    "!$&'()*+,;=:/?[]@", // reserved chars
                                                    TRUE); // Allow UTF-8 chars
@@ -681,9 +677,7 @@
     else // We have a path and not a URI. Turn it into a full URI and encode it
     {
         GError *error = nullptr;
-#ifdef VERBOSE_DEBUG
-        std::cout << "Is a path and is not already percent encoded" << std::endl;
-#endif
+        MH_DEBUG("Is a path and is not already percent encoded");
         gchar *str = g_filename_to_uri(uri.c_str(), nullptr, &error);
         if (!str)
         {
@@ -694,8 +688,7 @@
         g_free(str);
         if (error != nullptr)
         {
-            std::cerr << "Warning: failed to get actual track content type: " << error->message
-                      << std::endl;
+            MH_WARNING("Failed to get actual track content type: %s", error->message);
             g_error_free(error);
             g_free(str);
             g_free(uri_scheme);
@@ -742,11 +735,11 @@
     const std::string content_type {file_info_from_uri(encoded_uri)};
     if (content_type.empty())
     {
-        std::cerr << "Warning: failed to get actual track content type" << std::endl;
+        MH_WARNING("Failed to get actual track content type");
         return std::string("audio/video/");
     }
 
-    std::cout << "Found content type: " << content_type << std::endl;
+    MH_INFO("Found content type: %s", content_type);
 
     return content_type;
 }
@@ -758,7 +751,7 @@
 
     if (get_file_content_type(uri).find("audio/") == 0)
     {
-        std::cout << "Found audio content" << std::endl;
+        MH_INFO("Found audio content");
         return true;
     }
 
@@ -772,7 +765,7 @@
 
     if (get_file_content_type(uri).find("video/") == 0)
     {
-        std::cout << "Found video content" << std::endl;
+        MH_INFO("Found video content");
         return true;
     }
 

=== added directory 'src/core/media/logger'
=== added file 'src/core/media/logger/logger.cpp'
--- src/core/media/logger/logger.cpp	1970-01-01 00:00:00 +0000
+++ src/core/media/logger/logger.cpp	2016-04-06 19:07:29 +0000
@@ -0,0 +1,161 @@
+/*
+ * Copyright (C) 2015 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 warranties of
+ * MERCHANTABILITY, SATISFACTORY QUALITY, 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/>.
+ *
+ */
+
+#include <thread>
+
+#include "logger.h"
+
+#define BOOST_LOG_DYN_LINK
+#include <boost/date_time.hpp>
+#include <boost/filesystem.hpp>
+#include <boost/log/trivial.hpp>
+#include <boost/log/expressions.hpp>
+#include <boost/log/support/date_time.hpp>
+#include <boost/log/utility/manipulators.hpp>
+#include <boost/log/utility/setup.hpp>
+
+namespace media = core::ubuntu::media;
+
+namespace {
+namespace attrs {
+BOOST_LOG_ATTRIBUTE_KEYWORD(Severity, "core::ubuntu::media::Severity", media::Logger::Severity)
+BOOST_LOG_ATTRIBUTE_KEYWORD(Location, "Location", media::Logger::Location)
+BOOST_LOG_ATTRIBUTE_KEYWORD(Timestamp, "Timestamp", boost::posix_time::ptime)
+}
+
+struct BoostLogLogger : public media::Logger {
+    BoostLogLogger() :
+        initialized_(false) {
+    }
+
+    void Init(const media::Logger::Severity &severity = media::Logger::Severity::kWarning) override {
+        if (initialized_)
+            return;
+
+        boost::log::formatter formatter = boost::log::expressions::stream
+            << "[" << attrs::Severity << " "
+            << boost::log::expressions::format_date_time< boost::posix_time::ptime >("Timestamp", "%Y-%m-%d %H:%M:%S.%f")
+            << "] "
+            << boost::log::expressions::if_(boost::log::expressions::has_attr(attrs::Location))
+               [
+                   boost::log::expressions::stream << "[" << attrs::Location << "] "
+               ]
+            << boost::log::expressions::smessage;
+
+        boost::log::core::get()->remove_all_sinks();
+        auto logger = boost::log::add_console_log(std::cout);
+        logger->set_formatter(formatter);
+
+        // FIXME need to enable this once we found how we wrap this
+        // properly into our service architecture. For now left as
+        // it is.
+        boost::ignore_unused_variable_warning(severity);
+        // logger->set_filter(attrs::Severity < severity);
+
+        initialized_ = true;
+    }
+
+    void Log(Severity severity, const std::string& message, const boost::optional<Location> &loc) {
+        if (!initialized_)
+            Init();
+
+        if (auto rec = boost::log::trivial::logger::get().open_record()) {
+            boost::log::record_ostream out{rec};
+            out << boost::log::add_value(attrs::Severity, severity)
+                << boost::log::add_value(attrs::Timestamp, boost::posix_time::microsec_clock::universal_time())
+                << message;
+
+            if (loc) {
+                // We have to pass in a temporary as boost::log (<= 1.55) expects a
+                // mutable reference to be passed to boost::log::add_value(...).
+                auto tmp = *loc;
+                out << boost::log::add_value(attrs::Location, tmp);
+            }
+
+            boost::log::trivial::logger::get().push_record(std::move(rec));
+        }
+    }
+
+private:
+    bool initialized_;
+};
+
+std::shared_ptr<media::Logger>& MutableInstance() {
+    static std::shared_ptr<media::Logger> instance{new BoostLogLogger()};
+    return instance;
+}
+
+void SetInstance(const std::shared_ptr<media::Logger>& logger) {
+    MutableInstance() = logger;
+}
+}
+
+void media::Logger::Trace(const std::string& message, const boost::optional<Location>& location) {
+    Log(Severity::kTrace, message, location);
+}
+
+void media::Logger::Debug(const std::string& message, const boost::optional<Location>& location) {
+    Log(Severity::kDebug, message, location);
+}
+
+void media::Logger::Info(const std::string& message, const boost::optional<Location>& location) {
+    Log(Severity::kInfo, message, location);
+}
+
+void media::Logger::Warning(const std::string& message, const boost::optional<Location>& location) {
+    Log(Severity::kWarning, message, location);
+}
+
+void media::Logger::Error(const std::string& message, const boost::optional<Location>& location) {
+    Log(Severity::kError, message, location);
+}
+
+void media::Logger::Fatal(const std::string& message, const boost::optional<Location>& location) {
+    Log(Severity::kFatal, message, location);
+}
+
+namespace core {
+namespace ubuntu {
+namespace media {
+
+std::ostream& operator<<(std::ostream& strm, Logger::Severity severity) {
+    switch (severity) {
+    case media::Logger::Severity::kTrace: return strm << "TT";
+    case media::Logger::Severity::kDebug: return strm << "DD";
+    case media::Logger::Severity::kInfo: return strm << "II";
+    case media::Logger::Severity::kWarning: return strm << "WW";
+    case media::Logger::Severity::kError: return strm << "EE";
+    case media::Logger::Severity::kFatal: return strm << "FF";
+    default: return strm << static_cast<uint>(severity);
+    }
+}
+
+std::ostream& operator<<(std::ostream& out, const Logger::Location &location) {
+    return out << Utils::Sprintf("%s:%d@%s", boost::filesystem::path(location.file).filename().string(), location.line, location.function);
+}
+
+Logger& Log() {
+    return *MutableInstance();
+}
+
+void SetLogger(const std::shared_ptr<Logger>& logger) {
+    SetInstance(logger);
+}
+
+} // namespace media
+} // namespace ubuntu
+} // namespace core

=== added file 'src/core/media/logger/logger.h'
--- src/core/media/logger/logger.h	1970-01-01 00:00:00 +0000
+++ src/core/media/logger/logger.h	2016-04-06 19:07:29 +0000
@@ -0,0 +1,131 @@
+/*
+ * Copyright (C) 2015 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 warranties of
+ * MERCHANTABILITY, SATISFACTORY QUALITY, 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/>.
+ *
+ */
+
+#ifndef LOGGER_H_
+#define LOGGER_H_
+
+#include "core/media/non_copyable.h"
+#include "core/media/util/utils.h"
+
+#include <boost/optional.hpp>
+
+#include <string>
+
+namespace core {
+namespace ubuntu {
+namespace media {
+// A Logger enables persisting of messages describing & explaining the
+// state of the system.
+class Logger : public core::ubuntu::media::NonCopyable {
+public:
+    // Severity enumerates all known severity levels
+    // applicable to log messages.
+    enum class Severity {
+        kTrace,
+        kDebug,
+        kInfo,
+        kWarning,
+        kError,
+        kFatal
+    };
+
+    // A Location describes the origin of a log message.
+    struct Location {
+        std::string file; // The name of the file that contains the log message.
+        std::string function; // The function that contains the log message.
+        std::uint32_t line; // The line in file that resulted in the log message.
+    };
+
+    virtual void Init(const core::ubuntu::media::Logger::Severity &severity = core::ubuntu::media::Logger::Severity::kWarning) = 0;
+
+    virtual void Log(Severity severity, const std::string &message, const boost::optional<Location>& location) = 0;
+
+    virtual void Trace(const std::string& message, const boost::optional<Location>& location = boost::optional<Location>{});
+    virtual void Debug(const std::string& message, const boost::optional<Location>& location = boost::optional<Location>{});
+    virtual void Info(const std::string& message, const boost::optional<Location>& location = boost::optional<Location>{});
+    virtual void Warning(const std::string& message, const boost::optional<Location>& location = boost::optional<Location>{});
+    virtual void Error(const std::string& message, const boost::optional<Location>& location = boost::optional<Location>{});
+    virtual void Fatal(const std::string& message, const boost::optional<Location>& location = boost::optional<Location>{});
+
+
+    template<typename... T>
+    void Tracef(const boost::optional<Location>& location, const std::string& pattern, T&&...args) {
+        Trace(Utils::Sprintf(pattern, std::forward<T>(args)...), location);
+    }
+
+    template<typename... T>
+    void Debugf(const boost::optional<Location>& location, const std::string& pattern, T&&...args) {
+        Debug(Utils::Sprintf(pattern, std::forward<T>(args)...), location);
+    }
+
+    template<typename... T>
+    void Infof(const boost::optional<Location>& location, const std::string& pattern, T&&...args) {
+        Info(Utils::Sprintf(pattern, std::forward<T>(args)...), location);
+    }
+
+    template<typename... T>
+    void Warningf(const boost::optional<Location>& location, const std::string& pattern, T&&...args) {
+        Warning(Utils::Sprintf(pattern, std::forward<T>(args)...), location);
+    }
+
+    template<typename... T>
+    void Errorf(const boost::optional<Location>& location, const std::string& pattern, T&&...args) {
+        Error(Utils::Sprintf(pattern, std::forward<T>(args)...), location);
+    }
+
+    template<typename... T>
+    void Fatalf(const boost::optional<Location>& location, const std::string& pattern, T&&...args) {
+        Fatal(Utils::Sprintf(pattern, std::forward<T>(args)...), location);
+    }
+
+protected:
+    Logger() = default;
+};
+
+// operator<< inserts severity into out.
+std::ostream& operator<<(std::ostream& out, Logger::Severity severity);
+
+// operator<< inserts location into out.
+std::ostream& operator<<(std::ostream& out, const Logger::Location &location);
+
+// Log returns the core::ubuntu::media-wide configured logger instance.
+// Save to call before/after main.
+Logger& Log();
+// SetLog installs the given logger as core::ubuntu::media-wide default logger.
+void SetLogger(const std::shared_ptr<Logger>& logger);
+
+#define TRACE(...) Log().Tracef(Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+#define DEBUG(...) Log().Debugf(Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+#define INFO(...) Log().Infof(Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+#define WARNING(...) Log().Warningf(Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+#define ERROR(...) Log().Errorf(Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+#define FATAL(...) Log().Fatalf(Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+} // namespace media
+} // namespace ubuntu
+} // namespace core
+
+#define MH_TRACE(...) core::ubuntu::media::Log().Tracef(\
+        core::ubuntu::media::Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+#define MH_DEBUG(...) core::ubuntu::media::Log().Debugf(\
+        core::ubuntu::media::Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+#define MH_INFO(...) core::ubuntu::media::Log().Infof(\
+        core::ubuntu::media::Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+#define MH_WARNING(...) core::ubuntu::media::Log().Warningf(core::ubuntu::media::Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+#define MH_ERROR(...) core::ubuntu::media::Log().Errorf(core::ubuntu::media::Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+#define MH_FATAL(...) core::ubuntu::media::Log().Fatalf(core::ubuntu::media::Logger::Location{__FILE__, __FUNCTION__, __LINE__}, __VA_ARGS__)
+
+#endif

=== added file 'src/core/media/non_copyable.h'
--- src/core/media/non_copyable.h	1970-01-01 00:00:00 +0000
+++ src/core/media/non_copyable.h	2016-04-06 19:07:29 +0000
@@ -0,0 +1,36 @@
+/*
+ * Copyright (C) 2015 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 warranties of
+ * MERCHANTABILITY, SATISFACTORY QUALITY, 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/>.
+ *
+ */
+
+#ifndef NON_COPYABLE_H_
+#define NON_COPYABLE_H_
+
+namespace core {
+namespace ubuntu {
+namespace media {
+// The alert reader might wonder why we don't use boost::noncopyable. The reason
+// is simple: We would like to have a convenient virtual d'tor available.
+struct NonCopyable {
+    NonCopyable() = default;
+    NonCopyable(const NonCopyable&) = delete;
+    virtual ~NonCopyable() = default;
+    NonCopyable& operator=(const NonCopyable&) = delete;
+};
+}
+}
+}
+
+#endif

=== modified file 'src/core/media/player_implementation.cpp'
--- src/core/media/player_implementation.cpp	2016-02-19 16:14:42 +0000
+++ src/core/media/player_implementation.cpp	2016-04-06 19:07:29 +0000
@@ -28,9 +28,10 @@
 
 #include "gstreamer/engine.h"
 
+#include "core/media/logger/logger.h"
+
 #include <memory>
 #include <exception>
-#include <iostream>
 #include <mutex>
 
 #define UNUSED __attribute__((unused))
@@ -75,22 +76,22 @@
         // Poor man's logging of release/acquire events.
         display_state_lock->acquired().connect([](media::power::DisplayState state)
         {
-            std::cout << "Acquired new display state: " << state << std::endl;
+            MH_INFO("Acquired new display state: %s", state);
         });
 
         display_state_lock->released().connect([](media::power::DisplayState state)
         {
-            std::cout << "Released display state: " << state << std::endl;
+            MH_INFO("Released display state: %s", state);
         });
 
         system_state_lock->acquired().connect([](media::power::SystemState state)
         {
-            std::cout << "Acquired new system state: "  << state << std::endl;
+            MH_INFO("Acquired new system state: %s", state);
         });
 
         system_state_lock->released().connect([](media::power::SystemState state)
         {
-            std::cout << "Released system state: "  << state << std::endl;
+            MH_INFO("Released system state: %s", state);
         });
     }
 
@@ -120,7 +121,7 @@
          */
         return [this](const Engine::State& state)
         {
-            std::cout << "Setting state for parent: " << parent << std::endl;
+            MH_DEBUG("Setting state for parent: %s", parent);
             switch(state)
             {
             case Engine::State::ready:
@@ -139,7 +140,7 @@
                 parent->meta_data_for_current_track().set(std::get<1>(engine->track_meta_data().get()));
                 // And update our playback status.
                 parent->playback_status().set(media::Player::playing);
-                std::cout << "Requesting power state" << std::endl;
+                MH_INFO("Requesting power state");
                 request_power_state();
                 break;
             }
@@ -174,45 +175,44 @@
     {
         return [this](const media::Player::PlaybackStatus& status)
         {
-            std::cout << "Emiting playback_status_changed signal: " << status << std::endl;
+            MH_INFO("Emiting playback_status_changed signal: %s", status);
             parent->emit_playback_status_changed(status);
         };
     }
 
     void request_power_state()
     {
-        std::cout << __PRETTY_FUNCTION__ << std::endl;
+        MH_TRACE("");
         try
         {
             if (parent->is_video_source())
             {
                 if (++display_wakelock_count == 1)
                 {
-                    std::cout << "Requesting new display wakelock." << std::endl;
+                    MH_INFO("Requesting new display wakelock.");
                     display_state_lock->request_acquire(media::power::DisplayState::on);
-                    std::cout << "Requested new display wakelock." << std::endl;
+                    MH_INFO("Requested new display wakelock.");
                 }
             }
             else
             {
                 if (++system_wakelock_count == 1)
                 {
-                    std::cout << "Requesting new system wakelock." << std::endl;
+                    MH_INFO("Requesting new system wakelock.");
                     system_state_lock->request_acquire(media::power::SystemState::active);
-                    std::cout << "Requested new system wakelock." << std::endl;
+                    MH_INFO("Requested new system wakelock.");
                 }
             }
         }
         catch(const std::exception& e)
         {
-            std::cerr << "Warning: failed to request power state: ";
-            std::cerr << e.what() << std::endl;
+            MH_WARNING("Failed to request power state: %s", e.what());
         }
     }
 
     void clear_wakelock(const wakelock_clear_t &wakelock)
     {
-        cout << __PRETTY_FUNCTION__ << endl;
+        MH_TRACE("");
         try
         {
             switch (wakelock)
@@ -223,7 +223,7 @@
                     // Only actually clear the system wakelock once the count reaches zero
                     if (--system_wakelock_count == 0)
                     {
-                        std::cout << "Clearing system wakelock." << std::endl;
+                        MH_INFO("Clearing system wakelock.");
                         system_state_lock->request_release(media::power::SystemState::active);
                     }
                     break;
@@ -231,19 +231,18 @@
                     // Only actually clear the display wakelock once the count reaches zero
                     if (--display_wakelock_count == 0)
                     {
-                        std::cout << "Clearing display wakelock." << std::endl;
+                        MH_INFO("Clearing display wakelock.");
                         display_state_lock->request_release(media::power::DisplayState::on);
                     }
                     break;
                 case wakelock_clear_t::WAKELOCK_CLEAR_INVALID:
                 default:
-                    cerr << "Can't clear invalid wakelock type" << endl;
+                    MH_WARNING("Can't clear invalid wakelock type");
             }
         }
         catch(const std::exception& e)
         {
-            std::cerr << "Warning: failed to clear power state: ";
-            std::cerr << e.what() << std::endl;
+            MH_WARNING("Failed to request clear power state: %s", e.what());
         }
     }
 
@@ -294,9 +293,9 @@
         {
             // Using a TrackList for playback, added tracks via add_track(), but open_uri hasn't
             // been called yet to load a media resource
-            std::cout << "Calling d->engine->open_resource_for_uri() for first track added only: "
-                      << uri << std::endl;
-            std::cout << "\twith a Track::Id: " << id << std::endl;
+            MH_INFO("Calling d->engine->open_resource_for_uri() for first track added only: %s",
+                      uri);
+            MH_INFO("\twith a Track::Id: %s", id);
             static const bool do_pipeline_reset = false;
             engine->open_resource_for_uri(uri, do_pipeline_reset);
         }
@@ -311,10 +310,10 @@
         auto n_tracks = track_list->tracks()->size();
         bool has_tracks = (n_tracks > 0) ? true : false;
 
-        std::cout << "Updating MPRIS TrackList properties"
-                  << "; Tracks: " << n_tracks
-                  << ", has_previous: " << has_previous
-                  << ", has_next: " << has_next << std::endl;
+        MH_INFO("Updating MPRIS TrackList properties:");
+        MH_INFO("\tTracks: %d", n_tracks);
+        MH_INFO("\thas_previous: %d", has_previous);
+        MH_INFO("\thas_next: %d", has_next);
 
         // Update properties
         parent->can_play().set(has_tracks);
@@ -418,7 +417,7 @@
     // When the client changes the loop status, make sure to update the TrackList
     Parent::loop_status().changed().connect([this](media::Player::LoopStatus loop_status)
     {
-        std::cout << "LoopStatus: " << loop_status << std::endl;
+        MH_INFO("LoopStatus: %s", loop_status);
         d->track_list->on_loop_status_changed(loop_status);
     });
 
@@ -465,7 +464,7 @@
         const Track::UriType uri = d->track_list->query_uri_for_track(d->track_list->next());
         if (prev_track_id != d->track_list->current() && !uri.empty())
         {
-            std::cout << "Advancing to next track on playbin: " << uri << std::endl;
+            MH_INFO("Advancing to next track on playbin: %s", uri);
             static const bool do_pipeline_reset = false;
             d->engine->open_resource_for_uri(uri, do_pipeline_reset);
         }
@@ -508,7 +507,7 @@
         if (d->engine->state() != gstreamer::Engine::State::ready
                 && d->engine->state() != gstreamer::Engine::State::stopped)
         {
-            std::cout << "End of tracklist reached, stopping playback" << std::endl;
+            MH_INFO("End of tracklist reached, stopping playback");
             d->engine->stop();
         }
     });
@@ -528,15 +527,15 @@
         const Track::UriType uri = d->track_list->query_uri_for_track(id);
         if (!uri.empty())
         {
-            std::cout << "Setting next track on playbin (on_go_to_track signal): " << uri << std::endl;
-            std::cout << "\twith a Track::Id: " << id << std::endl;
+            MH_INFO("Setting next track on playbin (on_go_to_track signal): %s", uri);
+            MH_INFO("\twith a Track::Id: %s", id);
             static const bool do_pipeline_reset = true;
             d->engine->open_resource_for_uri(uri, do_pipeline_reset);
         }
 
         if (auto_play)
         {
-            std::cout << "Restoring playing state in on_go_to_track()" << std::endl;
+            MH_DEBUG("Restoring playing state");
             d->engine->play();
         }
 
@@ -545,7 +544,7 @@
 
     d->track_list->on_track_added().connect([this](const media::Track::Id& id)
     {
-        std::cout << "** Track was added, handling in PlayerImplementation" << std::endl;
+        MH_TRACE("** Track was added, handling in PlayerImplementation");
         if (d->track_list->tracks()->size() == 1)
             d->open_first_track_from_tracklist(id);
 
@@ -554,7 +553,7 @@
 
     d->track_list->on_tracks_added().connect([this](const media::TrackList::ContainerURI& tracks)
     {
-        std::cout << "** Track was added, handling in PlayerImplementation" << std::endl;
+        MH_TRACE("** Track was added, handling in PlayerImplementation");
         // If the two sizes are the same, that means the TrackList was previously empty and we need
         // to open the first track in the TrackList so that is_audio_source() and is_video_source()
         // will function correctly.
@@ -689,7 +688,7 @@
 
     // If empty uri, give the same meaning as QMediaPlayer::setMedia("")
     if (uri.empty()) {
-        cout << __PRETTY_FUNCTION__ << ": resetting current media" << endl;
+        MH_DEBUG("Resetting current media");
         return true;
     }
 
@@ -722,19 +721,21 @@
 template<typename Parent>
 void media::PlayerImplementation<Parent>::play()
 {
+    MH_TRACE("");
     d->engine->play();
 }
 
 template<typename Parent>
 void media::PlayerImplementation<Parent>::pause()
 {
+    MH_TRACE("");
     d->engine->pause();
 }
 
 template<typename Parent>
 void media::PlayerImplementation<Parent>::stop()
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
+    MH_TRACE("");
     d->engine->stop();
 }
 

=== modified file 'src/core/media/player_skeleton.cpp'
--- src/core/media/player_skeleton.cpp	2016-02-19 16:14:42 +0000
+++ src/core/media/player_skeleton.cpp	2016-04-06 19:07:29 +0000
@@ -31,6 +31,8 @@
 #include "mpris/metadata.h"
 #include "mpris/player.h"
 #include "mpris/playlists.h"
+
+#include "core/media/logger/logger.h"
 #include "util/uri_check.h"
 
 #include <core/dbus/object.h>
@@ -189,7 +191,7 @@
             {
                 const std::string err_str = {"Warning: Failed to open uri " + uri +
                      " because it can't be found."};
-                std::cerr << err_str << std::endl;
+                MH_ERROR("%s", err_str);
                 reply = dbus::Message::make_error(
                             in,
                             mpris::Player::Error::UriNotFound::name,
@@ -207,7 +209,7 @@
                 {
                     const std::string err_str = {"Warning: Failed to authenticate necessary "
                         "apparmor permissions to open uri: " + std::get<1>(result)};
-                    std::cerr << err_str << std::endl;
+                    MH_ERROR("%s", err_str);
                     reply = dbus::Message::make_error(
                                 in,
                                 mpris::Player::Error::InsufficientAppArmorPermissions::name,
@@ -236,7 +238,7 @@
             {
                 const std::string err_str = {"Warning: Failed to open uri " + uri +
                      " because it can't be found."};
-                std::cerr << err_str << std::endl;
+                MH_ERROR("%s", err_str);
                 reply = dbus::Message::make_error(
                             in,
                             mpris::Player::Error::UriNotFound::name,
@@ -254,7 +256,7 @@
                 {
                     const std::string err_str = {"Warning: Failed to authenticate necessary "
                         "apparmor permissions to open uri: " + std::get<1>(result)};
-                    std::cerr << err_str << std::endl;
+                    MH_ERROR("%s", err_str);
                     reply = dbus::Message::make_error(
                                 in,
                                 mpris::Player::Error::InsufficientAppArmorPermissions::name,

=== modified file 'src/core/media/player_stub.cpp'
--- src/core/media/player_stub.cpp	2016-02-19 16:14:42 +0000
+++ src/core/media/player_stub.cpp	2016-04-06 19:07:29 +0000
@@ -30,10 +30,13 @@
 
 #include "mpris/player.h"
 
+#include "core/media/logger/logger.h"
+
 #include <core/dbus/property.h>
 #include <core/dbus/types/object_path.h>
 
 #include <limits>
+#include <sstream>
 
 #define UNUSED __attribute__((unused))
 
@@ -159,37 +162,38 @@
         {
             dbus.seeked_to->connect([this](std::uint64_t value)
             {
-                std::cout << "SeekedTo signal arrived via the bus." << std::endl;
+                MH_DEBUG("SeekedTo signal arrived via the bus.");
                 seeked_to(value);
             });
 
             dbus.about_to_finish->connect([this]()
             {
-                std::cout << "AboutToFinish signal arrived via the bus." << std::endl;
+                MH_DEBUG("AboutToFinish signal arrived via the bus.");
                 about_to_finish();
             });
 
             dbus.end_of_stream->connect([this]()
             {
-                std::cout << "EndOfStream signal arrived via the bus." << std::endl;
+                MH_DEBUG("EndOfStream signal arrived via the bus.");
                 end_of_stream();
             });
 
             dbus.playback_status_changed->connect([this](const media::Player::PlaybackStatus& status)
             {
-                std::cout << "PlaybackStatusChanged signal arrived via the bus (Status: " << status << ")" << std::endl;
+                MH_DEBUG("PlaybackStatusChanged signal arrived via the bus (status: %s)",
+                        status);
                 playback_status_changed(status);
             });
 
             dbus.video_dimension_changed->connect([this](const media::video::Dimensions dimensions)
             {
-                std::cout << "VideoDimensionChanged signal arrived via the bus." << std::endl;
+                MH_DEBUG("VideoDimensionChanged signal arrived via the bus.");
                 video_dimension_changed(dimensions);
             });
 
             dbus.error->connect([this](const media::Player::Error& e)
             {
-                std::cout << "Error signal arrived via the bus (Error: " << e << ")" << std::endl;
+                MH_DEBUG("Error signal arrived via the bus (error: %s)", e);
                 error(e);
             });
         }

=== modified file 'src/core/media/power/state_controller.cpp'
--- src/core/media/power/state_controller.cpp	2015-05-27 18:37:24 +0000
+++ src/core/media/power/state_controller.cpp	2016-04-06 19:07:29 +0000
@@ -16,13 +16,13 @@
  * Authored by: Thomas Voß <[e-mail]>
  */
 
+#include "core/media/logger/logger.h"
+
 #include <core/media/power/state_controller.h>
 
 #include <core/dbus/macros.h>
 #include <core/dbus/object.h>
 
-#include <iostream>
-
 namespace media = core::ubuntu::media;
 
 namespace com { namespace canonical {
@@ -98,7 +98,7 @@
     // From core::ubuntu::media::power::StateController::Lock<DisplayState>
     void request_acquire(media::power::DisplayState state) override
     {
-        std::cout << __PRETTY_FUNCTION__ << std::endl;
+        MH_TRACE("");
 
         if (state == media::power::DisplayState::off)
             return;
@@ -110,7 +110,7 @@
                     {
                         if (result.is_error())
                         {
-                            std::cerr << result.error().print() << std::endl;
+                            MH_ERROR("%s", result.error().print());
                             return;
                         }
 
@@ -149,7 +149,7 @@
                         {
                             if (result.is_error())
                             {
-                                std::cerr << result.error().print() << std::endl;
+                                MH_ERROR("%s", result.error().print());
                                 return;
                             }
 
@@ -207,7 +207,7 @@
     // the system to stay active.
     void request_acquire(media::power::SystemState state) override
     {
-        std::cout << __PRETTY_FUNCTION__ << std::endl;
+        MH_TRACE("");
 
         if (state == media::power::SystemState::suspend)
             return;
@@ -223,7 +223,7 @@
             }
             else
             {
-                std::cerr << "Failed to lock system_state_cookie_store_guard and check system lock state" << std::endl;
+                MH_WARNING("Failed to lock system_state_cookie_store_guard and check system lock state");
                 // Prevent system_state_cookie_store.count(state) and the actual call to requestSysState below from
                 // getting out of sync.
                 return;
@@ -236,7 +236,7 @@
         {
             if (result.is_error())
             {
-                std::cerr << result.error().print() << std::endl;
+                MH_ERROR("%s", result.error().print());
                 return;
             }
 
@@ -249,7 +249,7 @@
                     if (ul.owns_lock())
                         sp->system_state_cookie_store[state] = result.value();
                     else
-                        std::cerr << "Failed to lock system_state_cookie_store_guard and update system lock state" << std::endl;
+                        MH_WARNING("Failed to lock system_state_cookie_store_guard and update system lock state");
                 }
 
                 sp->signals.acquired(state);
@@ -275,7 +275,7 @@
             }
             else
             {
-                std::cerr << "Failed to lock system_state_cookie_store_guard and check system lock state" << std::endl;
+                MH_WARNING("Failed to lock system_state_cookie_store_guard and check system lock state");
                 // Prevent system_state_cookie_store.count(state) and the actual call to clearSysState below from
                 // getting out of sync.
                 return;
@@ -287,7 +287,7 @@
         object->invoke_method_asynchronously_with_callback<com::canonical::powerd::Interface::clearSysState, void>([this, wp, state](const core::dbus::Result<void>& result)
         {
             if (result.is_error())
-                std::cerr << result.error().print() << std::endl;
+                MH_ERROR("%s", result.error().print());
 
             if (auto sp = wp.lock())
             {
@@ -297,7 +297,7 @@
                     if (ul.owns_lock())
                         sp->system_state_cookie_store.erase(state);
                     else
-                        std::cerr << "Failed to lock system_state_cookie_store_guard and erase system lock state" << std::endl;
+                        MH_WARNING("Failed to lock system_state_cookie_store_guard and erase system lock state");
                 }
 
                 sp->signals.released(state);
@@ -369,7 +369,7 @@
 
 media::power::StateController::Ptr media::power::make_platform_default_state_controller(core::ubuntu::media::helper::ExternalServices& external_services)
 {
-    return std::make_shared<impl::StateController>(external_services);
+    return std::make_shared<::impl::StateController>(external_services);
 }
 
 // operator<< pretty prints the given display state to the given output stream.

=== modified file 'src/core/media/server/server.cpp'
--- src/core/media/server/server.cpp	2015-04-10 16:13:55 +0000
+++ src/core/media/server/server.cpp	2016-04-06 19:07:29 +0000
@@ -21,6 +21,7 @@
 #include <core/media/track_list.h>
 
 #include "core/media/hashed_keyed_player_store.h"
+#include "core/media/logger/logger.h"
 #include "core/media/service_implementation.h"
 
 #include <core/posix/signal.h>
@@ -36,6 +37,37 @@
 
 namespace
 {
+void logger_init()
+{
+    const char *level = ::getenv("MH_LOG_LEVEL");
+    // Default level is kInfo
+    media::Logger::Severity severity{media::Logger::Severity::kInfo};
+    if (level)
+    {
+        if (strcmp(level, "trace") == 0)
+            severity = media::Logger::Severity::kTrace;
+        else if (strcmp(level, "debug") == 0)
+            severity = media::Logger::Severity::kDebug;
+        else if (strcmp(level, "info") == 0)
+            severity = media::Logger::Severity::kInfo;
+        else if (strcmp(level, "warning") == 0)
+            severity = media::Logger::Severity::kWarning;
+        else if (strcmp(level, "error") == 0)
+            severity = media::Logger::Severity::kError;
+        else if (strcmp(level, "fatal") == 0)
+            severity = media::Logger::Severity::kFatal;
+        else
+            std::cerr << "Invalid log level \"" << level
+                << "\", setting to info. Valid options: [trace, debug, info, warning, error, fatal]. "
+                << std::endl;
+    }
+    else
+        std::cout << "Using default log level: info" << std::endl;
+
+    media::Log().Init(severity);
+    cout << "Log level: " << severity << std::endl;
+}
+
 // All platform-specific initialization routines go here.
 void platform_init()
 {
@@ -66,6 +98,8 @@
         trap->stop();
     });
 
+    logger_init();
+
     // Init platform-specific functionality.
     platform_init();
 

=== modified file 'src/core/media/service.cpp'
--- src/core/media/service.cpp	2014-04-09 14:05:55 +0000
+++ src/core/media/service.cpp	2016-04-06 19:07:29 +0000
@@ -18,13 +18,15 @@
 
 #include <core/media/service.h>
 
+#include "core/media/logger/logger.h"
+
 #include "service_stub.h"
 
 namespace media = core::ubuntu::media;
 
 const std::shared_ptr<media::Service> media::Service::Client::instance()
 {
-    std::cout << "Creating a new static Service instance" << std::endl;
+    MH_TRACE("");
     static std::shared_ptr<media::Service> instance{new media::ServiceStub()};
     return instance;
 }

=== modified file 'src/core/media/service_implementation.cpp'
--- src/core/media/service_implementation.cpp	2016-03-02 18:32:46 +0000
+++ src/core/media/service_implementation.cpp	2016-04-06 19:07:29 +0000
@@ -33,6 +33,9 @@
 #include "recorder_observer.h"
 #include "telephony/call_monitor.h"
 
+#include "util/timeout.h"
+#include "core/media/logger/logger.h"
+
 #include <boost/asio.hpp>
 
 #include <string>
@@ -45,8 +48,6 @@
 
 #include <pulse/pulseaudio.h>
 
-#include "util/timeout.h"
-
 namespace media = core::ubuntu::media;
 
 using namespace std;
@@ -126,16 +127,16 @@
         switch (state)
         {
         case audio::OutputState::Earpiece:
-            std::cout << "AudioOutputObserver reports that output is now Headphones/Headset." << std::endl;
+            MH_INFO("AudioOutputObserver reports that output is now Headphones/Headset.");
             break;
         case audio::OutputState::Speaker:
-            std::cout << "AudioOutputObserver reports that output is now Speaker." << std::endl;
+            MH_INFO("AudioOutputObserver reports that output is now Speaker.");
             // Whatever player session is currently playing, make sure it is NOT resumed after
             // a phonecall is hung up
             pause_all_multimedia_sessions(resume_play_after_phonecall);
             break;
         case audio::OutputState::External:
-            std::cout << "AudioOutputObserver reports that output is now External." << std::endl;
+            MH_INFO("AudioOutputObserver reports that output is now External.");
             break;
         }
         d->audio_output_state = state;
@@ -146,13 +147,13 @@
         const bool resume_play_after_phonecall = true;
         switch (state) {
         case media::telephony::CallMonitor::State::OffHook:
-            std::cout << "Got call started signal, pausing all multimedia sessions" << std::endl;
+            MH_INFO("Got call started signal, pausing all multimedia sessions");
             // Whatever player session is currently playing, make sure it gets resumed after
             // a phonecall is hung up
             pause_all_multimedia_sessions(resume_play_after_phonecall);
             break;
         case media::telephony::CallMonitor::State::OnHook:
-            std::cout << "Got call ended signal, resuming paused multimedia sessions" << std::endl;
+            MH_INFO("Got call ended signal, resuming paused multimedia sessions");
             resume_paused_multimedia_sessions(false);
             break;
         }
@@ -217,10 +218,10 @@
                     d->configuration.player_store->remove_player_for_key(key);
             }
             catch (const std::out_of_range &e) {
-                std::cerr << "Failed to look up Player instance for key " << key
-                << ", no valid Player instance for that key value. Removal of Player from Player store"
-                << " might not have completed. This most likely means that media-hub-server has"
-                << " crashed and restarted." << std::endl;
+                MH_WARNING("Failed to look up Player instance for key %d"
+                    ", no valid Player instance for that key value. Removal of Player from Player store"
+                    " might not have completed. This most likely means that media-hub-server has"
+                    " crashed and restarted.", key);
                 return;
             }
         });
@@ -264,11 +265,11 @@
 
 void media::ServiceImplementation::pause_other_sessions(media::Player::PlayerKey key)
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
+    MH_TRACE("");
 
     if (not d->configuration.player_store->has_player_for_key(key))
     {
-        cerr << "Could not find Player by key: " << key << endl;
+        MH_WARNING("Could not find Player by key: %d", key);
         return;
     }
 
@@ -291,7 +292,7 @@
             current_player->audio_stream_role() == media::Player::multimedia &&
             other_player->audio_stream_role() == media::Player::multimedia)
         {
-            cout << "Pausing Player with key: " << other_key << endl;
+            MH_INFO("Pausing Player with key: %d", other_key);
             other_player->pause();
         }
     });
@@ -306,8 +307,8 @@
         {
             auto paused_player_pair = std::make_pair(key, resume_play_after_phonecall);
             d->paused_sessions.push_back(paused_player_pair);
-            std::cout << "Pausing Player with key: " << key << ", resuming after phone call? "
-                << (resume_play_after_phonecall ? "yes" : "no") << std::endl;
+            MH_INFO("Pausing Player with key: %d, resuming after phone call? %s", key,
+                (resume_play_after_phonecall ? "yes" : "no"));
             player->pause();
         }
     });
@@ -324,17 +325,17 @@
                 player = d->configuration.player_store->player_for_key(key);
             }
             catch (const std::out_of_range &e) {
-                std::cerr << "Failed to look up Player instance for key " << key
-                    << ", no valid Player instance for that key value and cannot automatically resume"
-                    << " paused players. This most likely means that media-hub-server has crashed and"
-                    << " restarted." << std::endl;
+                MH_WARNING("Failed to look up Player instance for key %d"
+                    ", no valid Player instance for that key value and cannot automatically resume"
+                    " paused players. This most likely means that media-hub-server has crashed and"
+                    " restarted.", key);
                 return;
             }
             // Only resume video playback if explicitly desired
             if ((resume_video_sessions || player->is_audio_source()) && resume_play_after_phonecall)
                 player->play();
             else
-                std::cout << "Not auto-resuming video player session or other type of player session." << std::endl;
+                MH_INFO("Not auto-resuming video player session or other type of player session.");
         });
 
     d->paused_sessions.clear();
@@ -350,16 +351,16 @@
         player = d->configuration.player_store->player_for_key(d->resume_key);
     }
     catch (const std::out_of_range &e) {
-        std::cerr << "Failed to look up Player instance for key " << d->resume_key
-            << ", no valid Player instance for that key value and cannot automatically resume"
-            << " paused Player. This most likely means that media-hub-server has crashed and"
-            << " restarted." << std::endl;
+        MH_WARNING("Failed to look up Player instance for key %d"
+            ", no valid Player instance for that key value and cannot automatically resume"
+            " paused Player. This most likely means that media-hub-server has crashed and"
+            " restarted.", d->resume_key);
         return;
     }
 
     if (player->playback_status() == Player::paused)
     {
-        cout << "Resuming playback of Player with key: " << d->resume_key << endl;
+        MH_INFO("Resuming playback of Player with key: %d", d->resume_key);
         player->play();
         d->resume_key = std::numeric_limits<std::uint32_t>::max();
     }

=== modified file 'src/core/media/service_skeleton.cpp'
--- src/core/media/service_skeleton.cpp	2016-03-02 18:32:46 +0000
+++ src/core/media/service_skeleton.cpp	2016-04-06 19:07:29 +0000
@@ -29,6 +29,8 @@
 #include "the_session_bus.h"
 #include "xesam.h"
 
+#include "core/media/logger/logger.h"
+
 #include <core/dbus/message.h>
 #include <core/dbus/object.h>
 #include <core/dbus/types/object_path.h>
@@ -134,9 +136,8 @@
             impl->access_service()->add_object_for_path(op)
         };
 
-        cout << "Session created by request of: " << msg->sender()
-             << ", key: " << key << ", uuid: " << uuid
-             << ", path:" << op << std::endl;
+        MH_DEBUG("Session created by request of: %s, key: %d, uuid: %d, path: %s",
+                msg->sender(), key, uuid, op);
 
         try
         {
@@ -147,7 +148,7 @@
             request_context_resolver->resolve_context_for_dbus_name_async(msg->sender(),
                     [this, key, msg](const media::apparmor::ubuntu::Context& context)
             {
-                fprintf(stderr, "%s():%d -- app_name='%s', attached\n", __func__, __LINE__, context.str().c_str());
+                MH_DEBUG(" -- app_name='%s', attached", context.str());
                 player_owner_map.emplace(std::make_pair(key, std::make_tuple(context.str(), true, msg->sender())));
             });
 
@@ -231,7 +232,8 @@
                         [this, msg, key, op](const media::apparmor::ubuntu::Context& context)
                 {
                     auto info = player_owner_map.at(key);
-                    fprintf(stderr, "%s():%d -- reattach app_name='%s', info='%s', '%s'\n", __func__, __LINE__, context.str().c_str(), std::get<0>(info).c_str(), std::get<2>(info).c_str());
+                    MH_DEBUG(" -- reattach app_name='%s', info='%s', '%s'",
+                            context.str(), std::get<0>(info), std::get<2>(info));
                     if (std::get<0>(info) == context.str()) {
                         std::get<1>(info) = true; // Set to Attached
                         std::get<2>(info) = msg->sender(); // Register new owner
@@ -242,7 +244,7 @@
                         // We only care to allow the MPRIS controls to apply to multimedia player (i.e. audio, video)
                         if (player->audio_stream_role() == media::Player::AudioStreamRole::multimedia)
                         {
-                            std::cout << "Setting current_player" << std::endl;
+                            MH_TRACE("Setting current_player");
                             exported.set_current_player(player);
                         }
 
@@ -305,7 +307,8 @@
                         [this, msg, key](const media::apparmor::ubuntu::Context& context)
                 {
                     auto info = player_owner_map.at(key);
-                    fprintf(stderr, "%s():%d -- Destroying app_name='%s', info='%s', '%s'\n", __func__, __LINE__, context.str().c_str(), std::get<0>(info).c_str(), std::get<2>(info).c_str());
+                    MH_DEBUG(" -- Destroying app_name='%s', info='%s', '%s'",
+                            context.str(), std::get<0>(info), std::get<2>(info));
                     if (std::get<0>(info) == context.str()) {
                         player_owner_map.erase(key);
 
@@ -454,7 +457,7 @@
         core::dbus::Message::Ptr reply;
         if (not configuration.player_store->has_player_for_key(key))
         {
-            std::cerr <<  __PRETTY_FUNCTION__ << " player key not found - " << key << std::endl;
+            MH_WARNING("Player key not found: %d", key);
             reply = dbus::Message::make_error(
                             msg,
                             mpris::Service::Errors::PlayerKeyNotFound::name(),
@@ -467,10 +470,9 @@
                 reply = dbus::Message::make_method_return(msg);
             }
             catch (const std::out_of_range &e) {
-                std::cerr << "Failed to look up Player instance for key " << key
-                    << ", no valid Player instance for that key value and cannot set current player."
-                    << " This most likely means that media-hub-server has crashed and restarted."
-                    << std::endl;
+                MH_WARNING("Failed to look up Player instance for key %d\
+                    , no valid Player instance for that key value and cannot set current player.\
+                    This most likely means that media-hub-server has crashed and restarted.", key);
                 reply = dbus::Message::make_error(
                             msg,
                             mpris::Service::Errors::PlayerKeyNotFound::name(),
@@ -491,10 +493,9 @@
             reply = dbus::Message::make_method_return(msg);
         }
         catch (const std::out_of_range &e) {
-            std::cerr << "Failed to look up Player instance for key " << key
-                << ", no valid Player instance for that key value and cannot pause other Players."
-                << " This most likely means that media-hub-server has crashed and restarted."
-                << std::endl;
+                MH_WARNING("Failed to look up Player instance for key %d\
+                    , no valid Player instance for that key value and cannot set current player.\
+                    This most likely means that media-hub-server has crashed and restarted.", key);
             reply = dbus::Message::make_error(
                     msg,
                     mpris::Service::Errors::PlayerKeyNotFound::name(),
@@ -529,7 +530,7 @@
             // TODO(tvoss): These three elements really should be configurable.
             defaults.identity = "core::media::Hub";
             defaults.desktop_entry = "mediaplayer-app";
-            defaults.supported_mime_types = {"audio/mpeg3"};
+            defaults.supported_mime_types = {"audio/mpeg3", "video/mpeg4"};
 
             return defaults;
         }
@@ -668,7 +669,7 @@
 
         void set_current_player(const std::shared_ptr<media::Player>& cp)
         {
-            std::cout << "*** " << __PRETTY_FUNCTION__ << std::endl;
+            MH_TRACE("");
             // We will not keep the object alive.
             current_player = cp;
 
@@ -784,7 +785,7 @@
 
         void reset_current_player()
         {
-            std::cout << __PRETTY_FUNCTION__ << std::endl;
+            MH_TRACE("");
             // And announce that we can no longer be controlled.
             player.properties.can_control->set(false);
             current_player.reset();

=== modified file 'src/core/media/telephony/CMakeLists.txt'
--- src/core/media/telephony/CMakeLists.txt	2014-10-31 07:49:33 +0000
+++ src/core/media/telephony/CMakeLists.txt	2016-04-06 19:07:29 +0000
@@ -9,6 +9,7 @@
 
 include_directories(
     ${TP_QT5_INCLUDE_DIRS}
+    ${PROJECT_SOURCE_DIR}/src/
 )
 
 add_library(call-monitor STATIC

=== modified file 'src/core/media/telephony/call_monitor.cpp'
--- src/core/media/telephony/call_monitor.cpp	2015-01-26 11:01:02 +0000
+++ src/core/media/telephony/call_monitor.cpp	2016-04-06 19:07:29 +0000
@@ -19,6 +19,8 @@
 
 #include "call_monitor.h"
 
+#include "core/media/logger/logger.h"
+
 #include "qtbridge.h"
 #include <TelepathyQt/AccountManager>
 #include <TelepathyQt/SimpleCallObserver>
@@ -95,7 +97,7 @@
 
     void accountManagerReady(Tp::PendingOperation* operation) {
         if (operation->isError()) {
-            std::cerr << "TelepathyBridge: Operation failed (accountManagerReady)" << std::endl;
+            MH_ERROR("TelepathyBridge: Operation failed (accountManagerReady)");
             QTimer::singleShot(1000, this, SLOT(accountManagerSetup())); // again
             return;
         }
@@ -118,13 +120,13 @@
 
     void accountReady(Tp::PendingOperation* operation) {
         if (operation->isError()) {
-            std::cerr << "TelepathyAccount: Operation failed (accountReady)" << std::endl;
+            MH_ERROR("TelepathyAccount: Operation failed (accountReady)");
             return;
         }
 
         Tp::PendingReady* pendingReady = qobject_cast<Tp::PendingReady*>(operation);
         if (pendingReady == 0) {
-            std::cerr << "Rejecting account because could not understand ready status" << std::endl;
+            MH_ERROR("Rejecting account because could not understand ready status");
             return;
         }
 
@@ -176,16 +178,16 @@
                 {
                     qt::core::world::enter_with_task([this]()
                     {
-                        std::cout << "CallMonitor: Creating TelepathyBridge" << std::endl;
+                        MH_DEBUG("CallMonitor: Creating TelepathyBridge");
                         mBridge = new TelepathyBridge();
                         cv.notify_all();
                     });
                 });
           }));
         } catch(const std::system_error& error) {
-            std::cerr << "exception(std::system_error) in CallMonitor thread start" << error.what() << std::endl;
+            MH_ERROR("exception(std::system_error) in CallMonitor thread start %s", error.what());
         } catch(...) {
-            std::cerr << "exception(...) in CallMonitor thread start" << std::endl;
+            MH_ERROR("exception(...) in CallMonitor thread start");
         }
 
         // Wait until telepathy bridge is set, so we can hook up the change signals
@@ -234,7 +236,7 @@
 
 media::telephony::CallMonitor::Ptr media::telephony::make_platform_default_call_monitor()
 {
-    return std::make_shared<impl::CallMonitor>();
+    return std::make_shared<::impl::CallMonitor>();
 }
 
 #include "call_monitor.moc"

=== modified file 'src/core/media/telephony/qtbridge.cpp'
--- src/core/media/telephony/qtbridge.cpp	2014-10-31 07:49:33 +0000
+++ src/core/media/telephony/qtbridge.cpp	2016-04-06 19:07:29 +0000
@@ -26,8 +26,6 @@
 #include<QThread>
 #include<QDebug>
 
-#include <iostream>
-
 namespace
 {
 QCoreApplication* app = nullptr;

=== modified file 'src/core/media/track_list_implementation.cpp'
--- src/core/media/track_list_implementation.cpp	2016-02-22 18:58:52 +0000
+++ src/core/media/track_list_implementation.cpp	2016-04-06 19:07:29 +0000
@@ -18,6 +18,7 @@
 
 #include <algorithm>
 #include <random>
+#include <sstream>
 #include <stdio.h>
 #include <stdlib.h>
 #include <tuple>
@@ -29,6 +30,8 @@
 
 #include "engine.h"
 
+#include "core/media/logger/logger.h"
+
 namespace dbus = core::dbus;
 namespace media = core::ubuntu::media;
 
@@ -125,14 +128,14 @@
         const media::Track::Id& position,
         bool make_current)
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
+    MH_TRACE("");
 
     std::stringstream ss;
     ss << d->object->path().as_string() << "/" << d->track_counter++;
     Track::Id id{ss.str()};
 
-    std::cout << "Adding Track::Id: " << id << std::endl;
-    std::cout << "\tURI: " << uri << std::endl;
+    MH_DEBUG("Adding Track::Id: %s", id);
+    MH_DEBUG("\tURI: %s", uri);
 
     const auto current = get_current_track();
 
@@ -159,7 +162,7 @@
             set_current_track(current);
         }
 
-        std::cout << "Signaling that we just added track id: " << id << std::endl;
+        MH_DEBUG("Signaling that we just added track id: %s", id);
         // Signal to the client that a track was added to the TrackList
         on_track_added()(id);
 
@@ -172,7 +175,7 @@
 
 void media::TrackListImplementation::add_tracks_with_uri_at(const ContainerURI& uris, const Track::Id& position)
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
+    MH_TRACE("");
 
     const auto current = get_current_track();
 
@@ -184,8 +187,8 @@
         std::stringstream ss;
         ss << d->object->path().as_string() << "/" << d->track_counter++;
         Track::Id id{ss.str()};
-        std::cout << "Adding Track::Id: " << id << std::endl;
-        std::cout << "\tURI: " << uri << std::endl;
+        MH_DEBUG("Adding Track::Id: %s", id);
+        MH_DEBUG("\tURI: %s", uri);
 
         tmp.push_back(id);
 
@@ -217,7 +220,7 @@
 
     set_current_track(current);
 
-    std::cout << "Signaling that we just added " << tmp.size() << " tracks to the TrackList" << std::endl;
+    MH_DEBUG("Signaling that we just added %d tracks to the TrackList", tmp.size());
     on_tracks_added()(tmp);
 
     if (!current_id.empty())
@@ -227,30 +230,30 @@
 bool media::TrackListImplementation::move_track(const media::Track::Id& id,
                                                 const media::Track::Id& to)
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
+    MH_TRACE("");
 
-    std::cout << "-----------------------------------------------------" << std::endl;
+    MH_DEBUG("-----------------------------------------------------");
     if (id.empty() or to.empty())
     {
-        std::cerr << "Can't move track since 'id' or 'to' are empty" << std::endl;
+        MH_ERROR("Can't move track since 'id' or 'to' are empty");
         return false;
     }
 
     if (id == to)
     {
-        std::cerr << "Can't move track to it's same position" << std::endl;
+        MH_ERROR("Can't move track to it's same position");
         return false;
     }
 
     if (tracks().get().size() == 1)
     {
-        std::cerr << "Can't move track since TrackList contains only one track" << std::endl;
+        MH_ERROR("Can't move track since TrackList contains only one track");
         return false;
     }
 
     bool ret = false;
     const media::Track::Id current_id = *current_iterator();
-    std::cout << "current_track id: " << current_id << std::endl;
+    MH_DEBUG("current_track id: %s", current_id);
     // Get an iterator that points to the track that is the insertion point
     auto insert_point_it = std::find(tracks().get().begin(), tracks().get().end(), to);
     if (insert_point_it != tracks().get().end())
@@ -260,7 +263,6 @@
         {
             // Get an iterator that points to the track to move within the TrackList
             auto to_move_it = std::find(tracks().get().begin(), tracks().get().end(), id);
-            std::cout << "Erasing old track position: " << *to_move_it << std::endl;
             if (to_move_it != tracks().get().end())
             {
                 container.erase(to_move_it);
@@ -282,11 +284,11 @@
                 {
                     throw media::TrackList::Errors::FailedToMoveTrack();
                 }
-                std::cout << "*** Updated current_iterator, id: " << *current_iterator() << std::endl;
+                MH_DEBUG("*** Updated current_iterator, id: %s", *current_iterator());
             }
             else
             {
-                std::cerr << "Can't update current_iterator - failed to find track after move" << std::endl;
+                MH_ERROR("Can't update current_iterator - failed to find track after move");
                 throw media::TrackList::Errors::FailedToMoveTrack();
             }
 
@@ -295,10 +297,10 @@
 
         if (result)
         {
-            std::cout << "TrackList after move" << std::endl;
-            for(auto track : tracks().get())
+            MH_DEBUG("TrackList after move");
+            for(const auto track : tracks().get())
             {
-                std::cout << track << std::endl;
+                MH_DEBUG("%s", track);
             }
             const media::TrackList::TrackIdTuple ids = std::make_tuple(id, to);
             // Signal to the client that track 'id' was moved within the TrackList
@@ -312,7 +314,7 @@
                 ("Failed to find source track " + id);
     }
 
-    std::cout << "-----------------------------------------------------" << std::endl;
+    MH_DEBUG("-----------------------------------------------------");
 
     return ret;
 }
@@ -345,7 +347,7 @@
 
 void media::TrackListImplementation::go_to(const media::Track::Id& track)
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
+    MH_TRACE("");
     // Signal the Player instance to go to a specific track for playback
     on_go_to_track()(track);
     on_track_changed()(track);
@@ -373,7 +375,7 @@
 
 void media::TrackListImplementation::reset()
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
+    MH_TRACE("");
 
     // Make sure playback stops
     on_end_of_tracklist()();

=== modified file 'src/core/media/track_list_skeleton.cpp'
--- src/core/media/track_list_skeleton.cpp	2016-02-22 16:16:52 +0000
+++ src/core/media/track_list_skeleton.cpp	2016-04-06 19:07:29 +0000
@@ -29,7 +29,9 @@
 
 #include "mpris/player.h"
 #include "mpris/track_list.h"
+
 #include "util/uri_check.h"
+#include "core/media/logger/logger.h"
 
 #include <core/dbus/object.h>
 #include <core/dbus/property.h>
@@ -40,7 +42,6 @@
 
 #include <iostream>
 #include <limits>
-#include <sstream>
 #include <cstdint>
 
 namespace dbus = core::dbus;
@@ -104,7 +105,7 @@
 
     void handle_add_track_with_uri_at(const core::dbus::Message::Ptr& msg)
     {
-        std::cout << "*** " << __PRETTY_FUNCTION__ << std::endl;
+        MH_TRACE("");
         request_context_resolver->resolve_context_for_dbus_name_async
             (msg->sender(), [this, msg](const media::apparmor::ubuntu::Context& context)
         {
@@ -124,7 +125,7 @@
             {
                 const std::string err_str = {"Warning: Not adding track " + uri +
                      " to TrackList because it can't be found."};
-                std::cerr << err_str << std::endl;
+                MH_WARNING("%s", err_str.c_str());
                 reply = dbus::Message::make_error(
                             msg,
                             mpris::Player::Error::UriNotFound::name,
@@ -141,7 +142,7 @@
                 {
                     const std::string err_str = {"Warning: Not adding track " + uri +
                         " to TrackList because of inadequate client apparmor permissions."};
-                    std::cerr << err_str << std::endl;
+                    MH_WARNING("%s", err_str.c_str());
                     reply = dbus::Message::make_error(
                                 msg,
                                 mpris::TrackList::Error::InsufficientPermissionsToAddTrack::name,
@@ -155,7 +156,7 @@
 
     void handle_add_tracks_with_uri_at(const core::dbus::Message::Ptr& msg)
     {
-        std::cout << "*** " << __PRETTY_FUNCTION__ << std::endl;
+        MH_TRACE("");
         request_context_resolver->resolve_context_for_dbus_name_async
             (msg->sender(), [this, msg](const media::apparmor::ubuntu::Context& context)
         {
@@ -176,7 +177,7 @@
                 {
                     uri_err_str = {"Warning: Not adding track " + uri +
                          " to TrackList because it can't be found."};
-                    std::cerr << uri_err_str << std::endl;
+                    MH_WARNING("%s", uri_err_str.c_str());
                     reply = dbus::Message::make_error(
                                 msg,
                                 mpris::Player::Error::UriNotFound::name,
@@ -201,7 +202,7 @@
             }
             else
             {
-                std::cerr << err_str << std::endl;
+                MH_WARNING("%s", err_str.c_str());
                 reply = dbus::Message::make_error(
                             msg,
                             mpris::TrackList::Error::InsufficientPermissionsToAddTrack::name,
@@ -225,7 +226,7 @@
             {
                 const std::string err_str = {"Error: Not moving track " + id +
                     " to destination " + to};
-                std::cerr << err_str << std::endl;
+                MH_WARNING("%s", err_str.c_str());
                 reply = dbus::Message::make_error(
                         msg,
                         mpris::TrackList::Error::FailedToMoveTrack::name,
@@ -262,9 +263,9 @@
 
         auto id_it = find(impl->tracks().get().begin(), impl->tracks().get().end(), track);
         if (id_it == impl->tracks().get().end()) {
-            ostringstream err_str;
+            stringstream err_str;
             err_str << "Track " << track << " not found in track list";
-            cout << __PRETTY_FUNCTION__ << " WARNING " << err_str.str() << endl;
+            MH_WARNING("%s", err_str.str());
             auto reply = dbus::Message::make_error(
                             msg,
                             mpris::TrackList::Error::TrackNotFound::name,
@@ -278,7 +279,7 @@
 
         if (id_it == impl->current_iterator())
         {
-            cout << "Removing current track" << endl;
+            MH_DEBUG("Removing current track");
             deleting_current = true;
 
             if (current_track != empty_iterator)
@@ -537,10 +538,10 @@
 
 media::Track::Id media::TrackListSkeleton::next()
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
+    MH_TRACE("");
     if (tracks().get().empty()) {
         // TODO Change ServiceSkeleton to return with error from DBus call
-        std::cerr << "ERROR: no tracks, cannot go to next" << std::endl;
+        MH_ERROR("No tracks, cannot go to next");
         return media::Track::Id{};
     }
 
@@ -549,13 +550,13 @@
     // End of the track reached so loop around to the beginning of the track
     if (d->loop_status == media::Player::LoopStatus::track)
     {
-        std::cout << "Looping on the current track since LoopStatus is set to track" << std::endl;
+        MH_INFO("Looping on the current track since LoopStatus is set to track");
         go_to_track = true;
     }
     // End of the tracklist reached so loop around to the beginning of the tracklist
     else if (d->loop_status == media::Player::LoopStatus::playlist && not has_next())
     {
-        std::cout << "Looping on the tracklist since LoopStatus is set to playlist" << std::endl;
+        MH_INFO("Looping on the tracklist since LoopStatus is set to playlist");
 
         if (shuffle())
         {
@@ -574,7 +575,7 @@
         {
             auto it = get_current_shuffled();
             if (++it != shuffled_tracks().end()) {
-                cout << "Advancing to next track: " << *it << endl;
+                MH_INFO("Advancing to next track: %s", *it);
                 set_current_track(*it);
                 go_to_track = true;
             }
@@ -584,7 +585,7 @@
             const auto it = std::next(current_iterator());
             if (not is_last_track(it))
             {
-                cout << "Advancing to next track: " << *it << endl;
+                MH_INFO("Advancing to next track: %s", *it);
                 d->current_track = it;
                 go_to_track = true;
             }
@@ -594,7 +595,7 @@
 
     if (go_to_track)
     {
-        cout << "next track id is " << *(current_iterator()) << endl;
+        MH_DEBUG("next track id is %s", *(current_iterator()));
         on_track_changed()(*(current_iterator()));
         const media::Track::Id id = *(current_iterator());
         // Signal the PlayerImplementation to play the next track
@@ -603,7 +604,7 @@
     else
     {
         // At the end of the tracklist and not set to loop
-        cout << "End of tracklist reached" << endl;
+        MH_INFO("End of tracklist reached");
         on_end_of_tracklist()();
     }
 
@@ -612,10 +613,10 @@
 
 media::Track::Id media::TrackListSkeleton::previous()
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
+    MH_TRACE("");
     if (tracks().get().empty()) {
         // TODO Change ServiceSkeleton to return with error from DBus call
-        std::cerr << "ERROR: no tracks, cannot go to previous" << std::endl;
+        MH_ERROR("No tracks, cannot go to previous");
         return media::Track::Id{};
     }
 
@@ -627,19 +628,19 @@
     // repeat it from the beginning
     if (d->current_position > max_position)
     {
-        std::cout << "Repeating current track..." << std::endl;
+        MH_INFO("Repeating current track...");
         go_to_track = true;
     }
     // Loop on the current track forever
     else if (d->loop_status == media::Player::LoopStatus::track)
     {
-        std::cout << "Looping on the current track..." << std::endl;
+        MH_INFO("Looping on the current track...");
         go_to_track = true;
     }
     // Loop over the whole playlist and repeat
     else if (d->loop_status == media::Player::LoopStatus::playlist && not has_previous())
     {
-        std::cout << "Looping on the entire TrackList..." << std::endl;
+        MH_INFO("Looping on the entire TrackList...");
 
         if (shuffle())
         {
@@ -680,7 +681,7 @@
     else
     {
         // At the beginning of the tracklist and not set to loop
-        cout << "Beginning of tracklist reached" << endl;
+        MH_INFO("Beginning of tracklist reached");
         on_end_of_tracklist()();
     }
 
@@ -698,12 +699,12 @@
     // a segfault when calling current()
     if (tracks().get().size() && (d->current_track == d->empty_iterator))
     {
-        std::cout << "Wrapping d->current_track back to begin()" << std::endl;
+        MH_DEBUG("Wrapping d->current_track back to begin()");
         d->current_track = d->skeleton.properties.tracks->get().begin();
     }
     else if (tracks().get().empty())
     {
-        std::cerr << "TrackList is empty therefore there is no valid current track" << std::endl;
+        MH_ERROR("TrackList is empty therefore there is no valid current track");
     }
 
     return d->current_track;
@@ -711,11 +712,10 @@
 
 bool media::TrackListSkeleton::update_current_iterator(const TrackList::ConstIterator &it)
 {
-    std::cout << __PRETTY_FUNCTION__ << std::endl;
+    MH_TRACE("");
     if (it == tracks().get().end())
         return false;
 
-    std::cout << "Updating current_track iterator" << std::endl;
     d->current_track = it;
 
     return true;
@@ -780,8 +780,7 @@
 
 void media::TrackListSkeleton::on_shuffle_changed(bool shuffle)
 {
-    cout << __PRETTY_FUNCTION__ << endl;
-
+    MH_TRACE("");
     set_shuffle(shuffle);
 }
 
@@ -793,7 +792,7 @@
 const core::Signal<media::TrackList::ContainerTrackIdTuple>& media::TrackListSkeleton::on_track_list_replaced() const
 {
     // Print the TrackList instance
-    std::cout << *this << std::endl;
+    MH_DEBUG("%s", *this);
     return d->signals.on_track_list_replaced;
 }
 

=== modified file 'src/core/media/track_list_stub.cpp'
--- src/core/media/track_list_stub.cpp	2016-02-19 16:14:42 +0000
+++ src/core/media/track_list_stub.cpp	2016-04-06 19:07:29 +0000
@@ -28,6 +28,8 @@
 #include "mpris/player.h"
 #include "mpris/track_list.h"
 
+#include "core/media/logger/logger.h"
+
 #include <core/dbus/property.h>
 #include <core/dbus/types/object_path.h>
 #include <core/dbus/types/variant.h>
@@ -111,43 +113,43 @@
         {
             dbus.on_track_added->connect([this](const Track::Id& id)
             {
-                std::cout << "OnTrackAdded signal arrived via the bus." << std::endl;
+                MH_DEBUG("OnTrackAdded signal arrived via the bus.");
                 on_track_added(id);
             });
 
             dbus.on_tracks_added->connect([this](const media::TrackList::ContainerURI& tracks)
             {
-                std::cout << "OnTracksAdded signal arrived via the bus." << std::endl;
+                MH_DEBUG("OnTracksAdded signal arrived via the bus.");
                 on_tracks_added(tracks);
             });
 
             dbus.on_track_moved->connect([this](const media::TrackList::TrackIdTuple& ids)
             {
-                std::cout << "OnTrackMoved signal arrived via the bus." << std::endl;
+                MH_DEBUG("OnTrackMoved signal arrived via the bus.");
                 on_track_moved(ids);
             });
 
             dbus.on_track_removed->connect([this](const Track::Id& id)
             {
-                std::cout << "OnTrackRemoved signal arrived via the bus." << std::endl;
+                MH_DEBUG("OnTrackRemoved signal arrived via the bus.");
                 on_track_removed(id);
             });
 
             dbus.on_track_list_reset->connect([this](void)
             {
-                std::cout << "OnTrackListReset signal arrived via the bus." << std::endl;
+                MH_DEBUG("OnTrackListReset signal arrived via the bus.");
                 on_track_list_reset();
             });
 
             dbus.on_track_list_replaced->connect([this](const media::TrackList::ContainerTrackIdTuple& list)
             {
-                std::cout << "OnTrackListReplaced signal arrived via the bus." << std::endl;
+                MH_DEBUG("OnTrackListReplaced signal arrived via the bus.");
                 on_track_list_replaced(list);
             });
 
             dbus.on_track_changed->connect([this](const Track::Id& id)
             {
-                std::cout << "OnTrackChanged signal arrived via the bus." << std::endl;
+                MH_DEBUG("OnTrackChanged signal arrived via the bus.");
                 on_track_changed(id);
             });
         }

=== added file 'src/core/media/util/utils.cpp'
--- src/core/media/util/utils.cpp	1970-01-01 00:00:00 +0000
+++ src/core/media/util/utils.cpp	2016-04-06 19:07:29 +0000
@@ -0,0 +1,41 @@
+/*
+ * Copyright (C) 2016 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 warranties of
+ * MERCHANTABILITY, SATISFACTORY QUALITY, 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/>.
+ *
+ */
+
+#include <boost/filesystem.hpp>
+#include <boost/algorithm/string.hpp>
+
+#include <memory>
+#include <fstream>
+#include <sstream>
+
+#include <cstring>
+#include <cstdarg>
+
+#include "utils.h"
+
+namespace media = core::ubuntu::media;
+
+uint64_t media::Utils::GetNowNs() {
+   struct timespec ts;
+   memset(&ts, 0, sizeof(ts));
+   clock_gettime(CLOCK_MONOTONIC, &ts);
+   return ts.tv_sec * 1000000000LL + ts.tv_nsec;
+}
+
+uint64_t media::Utils::GetNowUs() {
+    return GetNowNs() / 1000;
+}

=== added file 'src/core/media/util/utils.h'
--- src/core/media/util/utils.h	1970-01-01 00:00:00 +0000
+++ src/core/media/util/utils.h	2016-04-06 19:07:29 +0000
@@ -0,0 +1,69 @@
+/*
+ * Copyright (C) 2016 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 warranties of
+ * MERCHANTABILITY, SATISFACTORY QUALITY, 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/>.
+ *
+ */
+
+#ifndef UTILS_H_
+#define UTILS_H_
+
+#include <boost/format.hpp>
+
+#include <string>
+#include <vector>
+
+#define MCS_STR_VALUE(str) #str
+
+namespace core {
+namespace ubuntu {
+namespace media {
+typedef int64_t TimestampNs;
+typedef int64_t TimestampUs;
+struct Utils
+{
+    // Merely used as a namespace.
+    Utils() = delete;
+
+    // Sprintf - much like what you would expect :)
+    template<typename... Types>
+    static std::string Sprintf(const std::string& fmt_str, Types&&... args);
+    // GetEnv - returns a variable value from the environment
+    static uint64_t GetNowNs();
+    // GetNowUs - get a timestamp in microseconds
+    static uint64_t GetNowUs();
+};
+
+namespace impl {
+// Base case, just return the passed in boost::format instance.
+inline boost::format& Sprintf(boost::format& f)
+{
+    return f;
+}
+// Sprintf recursively walks the parameter pack at compile time.
+template <typename Head, typename... Tail>
+inline boost::format& Sprintf(boost::format& f, Head const& head, Tail&&... tail) {
+    return Sprintf(f % head, std::forward<Tail>(tail)...);
+}
+} // namespace impl
+} // namespace media
+} // namespace ubuntu
+} // namespace core
+
+template <typename... Types>
+inline std::string core::ubuntu::media::Utils::Sprintf(const std::string& format, Types&&... args) {
+    boost::format f(format);
+    return core::ubuntu::media::impl::Sprintf(f, std::forward<Types>(args)...).str();
+}
+
+#endif

=== modified file 'src/core/media/video/platform_default_sink.cpp'
--- src/core/media/video/platform_default_sink.cpp	2015-01-29 12:12:43 +0000
+++ src/core/media/video/platform_default_sink.cpp	2016-04-06 19:07:29 +0000
@@ -36,7 +36,7 @@
     // and returns true or returns false and leaves 'matrix' unchanged in case
     // of issues.
     bool transformation_matrix(float*) const
-    {        
+    {
         return true;
     }