Add fancy communication logging

14 files changed, 175 insertions, 129 deletions

diff --git a/src/ColorContext.cpp b/src/ColorContext.cpp
new file mode 100644
index 00000000..e136126b
--- /dev/null
+++ b/src/ColorContext.cpp
@@ -0,0 +1,44 @@
+/*
+  This file is part of Ingen.
+  Copyright 2007-2016 David Robillard <http://drobilla.net/>
+
+  Ingen is free software: you can redistribute it and/or modify it under the
+  terms of the GNU Affero General Public License as published by the Free
+  Software Foundation, either version 3 of the License, or any later version.
+
+  Ingen is distributed in the hope that it will be useful, but WITHOUT ANY
+  WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR
+  A PARTICULAR PURPOSE.  See the GNU Affero General Public License for details.
+
+  You should have received a copy of the GNU Affero General Public License
+  along with Ingen.  If not, see <http://www.gnu.org/licenses/>.
+*/
+
+#include "ingen/ColorContext.hpp"
+#include "ingen_config.h"
+
+#ifdef HAVE_ISATTY
+#    include <unistd.h>
+#else
+inline int isatty(int fd) { return 0; }
+#endif
+
+namespace Ingen {
+
+ColorContext::ColorContext(FILE* stream, Color color)
+	: _stream(stream)
+{
+	if (isatty(fileno(_stream))) {
+		fprintf(_stream, "\033[0;%dm", color);
+	}
+}
+
+ColorContext::~ColorContext()
+{
+	if (isatty(fileno(_stream))) {
+		fprintf(_stream, "\033[0m");
+		fflush(_stream);
+	}
+}
+
+}  // namespace Ingen
diff --git a/src/Configuration.cpp b/src/Configuration.cpp
index 7df565be..37a5c59c 100644
--- a/src/Configuration.cpp
+++ b/src/Configuration.cpp
@@ -65,6 +65,7 @@ Configuration::Configuration(Forge& forge)
 	add("path",           "path",           'L', "Target path for loaded graph", SESSION, forge.String, Atom());
 	add("queueSize",      "queue-size",     'q', "Event queue size", GLOBAL, forge.Int, forge.make(4096));
 	add("flushLog",       "flush-log",      'f', "Flush logs after every entry", SESSION, forge.Bool, forge.make(false));
+	add("dump",           "dump",           'd', "Dump communication", SESSION, forge.Bool, forge.make(false));
 	add("trace",          "trace",          't', "Show LV2 plugin trace messages", SESSION, forge.Bool, forge.make(false));
 	add("humanNames",     "human-names",     0,  "Show human names in GUI", GUI, forge.Bool, forge.make(true));
 	add("portLabels",     "port-labels",     0,  "Show port labels in GUI", GUI, forge.Bool, forge.make(true));
diff --git a/src/Log.cpp b/src/Log.cpp
index 46b88aec..4280aaf8 100644
--- a/src/Log.cpp
+++ b/src/Log.cpp
@@ -20,36 +20,10 @@
 #include "ingen/Node.hpp"
 #include "ingen/URIs.hpp"
 #include "ingen/World.hpp"
