Additional activity reporting.

libdevcore/CommonIO.h

@@ -76,7 +76,7 @@ template <class T, class U> inline std::ostream& operator<<(std::ostream& _out,
 template <class T, class U> inline std::ostream& operator<<(std::ostream& _out, std::multimap<T, U> const& _e);
 template <class _S, class _T> _S& operator<<(_S& _out, std::shared_ptr<_T> const& _p);
 
-template <class T> inline std::string toString(std::chrono::time_point<T> const& _e, std::string _format = "")
+template <class T> inline std::string toString(std::chrono::time_point<T> const& _e, std::string _format = "%F %T")
 {
 	unsigned long milliSecondsSinceEpoch = std::chrono::duration_cast<std::chrono::milliseconds>(_e.time_since_epoch()).count();
 	auto const durationSinceEpoch = std::chrono::milliseconds(milliSecondsSinceEpoch);

libethereum/BlockQueue.cpp

@@ -74,7 +74,11 @@ ImportResult BlockQueue::import(bytesConstRef _block, BlockChain const& _bc, boo
 	if (bi.timestamp > (u256)time(0)/* && !_isOurs*/)
 	{
 		m_future.insert(make_pair((unsigned)bi.timestamp, _block.toBytes()));
-		cblockq << "OK - queued for future.";
+		char buf[24];
+		time_t bit = (unsigned)bi.timestamp;
+		if (strftime(buf, 24, "%X", localtime(&bit)) == 0)
+			buf[0] = '\0'; // empty if case strftime fails
+		cblockq << "OK - queued for future [" << bi.timestamp << "vs" << time(0) << "] - will wait until" << buf;
 		return ImportResult::FutureTime;
 	}
 	else
@@ -132,12 +136,30 @@ bool BlockQueue::doneDrain(h256s const& _bad)
 
 void BlockQueue::tick(BlockChain const& _bc)
 {
+	if (m_future.empty())
+		return;
+
+	cblockq << "Checking past-future blocks...";
+
 	unsigned t = time(0);
-	for (auto i = m_future.begin(); i != m_future.end() && i->first < t; ++i)
+	if (t < m_future.begin()->first)
-		import(&(i->second), _bc);
+		return;
 
-	WriteGuard l(m_lock);
+	cblockq << "Past-future blocks ready.";
-	m_future.erase(m_future.begin(), m_future.upper_bound(t));
+
+	vector<bytes> todo;
+	{
+		WriteGuard l(m_lock);
+		auto end = m_future.upper_bound(t);
+		for (auto i = m_future.begin(); i != end; ++i)
+			todo.push_back(move(i->second));
+		m_future.erase(m_future.begin(), end);
+	}
+
+	cblockq << "Importing" << todo.size() << "past-future blocks.";
+
+	for (auto const& b: todo)
+		import(&b, _bc);
 }
 
 template <class T> T advanced(T _t, unsigned _n)

libethereum/Client.cpp

@@ -117,6 +117,13 @@ void BasicGasPricer::update(BlockChain const& _bc)
 	}
 }
 
+std::ostream& dev::eth::operator<<(std::ostream& _out, ActivityReport const& _r)
+{
+	_out << "Since " << toString(_r.since) << " (" << std::chrono::duration_cast<std::chrono::seconds>(std::chrono::system_clock::now() - _r.since).count();
+	_out << "): " << _r.ticks << "ticks";
+	return _out;
+}
+
 Client::Client(p2p::Host* _extNet, std::string const& _dbPath, WithExisting _forceAction, u256 _networkId):
 	Worker("eth"),
 	m_vc(_dbPath),
@@ -582,9 +589,12 @@ void Client::tick()
 {
 	if (chrono::system_clock::now() - m_lastTick > chrono::seconds(1))
 	{
+		m_report.ticks++;
 		checkWatchGarbage();
 		m_bq.tick(m_bc);
 		m_lastTick = chrono::system_clock::now();
+		if (m_report.ticks == 15)
+			cnote << activityReport();
 	}
 }
 

libethereum/Client.h

@@ -97,6 +97,14 @@ struct ClientChat: public LogChannel { static const char* name() { return "=C=";
 struct ClientTrace: public LogChannel { static const char* name() { return "-C-"; } static const int verbosity = 7; };
 struct ClientDetail: public LogChannel { static const char* name() { return " C "; } static const int verbosity = 14; };
 
+struct ActivityReport
+{
+	unsigned ticks = 0;
+	std::chrono::system_clock::time_point since = std::chrono::system_clock::now();
+};
+
+std::ostream& operator<<(std::ostream& _out, ActivityReport const& _r);
+
 /**
  * @brief Main API hub for interfacing with Ethereum.
  */
@@ -204,6 +212,8 @@ public:
 	void killChain();
 	/// Retries all blocks with unknown parents.
 	void retryUnkonwn() { m_bq.retryAllUnknown(); }
+	/// Get a report of activity.
+	ActivityReport activityReport() { ActivityReport ret; std::swap(m_report, ret); return ret; }
 
 protected:
 	/// InterfaceStub methods
@@ -295,6 +305,8 @@ private:
 	mutable std::chrono::system_clock::time_point m_lastTick = std::chrono::system_clock::now();
 											///< When did we last tick()?
 
+	ActivityReport m_report;
+
 	// TODO!!!!!! REPLACE WITH A PROPER X-THREAD ASIO SIGNAL SYSTEM (could just be condition variables)
 	std::atomic<bool> m_syncTransactionQueue = {false};
 	std::atomic<bool> m_syncBlockQueue = {false};