Browse Source

Additional alterations to network & logging for ease of debugging.

cl-refactor
Gav Wood 11 years ago
parent
commit
80c4925ff0
  1. 14
      alethzero/Main.ui
  2. 43
      alethzero/MainWin.cpp
  3. 3
      alethzero/MainWin.h
  4. 26
      libethereum/Client.cpp
  5. 3
      libethereum/Client.h
  6. 13
      libethereum/PeerNetwork.h
  7. 22
      libethereum/PeerServer.cpp
  8. 2
      libethereum/PeerServer.h
  9. 64
      libethereum/PeerSession.cpp
  10. 2
      libethereum/PeerSession.h
  11. 2
      libqethereum/QEthereum.h

14
alethzero/Main.ui

@ -377,19 +377,21 @@
<number>0</number>
</property>
<item>
<widget class="QListWidget" name="log">
<widget class="QPlainTextEdit" name="log">
<property name="font">
<font>
<family>Monospace</family>
<pointsize>12</pointsize>
<family>Ubuntu Mono</family>
</font>
</property>
<property name="focusPolicy">
<enum>Qt::NoFocus</enum>
</property>
<property name="frameShape">
<enum>QFrame::NoFrame</enum>
</property>
<property name="frameShadow">
<enum>QFrame::Plain</enum>
</property>
<property name="lineWidth">
<number>0</number>
</property>
</widget>
</item>
<item>

43
alethzero/MainWin.cpp

