From 177b288da9fb0ce7083e1838667f6c20beccc3ac Mon Sep 17 00:00:00 2001
From: Nicolas Pope <nicolas.pope@utu.fi>
Date: Wed, 4 Mar 2020 18:39:37 +0200
Subject: [PATCH] Resolves #335 audio reset bug

---
 components/audio/include/ftl/audio/buffer.hpp    | 11 ++++++++---
 components/codecs/include/ftl/codecs/packet.hpp  |  3 +++
 components/net/cpp/src/peer.cpp                  | 10 ++++++----
 components/operators/src/poser.cpp               |  2 +-
 components/streams/src/netstream.cpp             | 16 ++++++++--------
 components/streams/src/receiver.cpp              |  1 +
 .../structures/include/ftl/data/frameset.hpp     |  3 +++
 7 files changed, 30 insertions(+), 16 deletions(-)

diff --git a/components/audio/include/ftl/audio/buffer.hpp b/components/audio/include/ftl/audio/buffer.hpp
index 7d438320d..87a80285e 100644
--- a/components/audio/include/ftl/audio/buffer.hpp
+++ b/components/audio/include/ftl/audio/buffer.hpp
@@ -4,6 +4,9 @@
 #include <vector>
 #include <cmath>
 
+#define LOGURU_REPLACE_GLOG 1
+#include <loguru.hpp>
+
 namespace ftl {
 namespace audio {
 
@@ -25,7 +28,7 @@ class Buffer {
 	void setDelay(float d) {
 		req_delay_ = d  * static_cast<float>(rate_);
 		// Big jumps should be instant
-		if (fabs(req_delay_ - cur_delay_) > 0.5f) {
+		if (fabs(req_delay_ - cur_delay_) > 0.5f*static_cast<float>(rate_)) {
 			//cur_delay_ = req_delay_;
 			reset();
 		}
@@ -98,7 +101,8 @@ class FixedBuffer : public ftl::audio::Buffer<T> {
 
 	void reset() override {
 		Buffer<T>::reset();
-		write_position_ = 0;
+		write_position_ = 0; //int(this->cur_delay_);
+		LOG(INFO) << "RESET AUDIO: " << write_position_;
 		read_position_ = 0;
 	}
 
@@ -133,6 +137,7 @@ void FixedBuffer<T,CHAN,FRAME,SIZE>::write(const std::vector<T> &in) {
 
 		const float d = 0.6f*clamp((this->req_delay_ - this->cur_delay_) / static_cast<float>(this->rate_), 0.5f);
 		i += 1.0f - d;  // FIXME: Is this correct? Seems to function but perhaps not ideal
+		//LOG(INFO) << "D " << this->req_delay_ << " - " << this->cur_delay_;
 
 		/*if (d > 0.0f) {	// Increase delay = oversample with increment < 1.0
 			//i += 1.0f * (1.0f - d);
@@ -141,7 +146,7 @@ void FixedBuffer<T,CHAN,FRAME,SIZE>::write(const std::vector<T> &in) {
 			//i += 1.0f / (1.0f + d);
 			i += 1.0f - d;
 		}*/
-		this->cur_delay_ += d;
+		this->cur_delay_ += d; //* static_cast<float>(this->rate_);
 
 		offset_+= CHAN;
 		if (offset_ == CHAN*FRAME) {
diff --git a/components/codecs/include/ftl/codecs/packet.hpp b/components/codecs/include/ftl/codecs/packet.hpp
index e232bb31f..cace36128 100644
--- a/components/codecs/include/ftl/codecs/packet.hpp
+++ b/components/codecs/include/ftl/codecs/packet.hpp
@@ -74,6 +74,9 @@ struct StreamPacket {
 
 	inline int frameNumber() const { return (version >= 4) ? frame_number : streamID; }
 	inline int frameSetID() const { return (version >= 4) ? streamID : 0; }
+	inline int64_t localTimestamp() const { return timestamp + originClockDelta; }
+
+	int64_t originClockDelta;  // Not message packet / saved
 
 	MSGPACK_DEFINE(timestamp, streamID, frame_number, channel);
 
diff --git a/components/net/cpp/src/peer.cpp b/components/net/cpp/src/peer.cpp
index b86b3553b..2a8bf879c 100644
--- a/components/net/cpp/src/peer.cpp
+++ b/components/net/cpp/src/peer.cpp
@@ -218,8 +218,9 @@ Peer::Peer(SOCKET s, Universe *u, Dispatcher *d) : sock_(s), can_reconnect_(fals
 		});
 
 		bind("__ping__", [this]() {
-			auto now = std::chrono::high_resolution_clock::now();
-			return std::chrono::time_point_cast<std::chrono::milliseconds>(now).time_since_epoch().count();
+			//auto now = std::chrono::high_resolution_clock::now();
+			//return std::chrono::time_point_cast<std::chrono::milliseconds>(now).time_since_epoch().count();
+			return ftl::timer::get_time();
 		});
 
 		send("__handshake__", ftl::net::kMagic, ftl::net::kVersion, ftl::net::this_peer); 
@@ -293,8 +294,9 @@ Peer::Peer(const char *pUri, Universe *u, Dispatcher *d) : can_reconnect_(true),
 		});
 
 		bind("__ping__", [this]() {
-			auto now = std::chrono::high_resolution_clock::now();
-			return std::chrono::time_point_cast<std::chrono::milliseconds>(now).time_since_epoch().count();
+			//auto now = std::chrono::high_resolution_clock::now();
+			//return std::chrono::time_point_cast<std::chrono::milliseconds>(now).time_since_epoch().count();
+			return ftl::timer::get_time();
 		});
 	}
 }
diff --git a/components/operators/src/poser.cpp b/components/operators/src/poser.cpp
index 588da7535..e2ac71b0c 100644
--- a/components/operators/src/poser.cpp
+++ b/components/operators/src/poser.cpp
@@ -46,7 +46,6 @@ bool Poser::apply(ftl::rgbd::FrameSet &in, ftl::rgbd::FrameSet &out, cudaStream_
 
                     idstr += std::to_string(in.id) + string("-") + std::to_string(i) + string("-") + std::to_string(t.id);
 
-                    LOG(INFO) << "POSE ID: " << idstr;
                     auto pose = t.pose.cast<double>();  // f.getPose() * 
 
                     auto p = pose_db__.find(idstr);
@@ -55,6 +54,7 @@ bool Poser::apply(ftl::rgbd::FrameSet &in, ftl::rgbd::FrameSet &out, cudaStream_
 						ps.pose = pose;
 						ps.locked = false;
 						pose_db__.emplace(std::make_pair(idstr,ps));
+                        LOG(INFO) << "POSE ID: " << idstr;
                     } else {
                         // TODO: Merge poses
                         if (!(*p).second.locked) (*p).second.pose = pose;
diff --git a/components/streams/src/netstream.cpp b/components/streams/src/netstream.cpp
index c12482878..030bc0dfe 100644
--- a/components/streams/src/netstream.cpp
+++ b/components/streams/src/netstream.cpp
@@ -153,6 +153,8 @@ bool Net::begin() {
 		StreamPacket spkt = spkt_raw;
 		// FIXME: see #335
 		//spkt.timestamp -= clock_adjust_;
+		spkt.originClockDelta = clock_adjust_;
+		//LOG(INFO) << "LATENCY: " << ftl::timer::get_time() - spkt.localTimestamp() << " : " << spkt.timestamp << " - " << clock_adjust_;
 		spkt.version = 4;
 
 		// Manage recuring requests
@@ -236,8 +238,6 @@ bool Net::begin() {
 	peer_ = *p;
 	tally_ = 30*kTallyScale;
 	for (size_t i=0; i<reqtally_.size(); ++i) reqtally_[i] = 0;
-
-	LOG(INFO) << "SEND REQUESTS FOR: " << uri_;
 	
 	// Initially send a colour request just to create the connection
 	_sendRequest(Channel::Colour, kAllFramesets, kAllFrames, 30, 0);
@@ -281,7 +281,7 @@ bool Net::_sendRequest(Channel c, uint8_t frameset, uint8_t frames, uint8_t coun
 	net_->send(peer_, uri_, (short)0, spkt, pkt);
 
 	// FIXME: Find a way to use this for correct stream latency info
-	if (false) {  // TODO: Not every time
+	if (false) { //if (c == Channel::Colour) {  // TODO: Not every time
 		auto start = std::chrono::high_resolution_clock::now();
 		//int64_t mastertime;
 
@@ -289,16 +289,16 @@ bool Net::_sendRequest(Channel c, uint8_t frameset, uint8_t frames, uint8_t coun
 			net_->asyncCall<int64_t>(peer_, "__ping__", [this, start](const int64_t &mastertime) {
 				auto elapsed = std::chrono::high_resolution_clock::now() - start;
 				int64_t latency = std::chrono::duration_cast<std::chrono::milliseconds>(elapsed).count();
-				clock_adjust_ = mastertime - (ftl::timer::get_time() + (latency/2));
+				clock_adjust_ = ftl::timer::get_time() - mastertime + (latency/2);
 
-				if (clock_adjust_ > 0) {
-					LOG(INFO) << "Clock adjustment: " << clock_adjust_;
-				}
+				//if (clock_adjust_ > 0) {
+				//	LOG(INFO) << "Clock adjustment: " << clock_adjust_;
+				//}
 			});
 		} catch (...) {
 			LOG(ERROR) << "Ping failed";
 			// Reset time peer and remove timer
-			time_peer_ = ftl::UUID(0);
+			//time_peer_ = ftl::UUID(0);
 			return false;
 		}
 	}
diff --git a/components/streams/src/receiver.cpp b/components/streams/src/receiver.cpp
index b98b65534..a43b95ceb 100644
--- a/components/streams/src/receiver.cpp
+++ b/components/streams/src/receiver.cpp
@@ -176,6 +176,7 @@ void Receiver::_processAudio(const StreamPacket &spkt, const Packet &pkt) {
 		ftl::audio::FrameSet fs;
 		fs.id = 0;
 		fs.timestamp = frame.timestamp;
+		fs.originClockDelta;
 		fs.count = 1;
 		//fs.stale = false;
 		fs.clear(ftl::data::FSFlag::STALE);
diff --git a/components/structures/include/ftl/data/frameset.hpp b/components/structures/include/ftl/data/frameset.hpp
index de5d6f68f..4de7035f5 100644
--- a/components/structures/include/ftl/data/frameset.hpp
+++ b/components/structures/include/ftl/data/frameset.hpp
@@ -32,6 +32,7 @@ class FrameSet {
 
 	int id=0;
 	int64_t timestamp;				// Millisecond timestamp of all frames
+	int64_t originClockDelta;
 	std::vector<FRAME> frames;
 	std::atomic<int> count;				// Number of valid frames
 	std::atomic<unsigned int> mask;		// Mask of all sources that contributed
@@ -40,6 +41,8 @@ class FrameSet {
 
 	Eigen::Matrix4d pose;  // Set to identity by default.
 
+	inline int64_t localTimestamp() const { return timestamp + originClockDelta; }
+
 	void set(FSFlag f) { flags_ |= (1 << static_cast<int>(f)); }
 	void clear(FSFlag f) { flags_ &= ~(1 << static_cast<int>(f)); }
 	bool test(FSFlag f) const { return flags_ & (1 << static_cast<int>(f)); }
-- 
GitLab