-
-#ifdef HAVE_ISATTY
-#    include <unistd.h>
-#else
-inline int isatty(int fd) { return 0; }
-#endif
+#include "ingen/ColorContext.hpp"
 
 namespace Ingen {
 
-class ColorContext {
-public:
-	enum class Color { RED = 31, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE };
-
-	ColorContext(FILE* stream, Color color) : stream(stream) {
-		if (isatty(fileno(stream))) {
-			fprintf(stream, "\033[0;%dm", color);
-		}
-	}
-
-	~ColorContext() {
-		if (isatty(fileno(stream))) {
-			fprintf(stream, "\033[0m");
-			fflush(stream);
-		}
-	}
-
-
-	FILE* stream;
-};
-
 Log::Log(LV2_Log_Log* log, URIs& uris)
 	: _log(log)
 	, _uris(uris)
diff --git a/src/StreamWriter.cpp b/src/StreamWriter.cpp
new file mode 100644
index 00000000..a4e5b761
--- /dev/null
+++ b/src/StreamWriter.cpp
@@ -0,0 +1,39 @@
+/*
+  This file is part of Ingen.
+  Copyright 2012-2016 David Robillard <http://drobilla.net/>
+
+  Ingen is free software: you can redistribute it and/or modify it under the
+  terms of the GNU Affero General Public License as published by the Free
+  Software Foundation, either version 3 of the License, or any later version.
+
+  Ingen is distributed in the hope that it will be useful, but WITHOUT ANY
+  WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR
+  A PARTICULAR PURPOSE.  See the GNU Affero General Public License for details.
+
+  You should have received a copy of the GNU Affero General Public License
+  along with Ingen.  If not, see <http://www.gnu.org/licenses/>.
+*/
+
+#include "ingen/ColorContext.hpp"
+#include "ingen/StreamWriter.hpp"
+
+namespace Ingen {
+
+StreamWriter::StreamWriter(URIMap&             map,
+                           URIs&               uris,
+                           const Raul::URI&    uri,
+                           FILE*               stream,
+                           ColorContext::Color color)
+	: TurtleWriter(map, uris, uri)
+	, _stream(stream)
+	, _color(color)
+{}
+
+size_t
+StreamWriter::text_sink(const void* buf, size_t len)
+{
+	ColorContext ctx(_stream, _color);
+	return fwrite(buf, 1, len, _stream);
+}
+
+} // namespace Ingen
diff --git a/src/client/ClientStore.cpp b/src/client/ClientStore.cpp
index 3a90596d..e99f9c73 100644
--- a/src/client/ClientStore.cpp
+++ b/src/client/ClientStore.cpp
@@ -24,8 +24,6 @@
 #include "ingen/client/PortModel.hpp"
 #include "ingen/client/SigClientInterface.hpp"
 
-// #define INGEN_CLIENT_STORE_DUMP 1
-
 using namespace std;
 
 namespace Ingen {
@@ -211,10 +209,6 @@ ClientStore::add_plugin(SPtr<PluginModel> pm)
 void
 ClientStore::del(const Raul::URI& uri)
 {
-#ifdef INGEN_CLIENT_STORE_DUMP
-	std::cerr << "Client del " << uri << std::endl;
-#endif
-
 	if (Node::uri_is_path(uri)) {
 		remove_object(Node::uri_to_path(uri));
 	} else {
@@ -236,11 +230,6 @@ ClientStore::copy(const Raul::URI& old_uri,
 void
 ClientStore::move(const Raul::Path& old_path, const Raul::Path& new_path)
 {
-#ifdef INGEN_CLIENT_STORE_DUMP
-	std::cerr << "Client move " << old_path
-	          << " => " << new_path << endl;
-#endif
-
 	const iterator top = find(old_path);
 	if (top != end()) {
 		rename(top, new_path);
@@ -253,13 +242,6 @@ ClientStore::put(const Raul::URI&            uri,
                  Resource::Graph             ctx)
 {
 	typedef Resource::Properties::const_iterator Iterator;
-#ifdef INGEN_CLIENT_STORE_DUMP
-	std::cerr << "Client put " << uri << " {" << endl;
-	for (auto p : properties)
-		std::cerr << '\t' << p.first << " " << _uris.forge.str(p.second)
-		          << "^^" << _uris.forge.str(_uris.forge.make_urid(p.second.type()), true) << endl;
-	std::cerr << "}" << endl;
-#endif
 
 	bool is_graph, is_block, is_port, is_output;
 	Resource::type(uris(), properties,
@@ -365,19 +347,6 @@ ClientStore::delta(const Raul::URI&            uri,
                    const Resource::Properties& remove,
                    const Resource::Properties& add)
 {
-#ifdef INGEN_CLIENT_STORE_DUMP
-	std::cerr << "Client delta " << uri << " {" << endl;
-	for (auto r : remove)
-		std::cerr << "    - " << r.first
-		          << " " << _uris.forge.str(r.second)
-		          << "^^" << _uris.forge.str(_uris.forge.make_urid(r.second.type()), true) << endl;
-	for (auto a : add)
-		std::cerr << "    + " << a.first
-		          << " " << _uris.forge.str(a.second)
-		          << "^^" << _uris.forge.str(_uris.forge.make_urid(a.second.type()), true) << endl;
-	std::cerr << "}" << endl;
-#endif
-
 	if (uri == Raul::URI("ingen:/clients/this")) {
 		// Client property, which we don't store (yet?)
 		return;
@@ -406,11 +375,6 @@ ClientStore::set_property(const Raul::URI& subject_uri,
                           const Raul::URI& predicate,
                           const Atom&      value)
 {
-#ifdef INGEN_CLIENT_STORE_DUMP
-	std::cerr << "Client set " << subject_uri << " : "
-	          << predicate << " = " << _uris.forge.str(value) << std::endl;
-#endif
-
 	if (subject_uri == Raul::URI("ingen:/engine")) {
 		_log.info(fmt("Engine property <%1%> = %2%\n")
 		          % predicate.c_str() % _uris.forge.str(value));
@@ -488,10 +452,6 @@ void
 ClientStore::connect(const Raul::Path& src_path,
                      const Raul::Path& dst_path)
 {
-#ifdef INGEN_CLIENT_STORE_DUMP
-	std::cerr << "Client connect " << src_path << " => " << dst_path << std::endl;
-#endif
-
 	attempt_connection(src_path, dst_path);
 }
 
@@ -499,10 +459,6 @@ void
 ClientStore::disconnect(const Raul::Path& src_path,
                         const Raul::Path& dst_path)
 {
-#ifdef INGEN_CLIENT_STORE_DUMP
-	std::cerr << "Client disconnect " << src_path << " => " << dst_path << std::endl;
-#endif
-
 	SPtr<PortModel> tail = dynamic_ptr_cast<PortModel>(_object(src_path));
 	SPtr<PortModel> head = dynamic_ptr_cast<PortModel>(_object(dst_path));
 
@@ -521,10 +477,6 @@ void
 ClientStore::disconnect_all(const Raul::Path& parent_graph,
                             const Raul::Path& path)
 {
-#ifdef INGEN_CLIENT_STORE_DUMP
-	std::cerr << "Client disconnect all " << path << " in " << parent_graph << std::endl;
-#endif
-
 	SPtr<GraphModel>  graph  = dynamic_ptr_cast<GraphModel>(_object(parent_graph));
 	SPtr<ObjectModel> object = _object(path);
 
diff --git a/src/gui/App.cpp b/src/gui/App.cpp
index fad2f195..c023fe8c 100644
--- a/src/gui/App.cpp
+++ b/src/gui/App.cpp
@@ -27,6 +27,7 @@
 #include "ingen/EngineBase.hpp"
 #include "ingen/Interface.hpp"
 #include "ingen/Log.hpp"
+#include "ingen/StreamWriter.hpp"
 #include "ingen/World.hpp"
 #include "ingen/client/ClientStore.hpp"
 #include "ingen/client/GraphModel.hpp"
@@ -163,6 +164,29 @@ App::attach(SPtr<SigClientInterface> client)
 		_world->set_store(_store);
 	}
 
+	if (_world->conf().option("dump").get<int32_t>()) {
+		_dumper = SPtr<StreamWriter>(new StreamWriter(_world->uri_map(),
+		                                              _world->uris(),
+		                                              Raul::URI("ingen:/client"),
+		                                              stderr,
+		                                              ColorContext::Color::CYAN));
+
+#define DUMP_CONNECT(signal, method) \
+		client->signal_##signal().connect( \
+			sigc::mem_fun(*_dumper.get(), &StreamWriter::method));
+
+		DUMP_CONNECT(object_deleted, del);
+		DUMP_CONNECT(object_moved, move);
+		DUMP_CONNECT(put, put);
+		DUMP_CONNECT(delta, delta);
+		DUMP_CONNECT(connection, connect);
+		DUMP_CONNECT(disconnection, disconnect);
+		DUMP_CONNECT(disconnect_all, disconnect_all);
+		DUMP_CONNECT(property_change, set_property);
+
+#undef DUMP_CONNECT
+	}
+
 	_graph_tree_window->init(*this, *_store);
 
 	_client->signal_response().connect(
diff --git a/src/gui/App.hpp b/src/gui/App.hpp
index c609fa36..6071c750 100644
--- a/src/gui/App.hpp
+++ b/src/gui/App.hpp
@@ -39,6 +39,7 @@ class Interface;
 class Log;
 class Port;
 class Serialiser;
+class StreamWriter;
 class World;
 
 namespace Client {
@@ -145,6 +146,7 @@ protected:
 	SPtr<Client::SigClientInterface> _client;
 	SPtr<Client::ClientStore>        _store;
 	SPtr<ThreadedLoader>             _loader;
+	SPtr<StreamWriter>               _dumper;
 
 	Style* _style;
 
diff --git a/src/server/Engine.cpp b/src/server/Engine.cpp
index 8fa4d2f5..7baea132 100644
--- a/src/server/Engine.cpp
+++ b/src/server/Engine.cpp
@@ -28,6 +28,8 @@
 #include "ingen/Configuration.hpp"
 #include "ingen/Log.hpp"
 #include "ingen/Store.hpp"
+#include "ingen/StreamWriter.hpp"
+#include "ingen/Tee.hpp"
 #include "ingen/URIs.hpp"
 #include "ingen/World.hpp"
 #include "ingen/types.hpp"
@@ -69,7 +71,8 @@ Engine::Engine(Ingen::World* world)
 	, _buffer_factory(new BufferFactory(*this, world->uris()))
 	, _control_bindings(NULL)
 	, _event_writer(new EventWriter(*this))
-	, _atom_interface(new AtomReader(world->uri_map(), world->uris(), world->log(), *_event_writer))
+	, _interface(_event_writer)
+	, _atom_interface(nullptr)
 	, _maid(new Raul::Maid())
 	, _options(new LV2Options(world->uris()))
 	, _undo_stack(new UndoStack(_world->uris(), _world->uri_map()))
@@ -106,6 +109,21 @@ Engine::Engine(Ingen::World* world)
 	_world->lv2_features().add_feature(
 		SPtr<LV2Features::Feature>(
 			new LV2Features::EmptyFeature(LV2_STATE__loadDefaultState)));
+
+	if (world->conf().option("dump").get<int32_t>()) {
+		SPtr<Tee>          tee(new Tee());
+		SPtr<StreamWriter> dumper(new StreamWriter(world->uri_map(),
+		                                           world->uris(),
+		                                           Raul::URI("ingen:/engine"),
+		                                           stderr,
+		                                           ColorContext::Color::MAGENTA));
+		tee->add_sink(_event_writer);
+		tee->add_sink(dumper);
+		_interface = tee;
+	}
+
+	_atom_interface = new AtomReader(
+		world->uri_map(), world->uris(), world->log(), *_interface.get());
 }
 
 Engine::~Engine()
@@ -144,7 +162,6 @@ Engine::~Engine()
 	delete _block_factory;
 	delete _control_bindings;
 	delete _broadcaster;
-	delete _event_writer;
 	delete _worker;
 	delete _maid;
 
diff --git a/src/server/Engine.hpp b/src/server/Engine.hpp
index 82cbcdfb..32f284e0 100644
--- a/src/server/Engine.hpp
+++ b/src/server/Engine.hpp
@@ -28,6 +28,7 @@
 
 #include "Event.hpp"
 #include "RunContext.hpp"
+#include "EventWriter.hpp"
 
 namespace Raul { class Maid; }
 
@@ -44,7 +45,6 @@ class Broadcaster;
 class BufferFactory;
 class ControlBindings;
 class Driver;
-class EventWriter;
 class GraphImpl;
 class LV2Options;
 class PostProcessor;
@@ -98,7 +98,8 @@ public:
 
 	Ingen::World* world() const { return _world; }
 
-	EventWriter*     interface()        const { return _event_writer; }
+	Interface*       interface()        const { return _interface.get(); }
+	EventWriter*     event_writer()     const { return _event_writer.get(); }
 	AtomReader*      atom_interface()   const { return _atom_interface; }
 	BlockFactory*    block_factory()    const { return _block_factory; }
 	Broadcaster*     broadcaster()      const { return _broadcaster; }
@@ -123,23 +124,24 @@ public:
 private:
 	Ingen::World* _world;
 
-	BlockFactory*    _block_factory;
-	Broadcaster*     _broadcaster;
-	BufferFactory*   _buffer_factory;
-	ControlBindings* _control_bindings;
-	SPtr<Driver>     _driver;
-	EventWriter*     _event_writer;
-	AtomReader*      _atom_interface;
-	Raul::Maid*      _maid;
-	SPtr<LV2Options> _options;
-	UndoStack*       _undo_stack;
-	UndoStack*       _redo_stack;
-	PreProcessor*    _pre_processor;
-	PostProcessor*   _post_processor;
-	GraphImpl*       _root_graph;
-	Worker*          _worker;
-	Worker*          _sync_worker;
-	SocketListener*  _listener;
+	BlockFactory*     _block_factory;
+	Broadcaster*      _broadcaster;
+	BufferFactory*    _buffer_factory;
+	ControlBindings*  _control_bindings;
+	SPtr<Driver>      _driver;
+	SPtr<EventWriter> _event_writer;
+	SPtr<Interface>   _interface;
+	AtomReader*       _atom_interface;
+	Raul::Maid*       _maid;
+	SPtr<LV2Options>  _options;
+	UndoStack*        _undo_stack;
+	UndoStack*        _redo_stack;
+	PreProcessor*     _pre_processor;
+	PostProcessor*    _post_processor;
+	GraphImpl*        _root_graph;
+	Worker*           _worker;
+	Worker*           _sync_worker;
+	SocketListener*   _listener;
 
 	RunContext _run_context;
 
diff --git a/src/server/SocketServer.hpp b/src/server/SocketServer.hpp
index fc9fdeae..6420020e 100644
--- a/src/server/SocketServer.hpp
+++ b/src/server/SocketServer.hpp
@@ -17,10 +17,11 @@
 #ifndef INGEN_SERVER_SOCKET_SERVER_HPP
 #define INGEN_SERVER_SOCKET_SERVER_HPP
 
-#include "raul/Socket.hpp"
-
 #include "ingen/SocketReader.hpp"
 #include "ingen/SocketWriter.hpp"
+#include "ingen/StreamWriter.hpp"
+#include "ingen/Tee.hpp"
+#include "raul/Socket.hpp"
 
 #include "EventWriter.hpp"
 
@@ -28,21 +29,29 @@ namespace Ingen {
 namespace Server {
 
 /** The server side of an Ingen socket connection. */
-class SocketServer : public EventWriter, public SocketReader
+class SocketServer
 {
 public:
 	SocketServer(World&             world,
 	             Server::Engine&    engine,
 	             SPtr<Raul::Socket> sock)
-		: EventWriter(engine)
-		, SocketReader(world, *this, sock)
-		, _engine(engine)
+		: _engine(engine)
+		, _sink(world.conf().option("dump").get<int32_t>()
+		        ? SPtr<Interface>(
+			        new Tee({SPtr<Interface>(new EventWriter(engine)),
+					         SPtr<Interface>(new StreamWriter(world.uri_map(),
+					                                          world.uris(),
+					                                          Raul::URI("ingen:/engine"),
+					                                          stderr,
+					                                          ColorContext::Color::CYAN))}))
+		        : SPtr<Interface>(new EventWriter(engine)))
+		, _reader(new SocketReader(world, *_sink.get(), sock))
 		, _writer(new SocketWriter(world.uri_map(),
 		                           world.uris(),
 		                           sock->uri(),
 		                           sock))
 	{
-		set_respondee(_writer);
+		_sink->set_respondee(_writer);
 		engine.register_client(_writer);
 	}
 
@@ -60,6 +69,8 @@ protected:
 
 private:
 	Server::Engine&    _engine;
+	SPtr<Interface>    _sink;
+	SPtr<SocketReader> _reader;
 	SPtr<SocketWriter> _writer;
 };
 
diff --git a/src/server/events/Delta.cpp b/src/server/events/Delta.cpp
index d54ec53f..49ea27ff 100644
--- a/src/server/events/Delta.cpp
+++ b/src/server/events/Delta.cpp
@@ -38,9 +38,6 @@
 #include "SetPortValue.hpp"
 #include "events/Get.hpp"
 
-// #define DUMP 1
-// #include "ingen/URIMap.hpp"
-
 namespace Ingen {
 namespace Server {
 namespace Events {
@@ -74,25 +71,6 @@ Delta::Delta(Engine&           engine,
 			p.second.set_context(context);
 		}
 	}
-
-#ifdef DUMP
-	std::cerr << "Delta " << subject << " : " << (int)context << " {" << std::endl;
-	typedef Resource::Properties::const_iterator iterator;
-	for (iterator i = properties.begin(); i != properties.end(); ++i) {
-		std::cerr << "    + " << i->first
-		          << " " << engine.world()->forge().str(i->second)
-		          << "^^<" << engine.world()->uri_map().unmap_uri(i->second.type()) << ">"
-		          << std::endl;
-	}
-	typedef Resource::Properties::const_iterator iterator;
-	for (iterator i = remove.begin(); i != remove.end(); ++i) {
-		std::cerr << "    - " << i->first
-		          << " " << engine.world()->forge().str(i->second)
-		          << "^^<" << engine.world()->uri_map().unmap_uri(i->second.type()) << ">"
-		          << std::endl;
-	}
-	std::cerr << "}" << std::endl;
-#endif
 }
 
 Delta::~Delta()
diff --git a/src/server/events/Undo.cpp b/src/server/events/Undo.cpp
index 06289aa1..15c18ca2 100644
--- a/src/server/events/Undo.cpp
+++ b/src/server/events/Undo.cpp
@@ -44,7 +44,7 @@ Undo::pre_process()
 	}
 
 	_entry = stack->pop();
-	_engine.interface()->set_event_mode(mode);
+	_engine.event_writer()->set_event_mode(mode);
 	if (_entry.events.size() > 1) {
 		_engine.interface()->bundle_begin();
 	}
@@ -56,7 +56,7 @@ Undo::pre_process()
 	if (_entry.events.size() > 1) {
 		_engine.interface()->bundle_end();
 	}
-	_engine.interface()->set_event_mode(mode);
+	_engine.event_writer()->set_event_mode(mode);
 
 	return Event::pre_process_done(Status::SUCCESS);
 }
diff --git a/src/server/ingen_lv2.cpp b/src/server/ingen_lv2.cpp
index 53d302b1..0c32731c 100644
--- a/src/server/ingen_lv2.cpp
+++ b/src/server/ingen_lv2.cpp
@@ -544,8 +544,8 @@ ingen_instantiate(const LV2_Descriptor*    descriptor,
 	plugin->engine = engine;
 	plugin->world->set_engine(engine);
 
-	SPtr<EventWriter> interface = SPtr<EventWriter>(engine->interface(),
-	                                                NullDeleter<EventWriter>);
+	SPtr<Interface> interface = SPtr<Interface>(engine->interface(),
+	                                            NullDeleter<Interface>);
 
 	plugin->world->set_interface(interface);
 
diff --git a/src/wscript b/src/wscript
index b43c8928..beeed33b 100644
--- a/src/wscript
+++ b/src/wscript
@@ -6,6 +6,7 @@ def build(bld):
         'AtomReader.cpp',
         'AtomWriter.cpp',
         'ClashAvoider.cpp',
+        'ColorContext.cpp',
         'Configuration.cpp',
         'Forge.cpp',
         'LV2Features.cpp',
@@ -14,6 +15,7 @@ def build(bld):
         'Resource.cpp',
         'Serialiser.cpp',
         'Store.cpp',
+        'StreamWriter.cpp',
         'TurtleWriter.cpp',
         'URIMap.cpp',
         'URIs.cpp',