Closed jleeh closed 6 years ago
I was finally able to reproduce this just now. Full log (long):
2018-08-17T18:26:06Z [DEBUG] Received log from block #3857486 for address 0xC677B812EF5582A97b816DF4C22FCeB842864B53 for job 348a317cbb464edba5c6723c566d87e2 services/subscription.go:326 job={"id":"348a317cbb464edba5c6723c566d87e2","createdAt":"2018-08-17T13:14:48.001069508-05:00","initiators":[{"id":16,"jobId":"348a317cbb464edba5c6723c566d87e2","type":"runlog","time":"0001-01-01T00:00:00Z","address":"0xc677b812ef5582a97b816df4c22fceb842864b53"}],"tasks":[{"confirmations":0,"type":"cryptocompare"},{"confirmations":0,"type":"copy"},{"confirmations":0,"type":"multiply"},{"confirmations":0,"type":"ethuint256"},{"confirmations":0,"type":"ethtx"}],"startAt":null,"endAt":null} log={"address":"0xc677b812ef5582a97b816df4c22fceb842864b53","topics":["0x3fab86a1207bdcfe3976d0d9df25f263d45ae8d381a60960559771a2b223974d","0xca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db8","0x3334386133313763626234363465646261356336373233633536366438376532","0x0000000000000000000000000000000000000000000000000de0b6b3a7640000"],"data":"0x00000000000000000000000000000000000000000000000000000000000000010000000000000000000000000000000000000000000000000000000000000040000000000000000000000000000000000000000000000000000000000000003bbf68656e64706f696e74657072696365646673796d63455448657473796d736355534468636f7079506174689f63555344ff6574696d65731864ff0000000000","blockNumber":"0x3adc4e","transactionHash":"0x77accb636d2b1f8bb58202bf184041b873889dff346a394878b897466c639e36","transactionIndex":"0xb","blockHash":"0xb5264b2dfc9df45dce4d25483aa893c23faf8f019b3fd112e6fc683a7a749174","logIndex":"0xe","removed":false} initiator={"id":16,"jobId":"348a317cbb464edba5c6723c566d87e2","type":"runlog","time":"0001-01-01T00:00:00Z","address":"0xc677b812ef5582a97b816df4c22fceb842864b53"}
2018-08-17T18:26:06Z [INFO] Starting job services/job_runner.go:219 job=348a317cbb464edba5c6723c566d87e2 run=95b77565500d42b491be765a45722ec7 status=in_progress
2018-08-17T18:26:06Z [DEBUG] Produced task run services/job_runner.go:276 taskRun=TaskRun(cbf53ea01d3448869cf74e68996740af,cryptocompare,pending_confirmations,)
2018-08-17T18:26:06Z [DEBUG] Task cryptocompare services/job_runner.go:277 task=0 type=cryptocompare taskrun=cbf53ea01d3448869cf74e68996740af params={"address":"0xC677B812EF5582A97b816DF4C22FCeB842864B53","copyPath":["USD"],"dataPrefix":"0xca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db8","endpoint":"price","fsym":"ETH","functionSelector":"0x76005c26","times":100,"tsyms":"USD","type":"cryptocompare"}
2018-08-17T18:26:06Z [INFO] Finished current job run execution services/job_runner.go:250 job=348a317cbb464edba5c6723c566d87e2 run=95b77565500d42b491be765a45722ec7 status=pending_confirmations
2018-08-17T18:26:30Z [DEBUG] Received header #3857487 (0x3adc4f) with hash 0x75676889ebc5d3a02ab0c84f1e496cfe3d8f261bad01f5609c4845a460eb20ce services/head_tracker.go:221
2018-08-17T18:26:30Z [DEBUG] Woke up95b77565500d42b491be765a45722ec7worker to process 3857487 services/job_runner.go:125
2018-08-17T18:26:30Z [INFO] Starting job services/job_runner.go:219 run=95b77565500d42b491be765a45722ec7 status=in_progress job=348a317cbb464edba5c6723c566d87e2
2018-08-17T18:26:31Z [DEBUG] Produced task run services/job_runner.go:276 taskRun=TaskRun(cbf53ea01d3448869cf74e68996740af,cryptocompare,completed,)
2018-08-17T18:26:31Z [DEBUG] Task cryptocompare pending_confirmations services/job_runner.go:277 type=cryptocompare params={"address":"0xC677B812EF5582A97b816DF4C22FCeB842864B53","confirmations":0,"copyPath":["USD"],"dataPrefix":"0xca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db8","endpoint":"price","fsym":"ETH","functionSelector":"0x76005c26","times":100,"tsyms":"USD","type":"cryptocompare"} taskrun=cbf53ea01d3448869cf74e68996740af status=pending_confirmations task=0
2018-08-17T18:26:31Z [DEBUG] Produced task run services/job_runner.go:276 taskRun=TaskRun(a382741e8fdf41afbd46cfb15024cdc4,copy,completed,)
2018-08-17T18:26:31Z [DEBUG] Task copy services/job_runner.go:277 task=1 type=copy params={"address":"0xC677B812EF5582A97b816DF4C22FCeB842864B53","confirmations":0,"copyPath":["USD"],"dataPrefix":"0xca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db8","endpoint":"price","fsym":"ETH","functionSelector":"0x76005c26","times":100,"tsyms":"USD","type":"copy"} taskrun=a382741e8fdf41afbd46cfb15024cdc4
2018-08-17T18:26:31Z [DEBUG] Produced task run services/job_runner.go:276 taskRun=TaskRun(2ebb730ca7804e57bfffe1dddc41ff74,multiply,completed,)
2018-08-17T18:26:31Z [DEBUG] Task multiply services/job_runner.go:277 taskrun=2ebb730ca7804e57bfffe1dddc41ff74 params={"address":"0xC677B812EF5582A97b816DF4C22FCeB842864B53","confirmations":0,"copyPath":["USD"],"dataPrefix":"0xca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db8","endpoint":"price","fsym":"ETH","functionSelector":"0x76005c26","times":100,"tsyms":"USD","type":"multiply"} task=2 type=multiply
2018-08-17T18:26:31Z [DEBUG] Produced task run services/job_runner.go:276 taskRun=TaskRun(e904aa7476a9423598877a2da48e80c7,ethuint256,completed,)
2018-08-17T18:26:31Z [DEBUG] Task ethuint256 services/job_runner.go:277 task=3 params={"address":"0xC677B812EF5582A97b816DF4C22FCeB842864B53","confirmations":0,"copyPath":["USD"],"dataPrefix":"0xca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db8","endpoint":"price","fsym":"ETH","functionSelector":"0x76005c26","times":100,"tsyms":"USD","type":"ethuint256"} type=ethuint256 taskrun=e904aa7476a9423598877a2da48e80c7
2018-08-17T18:26:31Z [ERROR] EthTx Adapter Perform Resuming: json: cannot unmarshal non-string into Go struct field TxReceipt.blockNumber of type *hexutil.Big adapters/eth_tx.go:67 stacktrace=github.com/smartcontractkit/chainlink/logger.Error
/home/thomas/go/src/github.com/smartcontractkit/chainlink/logger/logger.go:135
github.com/smartcontractkit/chainlink/adapters.ensureTxRunResult
/home/thomas/go/src/github.com/smartcontractkit/chainlink/adapters/eth_tx.go:67
github.com/smartcontractkit/chainlink/adapters.createTxRunResult
/home/thomas/go/src/github.com/smartcontractkit/chainlink/adapters/eth_tx.go:51
github.com/smartcontractkit/chainlink/adapters.(*EthTx).Perform
/home/thomas/go/src/github.com/smartcontractkit/chainlink/adapters/eth_tx.go:25
github.com/smartcontractkit/chainlink/services.startTask
/home/thomas/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:310
github.com/smartcontractkit/chainlink/services.ExecuteRunAtBlock
/home/thomas/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:236
github.com/smartcontractkit/chainlink/services.(*jobRunner).workerLoop
/home/thomas/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:127
github.com/smartcontractkit/chainlink/services.(*jobRunner).channelForRun.func1
/home/thomas/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:105
2018-08-17T18:26:31Z [DEBUG] Produced task run services/job_runner.go:276 taskRun=TaskRun(c1b88375382842049dc683926c83d575,ethtx,pending_confirmations,)
2018-08-17T18:26:31Z [DEBUG] Task ethtx services/job_runner.go:277 type=ethtx params={"address":"0xC677B812EF5582A97b816DF4C22FCeB842864B53","confirmations":0,"copyPath":["USD"],"dataPrefix":"0xca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db8","endpoint":"price","fsym":"ETH","functionSelector":"0x76005c26","times":100,"tsyms":"USD","type":"ethtx"} taskrun=c1b88375382842049dc683926c83d575 task=4
2018-08-17T18:26:31Z [INFO] Finished current job run execution services/job_runner.go:250 job=348a317cbb464edba5c6723c566d87e2 run=95b77565500d42b491be765a45722ec7 status=pending_confirmations
2018-08-17T18:26:40Z [DEBUG] Received header #3857488 (0x3adc50) with hash 0x1a1a48ad524c9738139c2b582272034616eb4acda13ca670a701f099b1495e4a services/head_tracker.go:221
2018-08-17T18:26:40Z [DEBUG] Woke up95b77565500d42b491be765a45722ec7worker to process 3857488 services/job_runner.go:125
2018-08-17T18:26:40Z [INFO] Starting job services/job_runner.go:219 status=in_progress job=348a317cbb464edba5c6723c566d87e2 run=95b77565500d42b491be765a45722ec7
2018-08-17T18:26:40Z [ERROR] EthTx Adapter Perform Resuming: json: cannot unmarshal non-string into Go struct field TxReceipt.blockNumber of type *hexutil.Big adapters/eth_tx.go:67 stacktrace=github.com/smartcontractkit/chainlink/logger.Error
/home/thomas/go/src/github.com/smartcontractkit/chainlink/logger/logger.go:135
github.com/smartcontractkit/chainlink/adapters.ensureTxRunResult
/home/thomas/go/src/github.com/smartcontractkit/chainlink/adapters/eth_tx.go:67
github.com/smartcontractkit/chainlink/adapters.(*EthTx).Perform
/home/thomas/go/src/github.com/smartcontractkit/chainlink/adapters/eth_tx.go:27
github.com/smartcontractkit/chainlink/services.startTask
/home/thomas/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:310
github.com/smartcontractkit/chainlink/services.ExecuteRunAtBlock
/home/thomas/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:236
github.com/smartcontractkit/chainlink/services.(*jobRunner).workerLoop
/home/thomas/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:127
github.com/smartcontractkit/chainlink/services.(*jobRunner).channelForRun.func1
/home/thomas/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:105
2018-08-17T18:26:40Z [DEBUG] Produced task run services/job_runner.go:276 taskRun=TaskRun(c1b88375382842049dc683926c83d575,ethtx,pending_confirmations,)
2018-08-17T18:26:40Z [DEBUG] Task ethtx pending_confirmations services/job_runner.go:277 params={"USD":300.49,"address":"0xC677B812EF5582A97b816DF4C22FCeB842864B53","confirmations":0,"copyPath":["USD"],"dataPrefix":"0xca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db8","endpoint":"price","fsym":"ETH","functionSelector":"0x76005c26","times":100,"tsyms":"USD","type":"cryptocompare","value":"0x6941ab7592a5f8ec5158b0de17129939170db06675b10c8b3e4e9f6ca2d0882b"} status=pending_confirmations task=0 type=ethtx taskrun=c1b88375382842049dc683926c83d575
2018-08-17T18:26:40Z [INFO] Finished current job run execution services/job_runner.go:250 job=348a317cbb464edba5c6723c566d87e2 run=95b77565500d42b491be765a45722ec7 status=pending_confirmations
2018-08-17T18:27:13Z [DEBUG] Received header #3857489 (0x3adc51) with hash 0x380f7f966421dc84574322d0378253d50ae9d42e59e8dcfca96686d0d851c968 services/head_tracker.go:221
2018-08-17T18:27:13Z [DEBUG] Woke up95b77565500d42b491be765a45722ec7worker to process 3857489 services/job_runner.go:125
2018-08-17T18:27:13Z [INFO] Starting job services/job_runner.go:219 status=in_progress job=348a317cbb464edba5c6723c566d87e2 run=95b77565500d42b491be765a45722ec7
2018-08-17T18:27:13Z [DEBUG] Produced task run services/job_runner.go:276 taskRun=TaskRun(c1b88375382842049dc683926c83d575,ethtx,pending_confirmations,)
2018-08-17T18:27:13Z [DEBUG] Task ethtx pending_confirmations services/job_runner.go:277 params={"USD":300.49,"address":"0xC677B812EF5582A97b816DF4C22FCeB842864B53","confirmations":0,"copyPath":["USD"],"dataPrefix":"0xca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db8","endpoint":"price","fsym":"ETH","functionSelector":"0x76005c26","times":100,"tsyms":"USD","type":"cryptocompare","value":"0x6941ab7592a5f8ec5158b0de17129939170db06675b10c8b3e4e9f6ca2d0882b"} task=0 type=ethtx taskrun=c1b88375382842049dc683926c83d575 status=pending_confirmations
2018-08-17T18:27:13Z [INFO] Finished current job run execution services/job_runner.go:250 job=348a317cbb464edba5c6723c566d87e2 run=95b77565500d42b491be765a45722ec7 status=pending_confirmations
2018-08-17T18:27:15Z [DEBUG] Received header #3857490 (0x3adc52) with hash 0x1639d1e6414108716bf0a030c654f63ec4d60bac036d70810b1c2d9efeb91634 services/head_tracker.go:221
2018-08-17T18:27:15Z [DEBUG] Woke up95b77565500d42b491be765a45722ec7worker to process 3857490 services/job_runner.go:125
2018-08-17T18:27:15Z [INFO] Starting job services/job_runner.go:219 job=348a317cbb464edba5c6723c566d87e2 run=95b77565500d42b491be765a45722ec7 status=in_progress
2018-08-17T18:27:15Z [INFO] Confirmed tx 0x6941ab7592a5f8ec5158b0de17129939170db06675b10c8b3e4e9f6ca2d0882b store/tx_manager.go:176 txat={"Hash":"0x6941ab7592a5f8ec5158b0de17129939170db06675b10c8b3e4e9f6ca2d0882b","TxID":1,"GasPrice":20000000000,"Confirmed":true,"Hex":"0xf8aa808504a817c8008307a12094c677b812ef5582a97b816df4c22fceb842864b5380b84476005c26ca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db800000000000000000000000000000000000000000000000000000000000075612aa0eaf00b0953ef1e08f2d2c6c51d54cd27a9aae1e104b624744e8dc671e406d73aa041d4f63f18d85c61c00c2f07dfbd570b566297f4830299a2b681f587b9570e13","SentAt":3857487} receipt={"blockNumber":"0x3adc51","transactionHash":"0x6941ab7592a5f8ec5158b0de17129939170db06675b10c8b3e4e9f6ca2d0882b"}
2018-08-17T18:27:15Z [DEBUG] Produced task run services/job_runner.go:276 taskRun=TaskRun(c1b88375382842049dc683926c83d575,ethtx,completed,)
2018-08-17T18:27:15Z [DEBUG] Task ethtx pending_confirmations services/job_runner.go:277 task=0 status=pending_confirmations type=ethtx params={"USD":300.49,"address":"0xC677B812EF5582A97b816DF4C22FCeB842864B53","confirmations":0,"copyPath":["USD"],"dataPrefix":"0xca3be951ed3b11c89076c8bd5271ee26bf62c8923b96957541c930a0a5820db8","endpoint":"price","fsym":"ETH","functionSelector":"0x76005c26","times":100,"tsyms":"USD","type":"cryptocompare","value":"0x6941ab7592a5f8ec5158b0de17129939170db06675b10c8b3e4e9f6ca2d0882b"} taskrun=c1b88375382842049dc683926c83d575
2018-08-17T18:27:15Z [INFO] Finished current job run execution services/job_runner.go:250 job=348a317cbb464edba5c6723c566d87e2 run=95b77565500d42b491be765a45722ec7 status=completed
2018-08-17T18:27:15Z [DEBUG] Worker finished for 95b77565500d42b491be765a45722ec7 services/job_runner.go:110
The only thing different is now I'm using a Parity node. I don't think I could reproduce this with a Geth client. Will try to confirm.
Should be fixed in #159635007.
Just updated the nodes to latest master, and when replying on chain I'm seeing a full panic now:
2018-09-18T15:12:07Z [DEBUG] Task ethuint256 services/job_runner.go:277 task=3 type=ethuint256 params=
{
"address": "0x9706Af5E65Da0C6C515704188bc35227D3DB5ce1",
"confirmations": 0,
"dataPrefix": "0x28ee4cb03b128ef80673a630411559071c1ff140a338161318a1bd46243627f7",
"functionSelector": "0x76005c26",
"path": [
"USD"
],
"type": "ethuint256",
"url": "https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=USD,EUR,JPY"
}
taskrun=c34a295d8f2a4c179d49ab96be093dfa
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x530c39]
goroutine 28 [running]:
math/big.(*Int).Add(0xc420aefb00, 0x0, 0xc420aefb00, 0x0)
/usr/local/go/src/math/big/int.go:110 +0x29
github.com/smartcontractkit/chainlink/store.(*TxManager).handleConfirmed(0xc4200b0b60, 0xc420a31290, 0xc420dc1cc0, 0xc42127e120, 0x3e08fb, 0xc42127e120, 0x0, 0x0)
/go/src/github.com/smartcontractkit/chainlink/store/tx_manager.go:186 +0x6a
github.com/smartcontractkit/chainlink/store.(*TxManager).checkAttempt(0xc4200b0b60, 0xc420a31290, 0xc420dc1cc0, 0x3e08fb, 0xc4200360f8, 0xc2b880, 0xc420a31290)
/go/src/github.com/smartcontractkit/chainlink/store/tx_manager.go:174 +0x128
github.com/smartcontractkit/chainlink/store.(*TxManager).MeetsMinConfirmations(0xc4200b0b60, 0xee8756e78eb86f71, 0xadb6b90949680b73, 0xfe58f56b2ba81e96, 0x41979195596999f4, 0x41979195596999f4, 0x0, 0x0)
/go/src/github.com/smartcontractkit/chainlink/store/tx_manager.go:93 +0x28e
github.com/smartcontractkit/chainlink/adapters.ensureTxRunResult(0xc424276780, 0x20, 0x5, 0xc424891ce0, 0x15b, 0x0, 0x0, 0x0, 0x0, 0xd5fe2e, ...)
/go/src/github.com/smartcontractkit/chainlink/adapters/eth_tx.go:65 +0x125
github.com/smartcontractkit/chainlink/adapters.createTxRunResult(0xc422c92240, 0xc424276780, 0x20, 0x5, 0xc420ed1ce0, 0x15b, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/smartcontractkit/chainlink/adapters/eth_tx.go:51 +0x3dc
github.com/smartcontractkit/chainlink/adapters.(*EthTx).Perform(0xc422c92240, 0xc424276780, 0x20, 0x5, 0xc420ed1ce0, 0x15b, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/smartcontractkit/chainlink/adapters/eth_tx.go:25 +0x186
github.com/smartcontractkit/chainlink/services.startTask(0xc424276780, 0x20, 0xc420034480, 0x20, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:310 +0x20f
github.com/smartcontractkit/chainlink/services.ExecuteRunAtBlock(0xc424276780, 0x20, 0xc420034480, 0x20, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:236 +0x73f
github.com/smartcontractkit/chainlink/services.BeginRunAtBlock(0xc420034480, 0x20, 0x3346a85d, 0xed30a15fb, 0x0, 0xc4200b1a00, 0x1, 0x4, 0xc42016c3c0, 0x5, ...)
/go/src/github.com/smartcontractkit/chainlink/services/job_runner.go:181 +0x21d
github.com/smartcontractkit/chainlink/services.runJob(0x6c0cda655eaf0697, 0x2752c38b18045751, 0xe15cdbd3, 0xc4218c8100, 0x4, 0x4, 0xc421568480, 0xc0, 0xc0, 0x3e08fb, ...)
/go/src/github.com/smartcontractkit/chainlink/services/subscription.go:219 +0x1b9
github.com/smartcontractkit/chainlink/services.receiveRunLog(0x6c0cda655eaf0697, 0x2752c38b18045751, 0xe15cdbd3, 0xc4218c8100, 0x4, 0x4, 0xc421568480, 0xc0, 0xc0, 0x3e08fb, ...)
/go/src/github.com/smartcontractkit/chainlink/services/subscription.go:194 +0x295
github.com/smartcontractkit/chainlink/services.InitiatorSubscription.dispatchLog(0x0, 0xc420034480, 0x20, 0x3346a85d, 0xed30a15fb, 0x0, 0xc4200b1a00, 0x1, 0x4, 0xc42016c3c0, ...)
/go/src/github.com/smartcontractkit/chainlink/services/subscription.go:142 +0x128
github.com/smartcontractkit/chainlink/services.(InitiatorSubscription).(github.com/smartcontractkit/chainlink/services.dispatchLog)-fm(0x6c0cda655eaf0697, 0x2752c38b18045751, 0xe15cdbd3, 0xc4218c8100, 0x4, 0x4, 0xc421568480, 0xc0, 0xc0, 0x3e08fb, ...)
/go/src/github.com/smartcontractkit/chainlink/services/subscription.go:131 +0x94
github.com/smartcontractkit/chainlink/services.ManagedSubscription.listenToLogs(0xc4203dc000, 0xc42008cb40, 0xc42008cd20, 0x10c54e0, 0xc42012e7e0, 0xc42020f560, 0x0, 0xc420a2d220, 0x0, 0x0, ...)
/go/src/github.com/smartcontractkit/chainlink/services/subscription.go:278 +0x1f5
created by github.com/smartcontractkit/chainlink/services.NewManagedSubscription
/go/src/github.com/smartcontractkit/chainlink/services/subscription.go:255 +0x225
System Information
Environment Variables
Additional Information
The spec I'm using is from the repo for
Consumer
in examples, the one requesting: https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=USD,EUR,JPYThis error is outputted when executing
EthTx
in the spec:The node actually fired the transaction, as seen here: https://ropsten.etherscan.io/tx/0xb071411150d7366bd4ba3a25fce044584bcce7a2fd13c1a9c7cd5c6e3305f683
But the node seems to loop waiting for confirmations and always getting 0:
At the point of that log entry, it had around 33 confirmations.
From what I've followed in the logs, it marks it as complete after a while on 0 confirmations.
Upon further investigation, the status of the spec run is marked as complete rather than errored also.