3 days now I am fighting with this problem. So let me explain and hopefully one of you have met (and solved) the same issue.
- I use a local private block chain with geth version 1.5.8-stable-f58fb322. One node mining and presenting the RPC interfaces as follow
geth --datadir "syndChain" --rpc --networkid 10001 --nodiscover --maxpeers 0 --rpcapi "debug,db,eth,net,web3,personal" --rpccorsdomain "*" --verbosity 6 --mine console
- I have a basic Factory contract
contract Factory { uint public counter; bytes32[] public Names; address[] public newContracts; function setCounter(uint v) {counter = v; } function createContract (bytes32 name) { counter++; address newContract = new Contract(name); newContracts.push(newContract); } function getName (uint i) { counter++; Contract con = Contract(newContracts[i]); Names[i] = con.Name(); } } contract Contract { bytes32 public Name; function Contract (bytes32 name) { Name = name; } }
- I deploy it using the solidity browser or the geth console
geth --solc '/usr/local/bin/solc' attach http://localhost:8545 console
- I compile the source code using an import of a local "sol" file
var source= 'import "./sources/_deploy_.sol";' var compiled = eth.compile.solidity(source);
and the compiled variable provides correct result when displayed.
- I create the Factory instance in the normal way
var defaultgas = eth.getBlock('latest').gasLimit; var abi=[{"constant":false,"inputs":[{"name":"name","type":"bytes32"}],"name":"createContract","outputs":[],"payable":false,"type":"function"},{"constant":true,"inputs":[],"name":"counter","outputs":[{"name":"","type":"uint256"}],"payable":false,"type":"function"},{"constant":false,"inputs":[{"name":"i","type":"uint256"}],"name":"getName","outputs":[],"payable":false,"type":"function"},{"constant":false,"inputs":[{"name":"v","type":"uint256"}],"name":"setCounter","outputs":[],"payable":false,"type":"function"},{"constant":true,"inputs":[{"name":"","type":"uint256"}],"name":"newContracts","outputs":[{"name":"","type":"address"}],"payable":false,"type":"function"},{"constant":true,"inputs":[{"name":"","type":"uint256"}],"name":"Names","outputs":[{"name":"","type":"bytes32"}],"payable":false,"type":"function"}] var code="0x6060604052341561000c57fe5b5b6105298061001c6000396000f30060606040523615610076576000357c0100000000000000000000000000000000000000000000000000000000900463ffffffff1680633f811b801461007857806361bc221a1461009c5780636b8ff574146100c25780638bb5d9c3146100e2578063bd21ad1914610102578063f01a4e0e14610162575bfe5b341561008057fe5b61009a60048080356000191690602001909190505061019e565b005b34156100a457fe5b6100ac61024b565b6040518082815260200191505060405180910390f35b34156100ca57fe5b6100e06004808035906020019091905050610251565b005b34156100ea57fe5b6101006004808035906020019091905050610351565b005b341561010a57fe5b610120600480803590602001909190505061035c565b604051808273ffffffffffffffffffffffffffffffffffffffff1673ffffffffffffffffffffffffffffffffffffffff16815260200191505060405180910390f35b341561016a57fe5b610180600480803590602001909190505061039c565b60405180826000191660001916815260200191505060405180910390f35b6000600060008154809291906001019190505550816101bb6103c1565b808260001916600019168152602001915050604051809103906000f08015156101e057fe5b9050600280548060010182816101f691906103d0565b916000526020600020900160005b83909190916101000a81548173ffffffffffffffffffffffffffffffffffffffff021916908373ffffffffffffffffffffffffffffffffffffffff160217905550505b5050565b60005481565b600060006000815480929190600101919050555060028281548110151561027457fe5b906000526020600020900160005b9054906101000a900473ffffffffffffffffffffffffffffffffffffffff1690508073ffffffffffffffffffffffffffffffffffffffff16638052474d6000604051602001526040518163ffffffff167c0100000000000000000000000000000000000000000000000000000000028152600401809050602060405180830381600087803b151561030f57fe5b60325a03f1151561031c57fe5b5050506040518051905060018381548110151561033557fe5b906000526020600020900160005b5081600019169055505b5050565b806000819055505b50565b60028181548110151561036b57fe5b906000526020600020900160005b915054906101000a900473ffffffffffffffffffffffffffffffffffffffff1681565b6001818154811015156103ab57fe5b906000526020600020900160005b915090505481565b60405160dc8061042283390190565b8154818355818115116103f7578183600052602060002091820191016103f691906103fc565b5b505050565b61041e91905b8082111561041a576000816000905550600101610402565b5090565b9056006060604052341561000c57fe5b6040516020806100dc833981016040528080519060200190919050505b80600081600019169055505b505b6097806100456000396000f30060606040526000357c0100000000000000000000000000000000000000000000000000000000900463ffffffff1680638052474d14603a575bfe5b3415604157fe5b60476065565b60405180826000191660001916815260200191505060405180910390f35b600054815600a165627a7a72305820a044c7782bc843f188703cdbb7a826b46130d87bd54980c54c008a215c2279c90029a165627a7a72305820e5fdae98aa6917cee58e86baf173680ffd7b690109704c8467f080ce548103ce0029" var contract=eth.contract(abi) var F=contract.new({from:eth.coinbase, code: code, gas: defaultgas})
No params and no callback to simplify
- watching the miner console log i see when the contract is ready and I check the output of variable F
> F { abi: [{ constant: false, inputs: [{...}], name: "createContract", outputs: [], payable: false, type: "function" }, { constant: true, inputs: [], name: "counter", outputs: [{...}], payable: false, type: "function" }, { constant: false, inputs: [{...}], name: "getName", outputs: [], payable: false, type: "function" }, { constant: false, inputs: [{...}], name: "setCounter", outputs: [], payable: false, type: "function" }, { constant: true, inputs: [{...}], name: "newContracts", outputs: [{...}], payable: false, type: "function" }, { constant: true, inputs: [{...}], name: "Names", outputs: [{...}], payable: false, type: "function" }], address: "0x3c425e2f1d97139c0e23baddf3f77dbc0efc220f", transactionHash: "0x208fc2a4ffa8fd315a0f0db5a2087c67a4f9bb1b4ddfa4d56a40465d37e985c6", Names: function(), allEvents: function(), counter: function(), createContract: function(), getName: function(), newContracts: function(), setCounter: function() }
All good so far.
- I call the simple function of the contract to verify
> F.counter() 0 > F.setCounter(10) "0xa304802c43b234b6f5a74d9db7a626633dfca716c9f517c5c9425a97a29931f5" > F.counter() 10
- I try to create the sub contract, and this is when this get bad.
> F.createContract("ABCD") "0xc63c0dc0b2ed6ee8f22b2467331b3370b19648ef862610cf6e58d654f4859d98"
Checking the log I can see the transaction being displayed.
I0211 23:07:55.914127 eth/downloader/downloader.go:1474] Quality of service: rtt 20s, conf 1.000, ttl 1m0s I0211 23:07:58.780174 core/tx_pool.go:343] (t) 0xc43266ad => 3c425e2f (0x412df60)
c63c0dc0b2ed6ee8f22b2467331b3370b19648ef862610cf6e58d654f4859d98 I0211 23:07:58.780237 core/tx_pool.go:534] Promoting queued transaction: TX(c63c0dc0b2ed6ee8f22b2467331b3370b19648ef862610cf6e58d654f4859d98) Contract: false From: c43266ad7f60e313029ec3de5bdc5e0c3682d945 To: 3c425e2f1d97139c0e23baddf3f77dbc0efc220f Nonce: 18 GasPrice: 0x4a817c800 GasLimit 0x15f90 Value: 0x0 Data: 0x3f811b804142434400000000000000000000000000000000000000000000000000000000 V: 0x1b R: 0x84577996b6a8509a36d742dc349785f68d59d612a1a441f2d8559ead7d88e686 S: 0x99acc1ac7d9a19f60e333a3422b099982d334dae7c56d7d97a183fa05266181 Hex: f889128504a817c80083015f90943c425e2f1d97139c0e23baddf3f77dbc0efc220f80a43f811b8041424344000000000000000000000000000000000000000000000000000000001ba084577996b6a8509a36d742dc349785f68d59d612a1a441f2d8559ead7d88e686a0099acc1ac7d9a19f60e333a3422b099982d334dae7c56d7d97a183fa05266181 I0211 23:07:58.780604 internal/ethapi/api.go:1076] Tx(0xc63c0dc0b2ed6ee8f22b2467331b3370b19648ef862610cf6e58d654f4859d98) to: 0x3c425e2f1d97139c0e23baddf3f77dbc0efc220f I0211 23:07:58.780639 eth/handler.go:727] broadcast tx to 0 peers I0211 23:08:03.602114 core/state/statedb.go:605] Trie cache stats: 10119 misses, 2 unloads I0211 23:08:03.605721 core/database_util.go:385] stored block total difficulty [a1c85d35…]: 638137566 I0211 23:08:03.605768 core/database_util.go:371] stored block body [a1c85d35…] I0211 23:08:03.605829 core/database_util.go:352] stored header #2508 [a1c85d35…] I0211 23:08:03.606109 miner/unconfirmed.go:105] 🔗 mined block #2503 [8783efe1…] reached canonical chain I0211 23:08:03.606124 miner/unconfirmed.go:83] 🔨 mined potential block #2508 [a1c85d35…], waiting for 5 blocks to confirm I0211 23:08:03.606170 eth/handler.go:707] propagated block a1c85d35 to 0 peers in 2562047h47m16.854775807s I0211 23:08:03.606223 core/database_util.go:420] stored block receipts [a1c85d35…] I0211 23:08:03.606306 eth/handler.go:714] announced block a1c85d35 to 0 peers in 2562047h47m16.854775807s I0211 23:08:03.606324 eth/handler.go:714] announced block a1c85d35 to 0 peers in 2562047h47m16.854775807s I0211 23:08:03.606359 eth/gasprice/gasprice.go:179] Processed block #2508, base price is 18181818181 I0211 23:08:03.606929 core/state/state_object.go:270] c43266ad7f60e313029ec3de5bdc5e0c3682d945: #18 13535935700000000000000 (- 1800000000000000) I0211 23:08:03.606973 core/vm/vm.go:121] evm running: 6fcd7996 I0211 23:08:03.607134 core/state/statedb.go:455] (+) a851f2959a38baf9a01a9fb169259b129050c973 I0211 23:08:03.607159 core/vm/vm.go:121] evm running: a205eaed I0211 23:08:03.607250 core/vm/vm.go:124] evm done: a205eaed. time: 82.753µs I0211 23:08:03.607298 core/vm/vm.go:124] evm done: 6fcd7996. time: 319.118µs I0211 23:08:03.607310 core/state_transition.go:242] vm returned with error: < nil > I0211 23:08:03.607318 core/state/state_object.go:257] c43266ad7f60e313029ec3de5bdc5e0c3682d945: #19 13535937500000000000000 (+ 1800000000000000) I0211 23:08:03.607392 core/state_processor.go:125] receipt{med=954bf9db8fabe26d0a86fc282ba8549f290751ec4972d34e7e276333df1e240c cgas=90000 bloom=00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 logs=[]} I0211 23:08:03.607675 core/state/state_object.go:257] c43266ad7f60e313029ec3de5bdc5e0c3682d945: #19 13540937500000000000000 (+ 5000000000000000000) I0211 23:08:03.607791 miner/worker.go:514] commit new work on block 2509 with 1 txs & 0 uncles. Took 1.666204ms I0211 23:08:03.607844 miner/agent.go:111] (re)started agent[0]. mining... I0211 23:08:06.160209 core/state/statedb.go:605] Trie cache stats: 10131 misses, 3 unloads I0211 23:08:06.163689 core/database_util.go:385] stored block total difficulty [c362a0d1…]: 638575412 I0211 23:08:06.163741 core/database_util.go:371] stored block body [c362a0d1…] I0211 23:08:06.163809 core/database_util.go:352] stored header #2509 [c362a0d1…] I0211 23:08:06.164112 miner/unconfirmed.go:105] 🔗 mined block #2504 [34d145ea…] reached canonical chain I0211 23:08:06.164124 miner/unconfirmed.go:83] 🔨 mined potential block #2509 [c362a0d1…], waiting for 5 blocks to confirm I0211 23:08:06.164238 core/database_util.go:420] stored block receipts [c362a0d1…] I0211 23:08:06.164257 eth/handler.go:707] propagated block c362a0d1 to 0 peers in 2562047h47m16.854775807s I0211 23:08:06.164270 eth/handler.go:714] announced block c362a0d1 to 0 peers in 2562047h47m16.854775807s I0211 23:08:06.164280 eth/handler.go:714] announced block c362a0d1 to 0 peers in 2562047h47m16.854775807s I0211 23:08:06.164281 eth/gasprice/gasprice.go:179] Processed block #2509, base price is 18181818181 I0211 23:08:06.164351 core/tx_pool.go:655] Removed old pending transaction: TX(c63c0dc0b2ed6ee8f22b2467331b3370b19648ef862610cf6e58d654f4859d98) Contract: false From: c43266ad7f60e313029ec3de5bdc5e0c3682d945 To: 3c425e2f1d97139c0e23baddf3f77dbc0efc220f Nonce: 18 GasPrice: 0x4a817c800 GasLimit 0x15f90 Value: 0x0 Data: 0x3f811b804142434400000000000000000000000000000000000000000000000000000000 V: 0x1b R: 0x84577996b6a8509a36d742dc349785f68d59d612a1a441f2d8559ead7d88e686 S: 0x99acc1ac7d9a19f60e333a3422b099982d334dae7c56d7d97a183fa05266181 Hex: f889128504a817c80083015f90943c425e2f1d97139c0e23baddf3f77dbc0efc220f80a43f811b8041424344000000000000000000000000000000000000000000000000000000001ba084577996b6a8509a36d742dc349785f68d59d612a1a441f2d8559ead7d88e686a0099acc1ac7d9a19f60e333a3422b099982d334dae7c56d7d97a183fa05266181 I0211 23:08:06.164449 core/state/state_object.go:257] c43266ad7f60e313029ec3de5bdc5e0c3682d945: #19 13545937500000000000000 (+ 5000000000000000000) I0211 23:08:06.164517 miner/worker.go:514] commit new work on block 2510 with 0 txs & 0 uncles. Took 364.299µs
It looks normal except the vm returned with error: When I then try to see if the counter has been increased, it has not been. But the TransactionReceipt is fine. The Block contain the transaction etc...
- Conclusion I have done a lot of testing and re-testing and this behaviour seems to only happen when the called function in the Factory contract create a new instance of the sub contract, whether I assign it to a variable, push it to an array or not.
What is very strange is that some time (but not always) when I call the createTranche function from solidity-browser it does work on the same instance of Factory!!!
I don't think it is an out-of gas problem as i provide the max allowed.
So please can someone try to replicate and advise on how to resolve?
thanks
eth.getTransactionReceipt("0xc63c0dc0b2ed6ee8f22b2467331b3370b19648ef862610cf6e58d654f4859d98")
(That's the hash I see in step 7.) It'll show you how much gas it used, so at least you can potentially rule out an OOG error.