feat(@embark/proxy): Add dev tx to proxy when request fails to get response

Create a dev tx (a 0-value tx that is sent from the —dev account to itself) when a request goes through the proxy, but does not get a response after 5 seconds.

Log requests to disk (when log level is trace - enabled with the embark option `—loglevel trace`) that have not received a response and for which a dev tx has been sent.

Add logging to a `proxyLogs.json` log file as well, so that this information can be gleaned later for debugging purposes.

This particular PR Is meant to workaround an issue with running geth with the `—dev` option, as some transactions appear to get stuck, which then builds up further txs in a queue. Only when another tx is sent is the queue then purged as expected.

The remaining issue is that even though a dev tx is sent to relieve the queued txs, the originally offending tx still never receives a response from the node. This was the motivation behind creating a proxy log, so that a dev can inspect the txs that are essentially dropped.

**NOTE:** the base branch of this branch is `refactor/devfunds`. Please merge that branch first.
This commit is contained in:
emizzle 2019-04-04 19:52:09 +11:00 committed by Iuri Matias
parent 0c98af7977
commit 36be50e5dc
7 changed files with 136 additions and 26 deletions

View File

@ -6,7 +6,7 @@ import routes from '../routes';
import Login from '../components/Login';
import Layout from "../components/Layout";
import {DEFAULT_HOST} from '../constants';
import {getQueryToken, stripQueryToken, getQueryParam, stripQueryParam} from '../utils/utils';
import {getQueryToken, stripQueryToken} from '../utils/utils';
import {Helmet} from "react-helmet";
import {

View File

@ -135,7 +135,8 @@ DeploymentContainer.propTypes = {
web3Deploy: PropTypes.func,
web3Deployments: PropTypes.object,
web3EstimateGas: PropTypes.func,
web3GasEstimates: PropTypes.object
web3GasEstimates: PropTypes.object,
web3ContractsDeployed: PropTypes.object
};
export default connect(

View File

@ -46,7 +46,9 @@
"livenet": 1,
"testnet": 3,
"ropsten": 3,
"rinkeby": 4
"rinkeby": 4,
"development": 1337,
"development_parity": 17
},
"gasAllowanceError": "Returned error: gas required exceeds allowance or always failing transaction",
"gasAllowanceErrorMessage": "Failing call, this could be because of invalid inputs or function guards that may have been triggered, or an unknown error.",
@ -91,5 +93,8 @@
"embarkjs": "embarkjs.js",
"contractsJs": "contracts",
"symlinkDir": "modules"
},
"environments": {
"development": "development"
}
}

View File