@ -124,7 +124,15 @@ Main::Main(QWidget *parent) :
{
setWindowFlags(Qt::Window);
ui->setupUi(this);
g_logPost = [=](std::string const& s, char const* c) { simpleDebugOut(s, c); ui->log->addItem(QString::fromStdString(s)); };
g_logPost = [=](std::string const& s, char const* c)
{
simpleDebugOut(s, c);
m_logLock.lock();
m_logHistory.append(QString::fromStdString(s) + "\n");
m_logChanged = true;
m_logLock.unlock();
// ui->log->addItem(QString::fromStdString(s));
};
#if 0&&ETH_DEBUG
m_servers.append("192.168.0.10:30301");
@ -279,7 +287,7 @@ void Main::installBalancesWatch()
void Main::onNameRegChange()
{
cdebug << "NameReg changed!";
cwatch << "NameReg changed!";
// update any namereg-dependent stuff - for now force a full update.
refreshAll();
@ -287,7 +295,7 @@ void Main::onNameRegChange()
void Main::onCurrenciesChange()
{
cdebug << "Currencies changed!";
cwatch << "Currencies changed!";
installBalancesWatch();
// TODO: update any currency-dependent stuff?
@ -295,14 +303,14 @@ void Main::onCurrenciesChange()
void Main::onBalancesChange()
{
cdebug << "Our balances changed!";
cwatch << "Our balances changed!";
refreshBalances();
}
void Main::onNewBlock()
{
cdebug << "Blockchain changed!";
cwatch << "Blockchain changed!";
// update blockchain dependent views.
refreshBlockCount();
@ -312,7 +320,7 @@ void Main::onNewBlock()
void Main::onNewPending()
{
cdebug << "Pending transactions changed!";
cwatch << "Pending transactions changed!";
// update any pending-transaction dependent views.
refreshPending();
@ -608,6 +616,7 @@ void Main::refreshMining()
void Main::refreshBalances()
{
cwatch << "refreshBalances()";
// update all the balance-dependent stuff.
ui->ourAccounts->clear();
u256 totalBalance = 0;
@ -660,7 +669,7 @@ void Main::refreshAll()
void Main::refreshPending()
{
cdebug << "refreshPending()";
cwatch << "refreshPending()";
ui->transactionQueue->clear();
for (Transaction const& t: m_client->pending())
{
@ -682,7 +691,7 @@ void Main::refreshPending()
void Main::refreshAccounts()
{
cdebug << "refreshAccounts()";
cwatch << "refreshAccounts()";
ui->accounts->clear();
ui->contracts->clear();
for (auto n = 0; n < 2; ++n)
@ -703,7 +712,7 @@ void Main::refreshAccounts()
void Main::refreshDestination()
{
cdebug << "refreshDestination()";
cwatch << "refreshDestination()";
QString s;
for (auto i: m_client->addresses())
if ((s = pretty(i)).size())
@ -717,7 +726,7 @@ void Main::refreshDestination()
void Main::refreshBlockCount()
{
cdebug << "refreshBlockCount()";
cwatch << "refreshBlockCount()";
auto d = m_client->blockChain().details();
auto diff = BlockInfo(m_client->blockChain().block()).difficulty;
ui->blockCount->setText(QString("#%1 @%3 T%2 N%4 D%5").arg(d.number).arg(toLog2(d.totalDifficulty)).arg(toLog2(diff)).arg(eth::c_protocolVersion).arg(eth::c_databaseVersion));
@ -750,7 +759,7 @@ static bool transactionMatch(string const& _f, Transaction const& _t)
void Main::refreshBlockChain()
{
cdebug << "refreshBlockChain()";
cwatch << "refreshBlockChain()";
eth::ClientGuard g(m_client.get());
auto const& st = state();
@ -834,6 +843,15 @@ void Main::timerEvent(QTimerEvent*)
if (interval / 100 % 2 == 0)
refreshMining();
if (m_logChanged)
{
m_logLock.lock();
m_logChanged = false;
ui->log->appendPlainText(m_logHistory);
m_logHistory.clear();
m_logLock.unlock();
}
// refresh peer list every 1000ms, reset counter
if (interval == 1000)
{
@ -1198,7 +1216,8 @@ void Main::on_ourAccounts_doubleClicked()
void Main::on_log_doubleClicked()
{
qApp->clipboard()->setText(ui->log->currentItem()->text());
ui->log->setPlainText("");
m_logHistory.clear();
}
void Main::on_accounts_doubleClicked()

3
alethzero/MainWin.h

@ -229,6 +229,9 @@ private:
QNetworkAccessManager m_webCtrl;
QList<QPair<QString, QString>> m_consoleHistory;
QMutex m_logLock;
QString m_logHistory;
bool m_logChanged = true;
QEthereum* m_ethereum = nullptr;
};

26
libethereum/Client.cpp

@ -131,7 +131,7 @@ unsigned Client::installWatch(h256 _h)
{
auto ret = m_watches.size() ? m_watches.rbegin()->first + 1 : 0;
m_watches[ret] = Watch(_h);
cdebug << "Install watch" << ret << _h;
cwatch << "+++" << ret << _h;
return ret;
}
@ -149,7 +149,7 @@ unsigned Client::installWatch(TransactionFilter const& _f)
void Client::uninstallWatch(unsigned _i)
{
cdebug << "Uninstall watch" << _i;
cwatch << "XXX" << _i;
lock_guard<mutex> l(m_filterLock);
@ -189,7 +189,7 @@ void Client::noteChanged(h256Set const& _filters)
for (auto& i: m_watches)
if (_filters.count(i.second.id))
{
cdebug << "Watch activated" << i.first << i.second.id;
cwatch << "!!!" << i.first << i.second.id;
i.second.changes++;
}
}
@ -262,7 +262,7 @@ void Client::transact(Secret _secret, u256 _value, Address _dest, bytes const& _
ClientGuard l(this);
Transaction t;
cdebug << "Nonce at " << toAddress(_secret) << " pre:" << m_preMine.transactionsFrom(toAddress(_secret)) << " post:" << m_postMine.transactionsFrom(toAddress(_secret));
// cdebug << "Nonce at " << toAddress(_secret) << " pre:" << m_preMine.transactionsFrom(toAddress(_secret)) << " post:" << m_postMine.transactionsFrom(toAddress(_secret));
t.nonce = m_postMine.transactionsFrom(toAddress(_secret));
t.value = _value;
t.gasPrice = _gasPrice;
@ -302,6 +302,7 @@ void Client::inject(bytesConstRef _rlp)
void Client::work(bool _justQueue)
{
cdebug << ">>> WORK";
h256Set changeds;
// Process network events.
@ -309,11 +310,14 @@ void Client::work(bool _justQueue)
// Will broadcast any of our (new) transactions and blocks, and collect & add any of their (new) transactions and blocks.
if (m_net && !_justQueue)
{
cdebug << "--- WORK: LOCK";
ClientGuard l(this);
cdebug << "--- WORK: NETWORK";
m_net->process(); // must be in guard for now since it uses the blockchain.
// TODO: return h256Set as block hashes, once for each block that has come in/gone out.
h256Set newBlocks = m_net->sync(m_bc, m_tq, m_stateDB);
// returns h256Set as block hashes, once for each block that has come in/gone out.
cdebug << "--- WORK: TQ <== NET ==> CHAIN";
h256Set newBlocks = m_net->sync(m_bc, m_tq, m_stateDB, 100);
if (newBlocks.size())
{
for (auto i: newBlocks)
@ -353,6 +357,7 @@ void Client::work(bool _justQueue)
if (m_doMine)
{
cdebug << "--- WORK: MINE";
m_restartMining = false;
// Mine for a while.
@ -368,7 +373,9 @@ void Client::work(bool _justQueue)
if (mineInfo.completed)
{
// Import block.
cdebug << "--- WORK: COMPLETE MINE%";
m_postMine.completeMine();
cdebug << "--- WORK: CHAIN <== postSTATE";
h256s hs = m_bc.attemptImport(m_postMine.blockData(), m_stateDB);
if (hs.size())
{
@ -380,7 +387,10 @@ void Client::work(bool _justQueue)
}
}
else
{
cdebug << "--- WORK: SLEEP";
this_thread::sleep_for(chrono::milliseconds(100));
}
}
// Synchronise state to block chain.
@ -392,6 +402,7 @@ void Client::work(bool _justQueue)
// Resynchronise state with block chain & trans
{
ClientGuard l(this);
cdebug << "--- WORK: preSTATE <== CHAIN";
if (m_preMine.sync(m_bc) || m_postMine.address() != m_preMine.address())
{
if (m_doMine)
@ -402,6 +413,7 @@ void Client::work(bool _justQueue)
}
// returns h256s as blooms, once for each transaction.
cdebug << "--- WORK: postSTATE <== TQ";
h256s newPendingBlooms = m_postMine.sync(m_tq);
if (newPendingBlooms.size())
{
@ -415,7 +427,9 @@ void Client::work(bool _justQueue)
}
}
cdebug << "--- WORK: noteChanged" << changeds.size() << "items";
noteChanged(changeds);
cdebug << "<<< WORK";
}
void Client::lock() const

3
libethereum/Client.h

@ -157,6 +157,9 @@ struct Watch
unsigned changes = 1;
};
struct WatchChannel: public LogChannel { static const char* name() { return "(o)"; } static const int verbosity = 6; };
#define cwatch eth::LogOutputStream<eth::WatchChannel, true>()
/**
* @brief Main API hub for interfacing with Ethereum.
*/

13
libethereum/PeerNetwork.h

@ -46,12 +46,13 @@ class PeerSession;
struct NetWarn: public LogChannel { static const char* name() { return "!N!"; } static const int verbosity = 0; };
struct NetNote: public LogChannel { static const char* name() { return "*N*"; } static const int verbosity = 1; };
struct NetMessageSummary: public LogChannel { static const char* name() { return "-N-"; } static const int verbosity = 2; };
struct NetMessageDetail: public LogChannel { static const char* name() { return "=N="; } static const int verbosity = 3; };
struct NetTriviaSummary: public LogChannel { static const char* name() { return "-N-"; } static const int verbosity = 4; };
struct NetTriviaDetail: public LogChannel { static const char* name() { return "=N="; } static const int verbosity = 5; };
struct NetAllDetail: public LogChannel { static const char* name() { return "=N="; } static const int verbosity = 6; };
struct NetRight: public LogChannel { static const char* name() { return ">N>"; } static const int verbosity = 8; };
struct NetLeft: public LogChannel { static const char* name() { return "<N<"; } static const int verbosity = 9; };
struct NetConnect: public LogChannel { static const char* name() { return "+N+"; } static const int verbosity = 4; };
struct NetMessageDetail: public LogChannel { static const char* name() { return "=N="; } static const int verbosity = 5; };
struct NetTriviaSummary: public LogChannel { static const char* name() { return "-N-"; } static const int verbosity = 10; };
struct NetTriviaDetail: public LogChannel { static const char* name() { return "=N="; } static const int verbosity = 11; };
struct NetAllDetail: public LogChannel { static const char* name() { return "=N="; } static const int verbosity = 15; };
struct NetRight: public LogChannel { static const char* name() { return ">N>"; } static const int verbosity = 18; };
struct NetLeft: public LogChannel { static const char* name() { return "<N<"; } static const int verbosity = 19; };
enum PacketType
{

22
libethereum/PeerServer.cpp

@ -268,7 +268,7 @@ void PeerServer::ensureAccepting()
{
if (m_accepting == false)
{
clog(NetNote) << "Listening on local port " << m_listenPort << " (public: " << m_public << ")";
clog(NetConnect) << "Listening on local port " << m_listenPort << " (public: " << m_public << ")";
m_accepting = true;
m_acceptor.async_accept(m_socket, [=](boost::system::error_code ec)
{
@ -276,7 +276,7 @@ void PeerServer::ensureAccepting()
try
{
try {
clog(NetNote) << "Accepted connection from " << m_socket.remote_endpoint();
clog(NetConnect) << "Accepted connection from " << m_socket.remote_endpoint();
} catch (...){}
bi::address remoteAddress = m_socket.remote_endpoint().address();
// Port defaults to 0 - we let the hello tell us which port the peer listens to
@ -303,19 +303,19 @@ void PeerServer::connect(std::string const& _addr, unsigned short _port) noexcep
catch (exception const& e)
{
// Couldn't connect
clog(NetNote) << "Bad host " << _addr << " (" << e.what() << ")";
clog(NetConnect) << "Bad host " << _addr << " (" << e.what() << ")";
}
}
void PeerServer::connect(bi::tcp::endpoint const& _ep)
{
clog(NetNote) << "Attempting connection to " << _ep;
clog(NetConnect) << "Attempting connection to " << _ep;
bi::tcp::socket* s = new bi::tcp::socket(m_ioService);
s->async_connect(_ep, [=](boost::system::error_code const& ec)
{
if (ec)
{
clog(NetNote) << "Connection refused to " << _ep << " (" << ec.message() << ")";
clog(NetConnect) << "Connection refused to " << _ep << " (" << ec.message() << ")";
for (auto i = m_incomingPeers.begin(); i != m_incomingPeers.end(); ++i)
if (i->second.first == _ep && i->second.second < 3)
{
@ -323,13 +323,13 @@ void PeerServer::connect(bi::tcp::endpoint const& _ep)
goto OK;
}
// for-else
clog(NetNote) << "Giving up.";
clog(NetConnect) << "Giving up.";
OK:;
}
else
{
auto p = make_shared<PeerSession>(this, std::move(*s), m_networkId, _ep.address(), _ep.port());
clog(NetNote) << "Connected to " << _ep;
clog(NetConnect) << "Connected to " << _ep;
p->start();
}
delete s;
@ -363,7 +363,7 @@ bool PeerServer::noteBlock(h256 _hash, bytesConstRef _data)
return false;
}
h256Set PeerServer::sync(BlockChain& _bc, TransactionQueue& _tq, OverlayDB& _o)
h256Set PeerServer::sync(BlockChain& _bc, TransactionQueue& _tq, OverlayDB& _o, unsigned _max)
{
h256Set ret;
@ -427,12 +427,13 @@ h256Set PeerServer::sync(BlockChain& _bc, TransactionQueue& _tq, OverlayDB& _o)
}
m_latestBlockSent = h;
for (int accepted = 1, n = 0; accepted; ++n)
unsigned totalAccepted = 0;
for (int accepted = 1, n = 0; accepted && totalAccepted < _max; ++n)
{
accepted = 0;
lock_guard<recursive_mutex> l(m_incomingLock);
if (m_incomingBlocks.size())
for (auto it = prev(m_incomingBlocks.end());; --it)
for (auto it = prev(m_incomingBlocks.end()); totalAccepted < _max; --it)
{
try
{
@ -440,6 +441,7 @@ h256Set PeerServer::sync(BlockChain& _bc, TransactionQueue& _tq, OverlayDB& _o)
ret.insert(h);
it = m_incomingBlocks.erase(it);
++accepted;
++totalAccepted;
netChange = true;
}
catch (UnknownParent)

2
libethereum/PeerServer.h

@ -58,7 +58,7 @@ public:
void connect(bi::tcp::endpoint const& _ep);
/// Sync with the BlockChain. It might contain one of our mined blocks, we might have new candidates from the network.
h256Set sync(BlockChain& _bc, TransactionQueue&, OverlayDB& _o);
h256Set sync(BlockChain& _bc, TransactionQueue&, OverlayDB& _o, unsigned _max);
/// Conduct I/O, polling, syncing, whatever.
/// Ideally all time-consuming I/O is done in a background thread or otherwise asynchronously, but you get this call every 100ms or so anyway.

64
libethereum/PeerSession.cpp

@ -31,9 +31,9 @@ using namespace eth;
#define clogS(X) eth::LogOutputStream<X, true>(false) << "| " << std::setw(2) << m_socket.native_handle() << "] "
static const eth::uint c_maxHashes = 128; ///< Maximum number of hashes GetChain will ever send.
static const eth::uint c_maxBlocks = 32; ///< Maximum number of blocks Blocks will ever send.
static const eth::uint c_maxBlocksAsk = 32; ///< Maximum number of blocks we ask to receive in Blocks (when using GetChain).
static const eth::uint c_maxHashes = 4096; ///< Maximum number of hashes GetChain will ever send.
static const eth::uint c_maxBlocks = 2048; ///< Maximum number of blocks Blocks will ever send.
static const eth::uint c_maxBlocksAsk = 512; ///< Maximum number of blocks we ask to receive in Blocks (when using GetChain).
PeerSession::PeerSession(PeerServer* _s, bi::tcp::socket _socket, uint _rNId, bi::address _peerAddress, unsigned short _peerPort):
m_server(_s),
@ -111,24 +111,9 @@ bool PeerSession::interpret(RLP const& _r)
m_server->m_peers[m_id] = shared_from_this();
// Grab their block chain off them.
// Grab trsansactions off them.
{
uint n = m_server->m_chain->number(m_server->m_latestBlockSent);
clogS(NetAllDetail) << "Want chain. Latest:" << m_server->m_latestBlockSent << ", number:" << n;
uint count = std::min(c_maxHashes, n + 1);
RLPStream s;
prep(s).appendList(2 + count);
s << GetChainPacket;
auto h = m_server->m_latestBlockSent;
for (uint i = 0; i < count; ++i, h = m_server->m_chain->details(h).parent)
{
clogS(NetAllDetail) << " " << i << ":" << h;
s << h;
}
s << c_maxBlocksAsk;
sealAndSend(s);
s.clear();
prep(s).appendList(1);
s << GetTransactionsPacket;
sealAndSend(s);
@ -240,16 +225,27 @@ bool PeerSession::interpret(RLP const& _r)
}
}
m_rating += used;
if (g_logVerbosity >= 3)
unsigned knownParents = 0;
unsigned unknownParents = 0;
if (g_logVerbosity >= 2)
{
for (unsigned i = 1; i < _r.itemCount(); ++i)
{
auto h = sha3(_r[i].data());
BlockInfo bi(_r[i].data());
if (!m_server->m_chain->details(bi.parentHash) && !m_knownBlocks.count(bi.parentHash))
{
unknownParents++;
clogS(NetMessageDetail) << "Unknown parent " << bi.parentHash << " of block " << h;
}
else
{
knownParents++;
clogS(NetMessageDetail) << "Known parent " << bi.parentHash << " of block " << h;
}
}
}
clogS(NetMessageSummary) << dec << knownParents << " known parents, " << unknownParents << "unknown, " << used << "used.";
if (used) // we received some - check if there's any more
{
RLPStream s;
@ -259,6 +255,8 @@ bool PeerSession::interpret(RLP const& _r)
s << c_maxBlocksAsk;
sealAndSend(s);
}
else
clogS(NetMessageSummary) << "Peer sent all blocks in chain.";
break;
}
case GetChainPacket:
@ -316,6 +314,9 @@ bool PeerSession::interpret(RLP const& _r)
clogS(NetAllDetail) << " " << dec << i << " " << h;
s.appendRaw(m_server->m_chain->block(h));
}
if (!count)
clogS(NetMessageSummary) << "Sent peer all we have.";
clogS(NetAllDetail) << "Parent: " << h;
}
else if (parent != parents.back())
@ -487,7 +488,7 @@ void PeerSession::dropped()
if (m_socket.is_open())
try
{
clogS(NetNote) << "Closing " << m_socket.remote_endpoint();
clogS(NetConnect) << "Closing " << m_socket.remote_endpoint();
m_socket.close();
}
catch (...) {}
@ -503,7 +504,7 @@ void PeerSession::dropped()
void PeerSession::disconnect(int _reason)
{
clogS(NetNote) << "Disconnecting (reason:" << reasonOf((DisconnectReason)_reason) << ")";
clogS(NetConnect) << "Disconnecting (reason:" << reasonOf((DisconnectReason)_reason) << ")";
if (m_socket.is_open())
{
if (m_disconnect == chrono::steady_clock::time_point::max())
@ -531,6 +532,25 @@ void PeerSession::start()
doRead();
}
void PeerSession::startInitialSync()
{
uint n = m_server->m_chain->number(m_server->m_latestBlockSent);
clogS(NetAllDetail) << "Want chain. Latest:" << m_server->m_latestBlockSent << ", number:" << n;
uint count = std::min(c_maxHashes, n + 1);
RLPStream s;
prep(s).appendList(2 + count);
s << GetChainPacket;
auto h = m_server->m_latestBlockSent;
for (uint i = 0; i < count; ++i, h = m_server->m_chain->details(h).parent)
{
clogS(NetAllDetail) << " " << i << ":" << h;
s << h;
}
s << c_maxBlocksAsk;
sealAndSend(s);
}
void PeerSession::doRead()
{
// ignore packets received while waiting to disconnect

2
libethereum/PeerSession.h

@ -51,6 +51,8 @@ public:
bi::tcp::endpoint endpoint() const; ///< for other peers to connect to.
private:
void startInitialSync();
void dropped();
void doRead();
void doWrite(std::size_t length);

2
libqethereum/QEthereum.h

@ -187,7 +187,7 @@ private:
frame->disconnect(); \
frame->addToJavaScriptWindowObject("env", env, QWebFrame::QtOwnership); \
frame->addToJavaScriptWindowObject("eth", eth, QWebFrame::ScriptOwnership); \
frame->evaluateJavaScript("eth.makeWatch = function(a) { var ww = eth.newWatch(a); var ret = { w: ww }; ret.uninstall = function() { eth.killWatch(w); }; ret.changed = function(f) { eth.watchChanged.connect(function(nw) { env.note('check:' + nw + ' vs ' + ww); if (nw == ww) f() }); }; ret.transactions = function() { return JSON.parse(eth.watchTransactions(this.w)) }; return ret; }"); \
frame->evaluateJavaScript("eth.makeWatch = function(a) { var ww = eth.newWatch(a); var ret = { w: ww }; ret.uninstall = function() { eth.killWatch(w); }; ret.changed = function(f) { eth.watchChanged.connect(function(nw) { if (nw == ww) f() }); }; ret.transactions = function() { return JSON.parse(eth.watchTransactions(this.w)) }; return ret; }"); \
frame->evaluateJavaScript("eth.watch = function(a) { return eth.makeWatch(JSON.stringify(a)) }"); \
frame->evaluateJavaScript("eth.watchChain = function() { return eth.makeWatch('chainChanged') }"); \
frame->evaluateJavaScript("eth.watchPending = function() { return eth.makeWatch('pendingChanged') }"); \

Loading…
Cancel
Save