@ -42,7 +42,7 @@ class DevTxs {
sendTx(cb) {
// Send TXs only in dev networks
if (this.networkId !== 1337 && this.networkId !== 17) {
if (this.networkId !== constants.blockchain.networkIds.development && this.networkId !== constants.blockchain.networkIds.development_parity) {
return;
}
this.web3.eth.sendTransaction({value: "0", to: this.web3.eth.defaultAccount, from: this.web3.eth.defaultAccount}).then(cb);
@ -52,7 +52,7 @@ class DevTxs {
const self = this;
self.web3.eth.net.getId().then((networkId) => {
self.networkId = networkId;
if (self.networkId !== 1337) {
if (self.networkId !== constants.blockchain.networkIds.development && this.networkId !== constants.blockchain.networkIds.development_parity) {
return;
}
this.regularTxsInt = setInterval(function() { self.sendTx(() => {}); }, 1500);

View File

@ -1,5 +1,7 @@
const ProcessLogsApi = require('../../modules/process_logs_api');
const async = require('async');
const DevTxs = require('./dev_txs');
const ProcessLogsApi = require('../../modules/process_logs_api');
const constants = require('../../constants.json');
const PROCESS_NAME = 'blockchain';
@ -23,8 +25,25 @@ class BlockchainListener {
this.events = embark.events;
this.logger = embark.logger;
this.ipc = ipc;
this.isDev = this.embark.config.env === "development";
this.isDev = this.embark.config.env === constants.environments.development;
this.devTxs = null;
this.fs = this.embark.fs;
this.proxyLogFile = this.fs.dappPath(".embark", "proxyLogs.json");
this.writeProxyLogFile = async.cargo((tasks, callback) => {
const data = this._readProxyLogs();
tasks.forEach(task => {
data[new Date().getTime()] = task;
});
this.fs.writeJson(this.proxyLogFile, data, err => {
if (err) {
console.error(err);
}
callback();
});
});
this.ipc.server.once('connect', () => {
this.processLogsApi = new ProcessLogsApi({embark: this.embark, processName: PROCESS_NAME, silent: true});
@ -39,6 +58,7 @@ class BlockchainListener {
});
this._registerConsoleCommands();
this._listenToIpcCommands();
}
}
@ -54,6 +74,20 @@ class BlockchainListener {
});
}
_listenToIpcCommands() {
this.ipc.on('blockchain:proxy:log', (log) => {
this.logger.trace(log);
});
this.ipc.on('blockchain:proxy:logtofile', (log) => {
this._saveProxyLog(log);
});
this.ipc.on('blockchain:devtxs:sendtx', () => {
this._sendTx(() => {});
});
}
_registerConsoleCommands() {
this.embark.registerConsoleCommand({
description: __('Toggles regular transactions used to prevent transactions from getting stuck when using Geth and Metamask'),
@ -114,6 +148,19 @@ class BlockchainListener {
}
this.events.once('blockchain:devtxs:ready', () => { this.devTxs.sendTx(cb); });
}
_saveProxyLog(log) {
this.writeProxyLogFile.push(log);
}
_readProxyLogs() {
this.fs.ensureFileSync(this.proxyLogFile);
try {
return JSON.parse(this.fs.readFileSync(this.proxyLogFile));
} catch (_error) {
return {};
}
}
}
module.exports = BlockchainListener;

View File

@ -17,6 +17,7 @@ const Transaction = require('ethereumjs-tx');
const ethUtil = require('ethereumjs-util');
const METHODS_TO_MODIFY = {accounts: 'eth_accounts'};
const REQUEST_TIMEOUT = 5000;
const modifyPayload = (toModifyPayloads, body, accounts) => {
switch (toModifyPayloads[body.id]) {
@ -58,9 +59,10 @@ class Proxy {
this.receipts = {};
this.transactions = {};
this.toModifyPayloads = {};
this.timeouts = {};
}
trackRequest(req) {
trackRequest({ws, data: req }) {
if (!req) return;
try {
if (Object.values(METHODS_TO_MODIFY).includes(req.method)) {
@ -94,6 +96,30 @@ class Proxy {
this.receipts[req.id] = this.transactions[req.params[0]].commListId;
}
}
// track the response to see if it responded to
const timeout = {
txSent: false
};
timeout.timeoutId = setInterval(() => {
if(timeout.txSent) {
const message = `[${ws?"WS":"HTTP"} Request ID ${req.id}]: Original tx still not sent, considering it abandoned.`;
this.consoleLog(`====================================================================\n${message}\n====================================================================`);
this.logToFile(message);
// clear original interval
// do not delete the timeout in case the response comes far in the future
clearInterval(timeout.timeoutId);
}
else{
const message = `[${ws?"WS":"HTTP"} Request ID ${req.id}]: No response received after ${REQUEST_TIMEOUT/1000}s. Sending another tx to "push" it through...\nRequest ID ${req.id} details: ${JSON.stringify(req)}`;
this.consoleLog(`===================================================================\n${message}\n===================================================================`);
this.logToFile(message);
this.sendDevTx();
timeout.txSent = true;
}
}, REQUEST_TIMEOUT);
this.timeouts[req.id] = timeout;
} catch (e) {
console.error(
`Proxy: Error tracking request message '${JSON.stringify(req)}'`,
@ -107,7 +133,7 @@ class Proxy {
if (this.commList[res.id]) {
if (this.commList[res.id].kind === 'call') {
this.commList[res.id].result = res.result;
this.sendIpcMessage(this.commList[res.id]);
this.contractLog(this.commList[res.id]);
delete this.commList[res.id];
} else {
this.commList[res.id].transactionHash = res.result;
@ -123,11 +149,26 @@ class Proxy {
this.commList[this.receipts[res.id]].blockNumber = res.result.blockNumber;
this.commList[this.receipts[res.id]].gasUsed = res.result.gasUsed;
this.commList[this.receipts[res.id]].status = res.result.status;
this.sendIpcMessage(this.commList[this.receipts[res.id]]);
this.contractLog(this.commList[this.receipts[res.id]]);
delete this.transactions[this.commList[this.receipts[res.id]].transactionHash];
delete this.commList[this.receipts[res.id]];
delete this.receipts[res.id];
}
// clear any tracked requests
const timeout = this.timeouts[res.id];
if(timeout) {
// if a dev tx had already been sent in an attempt to "push" this tx through,
// record that information.
if(timeout.txSent) {
const message = `✔ [Request ID ${res.id}]: Request successfully pushed through!\n` +
`Response details: ${JSON.stringify(res)}`;
this.consoleLog(`====================================================================\n${message}\n====================================================================`);
this.logToFile(message);
}
// clear the interval and delete the timeout to effectively stop tracking it
clearInterval(timeout.timeoutId);
delete this.timeouts[res.id];
}
} catch (e) {
console.error(
`Proxy: Error tracking response message '${JSON.stringify(res)}'`
@ -135,18 +176,34 @@ class Proxy {
}
}
sendIpcMessage(message) {
sendIpcMessage(type, message) {
if (this.ipc.connected && !this.ipc.connecting) {
this.ipc.request('log', message);
this.ipc.request(type, message);
} else {
this.ipc.connecting = true;
this.ipc.connect(() => {
this.ipc.connecting = false;
this.ipc.request('log', message);
this.ipc.request(type, message);
});
}
}
contractLog(message) {
this.sendIpcMessage('log', message);
}
consoleLog(message) {
this.sendIpcMessage('blockchain:proxy:log', message);
}
logToFile(message) {
this.sendIpcMessage('blockchain:proxy:logtofile', message);
}
sendDevTx() {
this.sendIpcMessage('blockchain:devtxs:sendtx');
}
async serve(host, port, ws, origin, accounts, certOptions={}) {
const start = Date.now();
await (function waitOnTarget() {
@ -225,7 +282,7 @@ class Proxy {
Asm.connectTo(
pump(req, jsonParser())
).on('done', ({current: object}) => {
this.trackRequest(object);
this.trackRequest({ ws: false, data: object});
});
}
@ -241,11 +298,11 @@ class Proxy {
proxy.on('open', (_proxySocket) => { /* messages FROM the target */ });
proxy.on('proxyReqWs', (_proxyReq, _req, socket) => {
proxy.on('proxyReqWs', (_proxyReq, req, socket) => {
// messages TO the target
pump(socket, new WsParser(0, false)).on('frame', ({data: buffer}) => {
const object = parseJsonMaybe(buffer.toString());
this.trackRequest(object);
this.trackRequest({ ws: true, data: object });
});
});
}

View File

@ -28,14 +28,14 @@ describe('embark.Proxy', function () {
const to = "to";
const data = "data";
proxy.trackRequest({
proxy.trackRequest({ws: true, data: {
id: 1,
method: constants.blockchain.transactionMethods.eth_sendTransaction,
params: [{
to: to,
data: data
}]
});
}});
expect(proxy.commList[1]).to.deep.equal({
type: 'contract-log',
@ -49,11 +49,11 @@ describe('embark.Proxy', function () {
const to = "0x2e6242a07ea1c4e79ecc5c69a2dccae19878a280";
const data = "0x60fe47b1000000000000000000000000000000000000000000000000000000000000115c";
proxy.trackRequest({
proxy.trackRequest({ws: true, data: {
id: 1,
method: constants.blockchain.transactionMethods.eth_sendRawTransaction,
params: ["0xf8852701826857942e6242a07ea1c4e79ecc5c69a2dccae19878a28080a460fe47b1000000000000000000000000000000000000000000000000000000000000115c820a96a04d6e3cbb86d80a75cd51da02bf8f0cc9893d64ca7956ce21b350cc143aa8a023a05878a850e4e7810d08093add07df405298280fdd901ecbabb74e73422cb5e0b0"]
});
}});
expect(proxy.commList[1]).to.deep.equal({
type: 'contract-log',
@ -67,11 +67,11 @@ describe('embark.Proxy', function () {
describe('#trackResponse', function () {
describe('when the response is a transaction', function () {
before(function () {
proxy.trackRequest({
proxy.trackRequest({ws: true, data: {
id: 1,
method: constants.blockchain.transactionMethods.eth_sendTransaction,
params: [{to: "to", data: "data" }]
});
}});
});
it('should populate the transaction when it is a known id', function (done) {
@ -98,14 +98,14 @@ describe('embark.Proxy', function () {
describe('when the response is a receipt', function () {
it('should make an ipc call', function (done) {
proxy.trackRequest({
proxy.trackRequest({ws: true, data: {
id: 3,
method: constants.blockchain.transactionMethods.eth_sendTransaction,
params: [{
to: "to",
data: "data"
}]
});
}});
proxy.trackResponse({
id: 3,
@ -115,14 +115,14 @@ describe('embark.Proxy', function () {
}
});
proxy.trackRequest({
proxy.trackRequest({ws: true, data: {
id: 4,
method: constants.blockchain.transactionMethods.eth_getTransactionReceipt,
params: [{
to: "to",
data: "data"
}]
});
}});
expect(proxy.receipts[4]).to.be.equal(3);