Open borisovdev opened 2 years ago
@borisovdev I just tried the following and was able to get it to successfully work:
export LOG_LEVEL=debug
export ETH_CHAIN_ID=42
export MIN_OUTGOING_CONFIRMATIONS=2
export LINK_CONTRACT_ADDRESS=0xa36085F69e2889c224210F603D836748e7dC0088
export CHAINLINK_TLS_PORT=0
export SECURE_COOKIES=false
export GAS_UPDATER_ENABLED=true
export ALLOW_ORIGINS=*
export ETH_URL=wss://kovan.infura.io/ws/v3/098cb589a57042c3a79176a2e2a94991
export MINIMUM_CONTRACT_PAYMENT_JUELS=10000000000000
export DATABASE_URL=postgresql://test:test@localhost:5432/eademo?sslmode=disable
export DEFAULT_HTTP_TIMEOUT=60s
Deploy new version of Operator.sol to Kovan, set authorized sender to node address:
pragma solidity ^0.7;
import "@chainlink/contracts/src/v0.7/Operator.sol";
Create new job on node as per your jobspec, changing address fields to Operator.sol deployed address
Create new consumer contract as per your example, changing jobID to one created above
Deploy new consumer contract, using Kovan LINK address and deployed Operator.sol address
Fund new consumer contract with 1 LINK
Call requestMultipleParameters function, wait 60 secs
Call getter methods on consumer contract to verify result:
Can you please compare this to your scenario, try replicate this and then see what the difference is. Are you running on a local chain?
Thanks for your comment, @pappas999 . Yes, i use local blockchain by ganache-cli. All services, includes postgres, running under containers. Please, use docker compose spec to reproduce my environment 1 to 1. Thanks for remind about missing part in my environment description - Operator.sol (v0.7)
UPD: As Oracle contract I use Operator.sol (v0.7)
thanks @borisovdev , can you please attach a file containing your node logs at the time of when you execute the job, letting us know what date/time you executed the job at? Will help us debug the issue
Yesterday I found something interesting.
When using volume mount to local host for postgres db data, after a while, jobs stops send ethtx to Operator contract (node funded by Eth) from multi variable jobs (maybe all jobs). But job pipeline finished successfully.
Removing mounted postgres data directory on local host and restart services solves issue. But what the source of the problem?
I give logs from chainlink node during the day.
2022-05-24T20:32:42.865Z [DEBUG] Received new head #163 (0xa3) headtracker/head_tracker.go:327 blockHash=0x3e0e49b4bb94754d31bdb92f58ee8567d4d9b20ef20e641206b6153145923250 blockHeight=163 evmChainID=1337 logger=head_tracker parentHeadHash=0x3d16c9df694ed90403b1d1350bfe6c748ea09b3fb04c02af4467fc9539c20e6b
2022-05-24T20:32:42.872Z [DEBUG] Received a log log/broadcaster.go:357 address=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 blockHash=0x3e0e49b4bb94754d31bdb92f58ee8567d4d9b20ef20e641206b6153145923250 blockNumber=163 evmChainID=1337 logger=LogBroadcaster
2022-05-24T20:32:43.094Z [DEBUG] Initiating callbacks headtracker/head_broadcaster.go:134 evmChainID=1337 headNum=163 logger=HeadBroadcaster numCallbacks=4
2022-05-24T20:32:43.094Z [DEBUG] BalanceMonitor: signalling balance worker services/balance_monitor.go:99 evmChainID=1337
2022-05-24T20:32:43.094Z [DEBUG] Finished callback in 49.667µs headtracker/head_broadcaster.go:150 blockNumber=163 callbackType=*services.balanceMonitor evmChainID=1337 logger=HeadBroadcaster time=0.000049667
2022-05-24T20:32:43.094Z [DEBUG] Received head log/broadcaster.go:446 blockHash=0x3e0e49b4bb94754d31bdb92f58ee8567d4d9b20ef20e641206b6153145923250 blockNumber=163 chainLen=69 evmChainID=1337 logger=LogBroadcaster parentHash=0x3d16c9df694ed90403b1d1350bfe6c748ea09b3fb04c02af4467fc9539c20e6b
2022-05-24T20:32:43.094Z [DEBUG] Finished callback in 4.206µs headtracker/head_broadcaster.go:150 blockNumber=163 callbackType=*services.promReporter evmChainID=1337 logger=HeadBroadcaster time=0.000004206
2022-05-24T20:32:43.094Z [DEBUG] Finished callback in 5.526µs headtracker/head_broadcaster.go:150 blockNumber=163 callbackType=*log.broadcaster evmChainID=1337 logger=HeadBroadcaster time=0.000005526
2022-05-24T20:32:43.094Z [DEBUG] eth.Client#BalanceAt(...) eth/node.go:393 account=0x550e1F4B209687F80f4072c1eB9D91ca23daBAA2 blockNumber=<nil> evmChainID=1337 logger=Node.primary-0-1337 mode=websocket nodeTier=primary
2022-05-24T20:32:43.106Z [DEBUG] LogBroadcaster: Sending out log log/registrations.go:312 address=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 blockHash=0x3e0e49b4bb94754d31bdb92f58ee8567d4d9b20ef20e641206b6153145923250 blockNumber=163 evmChainID=1337 jobID=2 latestBlockNumber=163 logger=LogBroadcaster.Registrations
2022-05-24T20:32:43.107Z [INFO] Oracle request received directrequest/delegate.go:280 callbackAddr=0x1D3992d16Fa39070468229Db977C50b5E8d10C58 callbackFunctionId=fda4417b cancelExpiration=1653424662 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 data=6675726c425443783f68747470733a2f2f6d696e2d6170692e63727970746f636f6d706172652e636f6d2f646174612f70726963653f6673796d3d455448267473796d733d4254436770617468425443634254436675726c555344783f68747470733a2f2f6d696e2d6170692e63727970746f636f6d706172652e636f6d2f646174612f70726963653f6673796d3d455448267473796d733d5553446770617468555344635553446675726c455552783f68747470733a2f2f6d696e2d6170692e63727970746f636f6d706172652e636f6d2f646174612f70726963653f6673796d3d455448267473796d733d455552677061746845555263455552 dataVersion=1 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest payment=100000000000000000 requestId=7790dca694e55d63c8c963fbb2e6b70b591e1d0690c4c70995935aea7ec73008 requester=0x1D3992d16Fa39070468229Db977C50b5E8d10C58 specId=3433386339626532376166663463353862623766393633326163616134313866
2022-05-24T20:32:43.114Z [DEBUG] Initiating tasks for pipeline run of spec pipeline/runner.go:263 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f job ID=0 jobID=0 logger=DirectRequest.DirectRequest
2022-05-24T20:32:43.114Z [DEBUG] scheduling task run pipeline/scheduler.go:104 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=decode_log externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.114Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=map[string]interface {} resultValue={"callbackAddr":"0x1d3992d16fa39070468229db977c50b5e8d10c58","callbackFunctionId":[253,164,65,123],"cancelExpiration":1653424662,"data":"ZnVybEJUQ3g/aHR0cHM6Ly9taW4tYXBpLmNyeXB0b2NvbXBhcmUuY29tL2RhdGEvcHJpY2U/ZnN5bT1FVEgmdHN5bXM9QlRDZ3BhdGhCVENjQlRDZnVybFVTRHg/aHR0cHM6Ly9taW4tYXBpLmNyeXB0b2NvbXBhcmUuY29tL2RhdGEvcHJpY2U/ZnN5bT1FVEgmdHN5bXM9VVNEZ3BhdGhVU0RjVVNEZnVybEVVUng/aHR0cHM6Ly9taW4tYXBpLmNyeXB0b2NvbXBhcmUuY29tL2RhdGEvcHJpY2U/ZnN5bT1FVEgmdHN5bXM9RVVSZ3BhdGhFVVJjRVVS","dataVersion":1,"payment":100000000000000000,"requestId":[119,144,220,166,148,229,93,99,200,201,99,251,178,230,183,11,89,30,29,6,144,196,199,9,149,147,90,234,126,199,48,8],"requester":"0x1d3992d16fa39070468229db977c50b5e8d10c58","specId":[52,51,56,99,57,98,101,50,55,97,102,102,52,99,53,56,98,98,55,102,57,54,51,50,97,99,97,97,52,49,56,102]} runInfo={"IsRetryable":false,"IsPending":false} taskName=decode_log taskType=ethabidecodelog
2022-05-24T20:32:43.114Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=decode_cbor externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.114Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=map[string]interface {} resultValue={"pathBTC":"BTC","pathEUR":"EUR","pathUSD":"USD","urlBTC":"https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=BTC","urlEUR":"https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=EUR","urlUSD":"https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=USD"} runInfo={"IsRetryable":false,"IsPending":false} taskName=decode_cbor taskType=cborparse
2022-05-24T20:32:43.114Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=btc externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.114Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=usd externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.115Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=eur externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.115Z [DEBUG] HTTP task: sending request pipeline/task.http.go:77 allowUnrestrictedNetworkAccess=true attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest method=GET requestData=null taskName=eur taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=EUR
2022-05-24T20:32:43.115Z [DEBUG] HTTP task: sending request pipeline/task.http.go:77 allowUnrestrictedNetworkAccess=true attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest method=GET requestData=null taskName=btc taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=BTC
2022-05-24T20:32:43.115Z [DEBUG] HTTP task: sending request pipeline/task.http.go:77 allowUnrestrictedNetworkAccess=true attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest method=GET requestData=null taskName=usd taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=USD
2022-05-24T20:32:43.376Z [DEBUG] http adapter got 200 in 261.31873ms utils/http.go:67 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=btc taskType=http timeElapsedSeconds=0.26131873
2022-05-24T20:32:43.376Z [DEBUG] http adapter finished after 261.496005ms utils/http.go:76 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=btc taskType=http timeElapsedSeconds=0.261496005
2022-05-24T20:32:43.376Z [DEBUG] HTTP task got response pipeline/task.http.go:92 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dotID=btc externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest response={"BTC":0.06673} taskName=btc taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=BTC
2022-05-24T20:32:43.377Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=string resultValue={"BTC":0.06673} runInfo={"IsRetryable":false,"IsPending":false} taskName=btc taskType=http
2022-05-24T20:32:43.377Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=btc_parse externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.377Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=float64 resultValue=0.06673 runInfo={"IsRetryable":false,"IsPending":false} taskName=btc_parse taskType=jsonparse
2022-05-24T20:32:43.377Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=btc_multiply externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.377Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=decimal.Decimal resultValue=6673 runInfo={"IsRetryable":false,"IsPending":false} taskName=btc_multiply taskType=multiply
2022-05-24T20:32:43.398Z [DEBUG] http adapter got 200 in 282.772522ms utils/http.go:67 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=usd taskType=http timeElapsedSeconds=0.282772522
2022-05-24T20:32:43.398Z [DEBUG] http adapter finished after 282.878765ms utils/http.go:76 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=usd taskType=http timeElapsedSeconds=0.282878765
2022-05-24T20:32:43.398Z [DEBUG] HTTP task got response pipeline/task.http.go:92 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dotID=usd externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest response={"USD":1956.94} taskName=usd taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=USD
2022-05-24T20:32:43.398Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=string resultValue={"USD":1956.94} runInfo={"IsRetryable":false,"IsPending":false} taskName=usd taskType=http
2022-05-24T20:32:43.398Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=usd_parse externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.398Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=float64 resultValue=1956.94 runInfo={"IsRetryable":false,"IsPending":false} taskName=usd_parse taskType=jsonparse
2022-05-24T20:32:43.398Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=usd_multiply externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.399Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=decimal.Decimal resultValue=195694000 runInfo={"IsRetryable":false,"IsPending":false} taskName=usd_multiply taskType=multiply
2022-05-24T20:32:43.404Z [DEBUG] http adapter got 200 in 289.62505ms utils/http.go:67 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=eur taskType=http timeElapsedSeconds=0.28962505
2022-05-24T20:32:43.405Z [DEBUG] http adapter finished after 289.765427ms utils/http.go:76 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=eur taskType=http timeElapsedSeconds=0.289765427
2022-05-24T20:32:43.405Z [DEBUG] HTTP task got response pipeline/task.http.go:92 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dotID=eur externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest response={"EUR":1823.8} taskName=eur taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=EUR
2022-05-24T20:32:43.405Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=string resultValue={"EUR":1823.8} runInfo={"IsRetryable":false,"IsPending":false} taskName=eur taskType=http
2022-05-24T20:32:43.405Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=eur_parse externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.405Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=float64 resultValue=1823.8 runInfo={"IsRetryable":false,"IsPending":false} taskName=eur_parse taskType=jsonparse
2022-05-24T20:32:43.405Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=eurs_multiply externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.405Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=decimal.Decimal resultValue=182380000 runInfo={"IsRetryable":false,"IsPending":false} taskName=eurs_multiply taskType=multiply
2022-05-24T20:32:43.405Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=encode_mwr externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.405Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=string resultValue=0x7790dca694e55d63c8c963fbb2e6b70b591e1d0690c4c70995935aea7ec730080000000000000000000000000000000000000000000000000000000000001a11000000000000000000000000000000000000000000000000000000000baa0db0000000000000000000000000000000000000000000000000000000000adee5e0 runInfo={"IsRetryable":false,"IsPending":false} taskName=encode_mwr taskType=ethabiencode
2022-05-24T20:32:43.406Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=encode_tx externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.406Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=string resultValue=0x6ae0bc767790dca694e55d63c8c963fbb2e6b70b591e1d0690c4c70995935aea7ec73008000000000000000000000000000000000000000000000000016345785d8a00000000000000000000000000001d3992d16fa39070468229db977c50b5e8d10c58fda4417b0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000628d421600000000000000000000000000000000000000000000000000000000000000c000000000000000000000000000000000000000000000000000000000000000807790dca694e55d63c8c963fbb2e6b70b591e1d0690c4c70995935aea7ec730080000000000000000000000000000000000000000000000000000000000001a11000000000000000000000000000000000000000000000000000000000baa0db0000000000000000000000000000000000000000000000000000000000adee5e0 runInfo={"IsRetryable":false,"IsPending":false} taskName=encode_tx taskType=ethabiencode
2022-05-24T20:32:43.406Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=submit_tx externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:32:43.425Z [DEBUG] Postgres event broadcaster: received notification pg/event_broadcaster.go:133 channel=insert_on_eth_txes logger=EventBroadcaster payload=550e1f4b209687f80f4072c1eb9d91ca23dabaa2
2022-05-24T20:32:43.425Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=<nil> runInfo={"IsRetryable":false,"IsPending":true} taskName=submit_tx taskType=ethtx
2022-05-24T20:32:45.094Z [ERROR] Timed out handling head bulletprooftxmanager/bulletprooftxmanager.go:252 blockNum=163 ctxErr=context deadline exceeded evmChainID=1337 logger=BulletproofTxManager stacktrace=github.com/smartcontractkit/chainlink/core/services/bulletprooftxmanager.(*BulletproofTxManager).OnNewLongestChain.func1
/chainlink/core/services/bulletprooftxmanager/bulletprooftxmanager.go:252
github.com/smartcontractkit/chainlink/core/utils.(*StartStopOnce).IfStarted
/chainlink/core/utils/utils.go:941
github.com/smartcontractkit/chainlink/core/services/bulletprooftxmanager.(*BulletproofTxManager).OnNewLongestChain
/chainlink/core/services/bulletprooftxmanager/bulletprooftxmanager.go:244
github.com/smartcontractkit/chainlink/core/services/headtracker.(*headBroadcaster).executeCallbacks.func1
/chainlink/core/services/headtracker/head_broadcaster.go:148
2022-05-24T20:32:45.095Z [DEBUG] Finished callback in 2.00075075s headtracker/head_broadcaster.go:150 blockNumber=163 callbackType=*bulletprooftxmanager.BulletproofTxManager evmChainID=1337 logger=HeadBroadcaster time=2.00075075
2022-05-24T20:42:01.887Z [DEBUG] Received new head #170 (0xaa) headtracker/head_tracker.go:327 blockHash=0x5b37fa53ccdb3f5d678912c43099351a96aa7fe6aa4cc60aed8892aaf2e0de1e blockHeight=170 evmChainID=1337 logger=head_tracker parentHeadHash=0xab7f8b1e809e45df407629bbdda26dae750ce943ceb8c465a63c55cfa1f9d9c1
2022-05-24T20:42:01.895Z [DEBUG] Received a log log/broadcaster.go:357 address=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 blockHash=0x5b37fa53ccdb3f5d678912c43099351a96aa7fe6aa4cc60aed8892aaf2e0de1e blockNumber=170 evmChainID=1337 logger=LogBroadcaster
2022-05-24T20:42:02.680Z [DEBUG] Initiating callbacks headtracker/head_broadcaster.go:134 evmChainID=1337 headNum=170 logger=HeadBroadcaster numCallbacks=4
2022-05-24T20:42:02.680Z [DEBUG] Finished callback in 4.863µs headtracker/head_broadcaster.go:150 blockNumber=170 callbackType=*services.promReporter evmChainID=1337 logger=HeadBroadcaster time=0.000004863
2022-05-24T20:42:02.680Z [DEBUG] BalanceMonitor: signalling balance worker services/balance_monitor.go:99 evmChainID=1337
2022-05-24T20:42:02.680Z [DEBUG] Finished callback in 9.767µs headtracker/head_broadcaster.go:150 blockNumber=170 callbackType=*log.broadcaster evmChainID=1337 logger=HeadBroadcaster time=0.000009767
2022-05-24T20:42:02.680Z [DEBUG] processHead bulletprooftxmanager/eth_confirmer.go:200 evmChainID=1337 headNum=170 id=eth_confirmer logger=BulletproofTxManager.EthConfirmer
2022-05-24T20:42:02.680Z [DEBUG] eth.Client#BalanceAt(...) eth/node.go:393 account=0x0eAB81866AF45BF7de799079491dB01B38826427 blockNumber=<nil> evmChainID=1337 logger=Node.primary-0-1337 mode=websocket nodeTier=primary
2022-05-24T20:42:02.680Z [DEBUG] Finished callback in 25.356µs headtracker/head_broadcaster.go:150 blockNumber=170 callbackType=*bulletprooftxmanager.BulletproofTxManager evmChainID=1337 logger=HeadBroadcaster time=0.000025356
2022-05-24T20:42:02.680Z [DEBUG] Finished callback in 99.44µs headtracker/head_broadcaster.go:150 blockNumber=170 callbackType=*services.balanceMonitor evmChainID=1337 logger=HeadBroadcaster time=0.00009944
2022-05-24T20:42:02.680Z [DEBUG] fetching 1 blocks (16 in local history) gas/block_history_estimator.go:403 blockNum=170 evmChainID=1337 inHistory=16 logger=BulletproofTxManager.BlockHistoryEstimator n=1
2022-05-24T20:42:02.681Z [DEBUG] Batch fetching blocks 169 thru 169 gas/block_history_estimator.go:462 evmChainID=1337 logger=BulletproofTxManager.BlockHistoryEstimator
2022-05-24T20:42:02.681Z [DEBUG] eth.Client#BatchCall(...) eth/node.go:218 evmChainID=1337 logger=Node.primary-0-1337 mode=websocket nBatchElems=1 nodeTier=primary
2022-05-24T20:42:02.680Z [DEBUG] Received head log/broadcaster.go:446 blockHash=0x5b37fa53ccdb3f5d678912c43099351a96aa7fe6aa4cc60aed8892aaf2e0de1e blockNumber=170 chainLen=57 evmChainID=1337 logger=LogBroadcaster parentHash=0xab7f8b1e809e45df407629bbdda26dae750ce943ceb8c465a63c55cfa1f9d9c1
2022-05-24T20:42:02.684Z [DEBUG] Finished CheckForReceipts bulletprooftxmanager/eth_confirmer.go:210 evmChainID=1337 headNum=170 id=eth_confirmer logger=BulletproofTxManager.EthConfirmer time=0.003549357
2022-05-24T20:42:02.689Z [DEBUG] Finished RebroadcastWhereNecessary bulletprooftxmanager/eth_confirmer.go:217 evmChainID=1337 headNum=170 id=eth_confirmer logger=BulletproofTxManager.EthConfirmer time=0.005503889
2022-05-24T20:42:02.693Z [DEBUG] LogBroadcaster: Sending out log log/registrations.go:312 address=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 blockHash=0x5b37fa53ccdb3f5d678912c43099351a96aa7fe6aa4cc60aed8892aaf2e0de1e blockNumber=170 evmChainID=1337 jobID=1 latestBlockNumber=170 logger=LogBroadcaster.Registrations
2022-05-24T20:42:02.693Z [DEBUG] Setting new default gas price: 20.00 Gwei gas/block_history_estimator.go:348 blocks=[154,155,156,157,158,159,160,161,162,163,164,165,166,167,168,169] evmChainID=1337 gasPriceGWei=20.00 gasPriceWei=20000000000 headNum=170 logger=BulletproofTxManager.BlockHistoryEstimator maxGasPriceWei=5000000000000
2022-05-24T20:42:02.695Z [INFO] Oracle request received directrequest/delegate.go:280 callbackAddr=0x4982F393c92cCa2dDcED4b00EBfCdCcB9EAcdB19 callbackFunctionId=fda4417b cancelExpiration=1653425221 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 data=6675726c425443783f68747470733a2f2f6d696e2d6170692e63727970746f636f6d706172652e636f6d2f646174612f70726963653f6673796d3d455448267473796d733d4254436770617468425443634254436675726c555344783f68747470733a2f2f6d696e2d6170692e63727970746f636f6d706172652e636f6d2f646174612f70726963653f6673796d3d455448267473796d733d5553446770617468555344635553446675726c455552783f68747470733a2f2f6d696e2d6170692e63727970746f636f6d706172652e636f6d2f646174612f70726963653f6673796d3d455448267473796d733d455552677061746845555263455552 dataVersion=1 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest payment=100000000000000000 requestId=ad6d4393721b5a74688b6e3753b7f2f5760dc7ba5fac119644bca8d7f22a731f requester=0x4982F393c92cCa2dDcED4b00EBfCdCcB9EAcdB19 specId=3433386339626532376166663463353862623766393633326163616134313866
2022-05-24T20:42:02.699Z [DEBUG] Initiating tasks for pipeline run of spec pipeline/runner.go:263 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f job ID=0 jobID=0 logger=DirectRequest.DirectRequest
2022-05-24T20:42:02.699Z [DEBUG] scheduling task run pipeline/scheduler.go:104 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=decode_log externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.700Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=map[string]interface {} resultValue={"callbackAddr":"0x4982f393c92cca2ddced4b00ebfcdccb9eacdb19","callbackFunctionId":[253,164,65,123],"cancelExpiration":1653425221,"data":"ZnVybEJUQ3g/aHR0cHM6Ly9taW4tYXBpLmNyeXB0b2NvbXBhcmUuY29tL2RhdGEvcHJpY2U/ZnN5bT1FVEgmdHN5bXM9QlRDZ3BhdGhCVENjQlRDZnVybFVTRHg/aHR0cHM6Ly9taW4tYXBpLmNyeXB0b2NvbXBhcmUuY29tL2RhdGEvcHJpY2U/ZnN5bT1FVEgmdHN5bXM9VVNEZ3BhdGhVU0RjVVNEZnVybEVVUng/aHR0cHM6Ly9taW4tYXBpLmNyeXB0b2NvbXBhcmUuY29tL2RhdGEvcHJpY2U/ZnN5bT1FVEgmdHN5bXM9RVVSZ3BhdGhFVVJjRVVS","dataVersion":1,"payment":100000000000000000,"requestId":[173,109,67,147,114,27,90,116,104,139,110,55,83,183,242,245,118,13,199,186,95,172,17,150,68,188,168,215,242,42,115,31],"requester":"0x4982f393c92cca2ddced4b00ebfcdccb9eacdb19","specId":[52,51,56,99,57,98,101,50,55,97,102,102,52,99,53,56,98,98,55,102,57,54,51,50,97,99,97,97,52,49,56,102]} runInfo={"IsRetryable":false,"IsPending":false} taskName=decode_log taskType=ethabidecodelog
2022-05-24T20:42:02.700Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=decode_cbor externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.700Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=map[string]interface {} resultValue={"pathBTC":"BTC","pathEUR":"EUR","pathUSD":"USD","urlBTC":"https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=BTC","urlEUR":"https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=EUR","urlUSD":"https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=USD"} runInfo={"IsRetryable":false,"IsPending":false} taskName=decode_cbor taskType=cborparse
2022-05-24T20:42:02.700Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=btc externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.700Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=usd externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.700Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=eur externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.700Z [DEBUG] HTTP task: sending request pipeline/task.http.go:77 allowUnrestrictedNetworkAccess=true attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest method=GET requestData=null taskName=eur taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=EUR
2022-05-24T20:42:02.700Z [DEBUG] HTTP task: sending request pipeline/task.http.go:77 allowUnrestrictedNetworkAccess=true attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest method=GET requestData=null taskName=btc taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=BTC
2022-05-24T20:42:02.700Z [DEBUG] HTTP task: sending request pipeline/task.http.go:77 allowUnrestrictedNetworkAccess=true attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest method=GET requestData=null taskName=usd taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=USD
2022-05-24T20:42:02.705Z [DEBUG] Finished EnsureConfirmedTransactionsInLongestChain bulletprooftxmanager/eth_confirmer.go:224 evmChainID=1337 headNum=170 id=eth_confirmer logger=BulletproofTxManager.EthConfirmer time=0.015867417
2022-05-24T20:42:02.707Z [DEBUG] Finished ResumePendingTaskRuns bulletprooftxmanager/eth_confirmer.go:232 evmChainID=1337 headNum=170 id=eth_confirmer logger=BulletproofTxManager.EthConfirmer time=0.001899083
2022-05-24T20:42:02.912Z [DEBUG] http adapter got 200 in 210.445862ms utils/http.go:67 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=btc taskType=http timeElapsedSeconds=0.210445862
2022-05-24T20:42:02.912Z [DEBUG] http adapter finished after 210.833955ms utils/http.go:76 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=btc taskType=http timeElapsedSeconds=0.210833955
2022-05-24T20:42:02.912Z [DEBUG] HTTP task got response pipeline/task.http.go:92 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dotID=btc externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest response={"BTC":0.06677} taskName=btc taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=BTC
2022-05-24T20:42:02.913Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=string resultValue={"BTC":0.06677} runInfo={"IsRetryable":false,"IsPending":false} taskName=btc taskType=http
2022-05-24T20:42:02.913Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=btc_parse externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.914Z [DEBUG] http adapter got 200 in 212.941507ms utils/http.go:67 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=eur taskType=http timeElapsedSeconds=0.212941507
2022-05-24T20:42:02.914Z [DEBUG] http adapter finished after 213.481089ms utils/http.go:76 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=eur taskType=http timeElapsedSeconds=0.213481089
2022-05-24T20:42:02.915Z [DEBUG] HTTP task got response pipeline/task.http.go:92 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dotID=eur externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest response={"EUR":1825.88} taskName=eur taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=EUR
2022-05-24T20:42:02.915Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=string resultValue={"EUR":1825.88} runInfo={"IsRetryable":false,"IsPending":false} taskName=eur taskType=http
2022-05-24T20:42:02.914Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=float64 resultValue=0.06677 runInfo={"IsRetryable":false,"IsPending":false} taskName=btc_parse taskType=jsonparse
2022-05-24T20:42:02.915Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=eur_parse externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.916Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=btc_multiply externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.916Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=decimal.Decimal resultValue=6677 runInfo={"IsRetryable":false,"IsPending":false} taskName=btc_multiply taskType=multiply
2022-05-24T20:42:02.917Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=float64 resultValue=1825.88 runInfo={"IsRetryable":false,"IsPending":false} taskName=eur_parse taskType=jsonparse
2022-05-24T20:42:02.917Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=eurs_multiply externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.918Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=decimal.Decimal resultValue=182588000 runInfo={"IsRetryable":false,"IsPending":false} taskName=eurs_multiply taskType=multiply
2022-05-24T20:42:02.990Z [DEBUG] http adapter got 200 in 288.694898ms utils/http.go:67 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=usd taskType=http timeElapsedSeconds=0.288694898
2022-05-24T20:42:02.991Z [DEBUG] http adapter finished after 289.11744ms utils/http.go:76 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.HTTPRequest statusCode=200 taskName=usd taskType=http timeElapsedSeconds=0.28911744
2022-05-24T20:42:02.991Z [DEBUG] HTTP task got response pipeline/task.http.go:92 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dotID=usd externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest response={"USD":1959.93} taskName=usd taskType=http url=https://min-api.cryptocompare.com/data/price?fsym=ETH&tsyms=USD
2022-05-24T20:42:02.991Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=string resultValue={"USD":1959.93} runInfo={"IsRetryable":false,"IsPending":false} taskName=usd taskType=http
2022-05-24T20:42:02.991Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=usd_parse externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.992Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=float64 resultValue=1959.93 runInfo={"IsRetryable":false,"IsPending":false} taskName=usd_parse taskType=jsonparse
2022-05-24T20:42:02.992Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=usd_multiply externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.992Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=decimal.Decimal resultValue=195993000 runInfo={"IsRetryable":false,"IsPending":false} taskName=usd_multiply taskType=multiply
2022-05-24T20:42:02.992Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=encode_mwr externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.993Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=string resultValue=0xad6d4393721b5a74688b6e3753b7f2f5760dc7ba5fac119644bca8d7f22a731f0000000000000000000000000000000000000000000000000000000000001a15000000000000000000000000000000000000000000000000000000000bae9da8000000000000000000000000000000000000000000000000000000000ae21260 runInfo={"IsRetryable":false,"IsPending":false} taskName=encode_mwr taskType=ethabiencode
2022-05-24T20:42:02.993Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=encode_tx externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:02.993Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=string resultValue=0x6ae0bc76ad6d4393721b5a74688b6e3753b7f2f5760dc7ba5fac119644bca8d7f22a731f000000000000000000000000000000000000000000000000016345785d8a00000000000000000000000000004982f393c92cca2ddced4b00ebfcdccb9eacdb19fda4417b0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000628d444500000000000000000000000000000000000000000000000000000000000000c00000000000000000000000000000000000000000000000000000000000000080ad6d4393721b5a74688b6e3753b7f2f5760dc7ba5fac119644bca8d7f22a731f0000000000000000000000000000000000000000000000000000000000001a15000000000000000000000000000000000000000000000000000000000bae9da8000000000000000000000000000000000000000000000000000000000ae21260 runInfo={"IsRetryable":false,"IsPending":false} taskName=encode_tx taskType=ethabiencode
2022-05-24T20:42:02.993Z [DEBUG] scheduling task run pipeline/scheduler.go:256 attempts=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 dot_id=submit_tx externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest.Scheduler
2022-05-24T20:42:03.032Z [DEBUG] Postgres event broadcaster: received notification pg/event_broadcaster.go:133 channel=insert_on_eth_txes logger=EventBroadcaster payload=0eab81866af45bf7de799079491db01b38826427
2022-05-24T20:42:03.032Z [DEBUG] Pipeline task completed pipeline/runner.go:410 attempt=0 contract=0x0f77366B2e7342Bf05772bc286B75Ccc72c81303 externalJobID=438c9be2-7aff-4c58-bb7f-9632acaa418f jobID=0 logger=DirectRequest.DirectRequest resultType=<nil> runInfo={"IsRetryable":false,"IsPending":true} taskName=submit_tx taskType=ethtx
2022-05-24T20:42:03.043Z [DEBUG] eth.Client#SendTransaction(...) eth/node.go:268 evmChainID=1337 logger=Node.primary-0-1337 mode=websocket nodeTier=primary tx={"type":"0x0","nonce":"0x1","gasPrice":"0x4a817c800","maxPriorityFeePerGas":null,"maxFeePerGas":null,"gas":"0x7a120","value":"0x0","input":"0x6ae0bc76ad6d4393721b5a74688b6e3753b7f2f5760dc7ba5fac119644bca8d7f22a731f000000000000000000000000000000000000000000000000016345785d8a00000000000000000000000000004982f393c92cca2ddced4b00ebfcdccb9eacdb19fda4417b0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000628d444500000000000000000000000000000000000000000000000000000000000000c00000000000000000000000000000000000000000000000000000000000000080ad6d4393721b5a74688b6e3753b7f2f5760dc7ba5fac119644bca8d7f22a731f0000000000000000000000000000000000000000000000000000000000001a15000000000000000000000000000000000000000000000000000000000bae9da8000000000000000000000000000000000000000000000000000000000ae21260","v":"0xa95","r":"0xe64084c2d557080ff7e55fc59a581a7411135a417657f12c3b40ca5320cb29bf","s":"0x7316fa01d928f6690383c20dd09d655a406f8043335c1d5a35df97237b94ee84","to":"0x0f77366b2e7342bf05772bc286b75ccc72c81303","hash":"0xd4a6127409596471c97d2f2bb459b93fd428a85448f93c9d437de10e572ee624"}
2022-05-24T20:42:03.158Z [DEBUG] Received new head #171 (0xab) headtracker/head_tracker.go:327 blockHash=0xa7051659e06881df8d835791e833294561a6c3ad013c23f4f82e4c28e8cf6d39 blockHeight=171 evmChainID=1337 logger=head_tracker parentHeadHash=0x5b37fa53ccdb3f5d678912c43099351a96aa7fe6aa4cc60aed8892aaf2e0de1e
2022-05-24T20:42:03.158Z [DEBUG] Sent transaction bulletprooftxmanager/bulletprooftxmanager.go:424 attempt={"ID":2,"EthTxID":2,"EthTx":{"ID":2,"Nonce":1,"FromAddress":"0x0eab81866af45bf7de799079491db01b38826427","ToAddress":"0x0f77366b2e7342bf05772bc286b75ccc72c81303","EncodedPayload":"auC8dq1tQ5NyG1p0aItuN1O38vV2Dce6X6wRlkS8qNfyKnMfAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAWNFeF2KAAAAAAAAAAAAAAAAAABJgvOTySzKLdztSwDr/NzLnqzbGf2kQXsAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAGKNREUAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAACArW1Dk3IbWnRoi243U7fy9XYNx7pfrBGWRLyo1/Iqcx8AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAaFQAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAALrp2oAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAriEmA=","Value":"0","GasLimit":500000,"Error":null,"BroadcastAt":null,"CreatedAt":"2022-05-24T20:42:02.995481Z","State":"in_progress","Meta":{"JobID":0,"SubId":0,"MaxLink":"","RequestID":"0x0000000000000000000000000000000000000000000000000000000000000000","RequestTxHash":"0x0000000000000000000000000000000000000000000000000000000000000000"},"Subject":{"UUID":"00000000-0000-0000-0000-000000000000","Valid":false},"EVMChainID":"1337","PipelineTaskRunID":{"UUID":"bc37b560-6056-4cf1-95ae-5677d3060174","Valid":true},"MinConfirmations":12,"AccessList":null,"Simulate":false},"GasPrice":"20000000000","GasTipCap":null,"GasFeeCap":null,"ChainSpecificGasLimit":500000,"SignedRawTx":"+QHNAYUEqBfIAIMHoSCUD3c2ay5zQr8FdyvChrdczHLIEwOAuQFkauC8dq1tQ5NyG1p0aItuN1O38vV2Dce6X6wRlkS8qNfyKnMfAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAWNFeF2KAAAAAAAAAAAAAAAAAABJgvOTySzKLdztSwDr/NzLnqzbGf2kQXsAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAGKNREUAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAACArW1Dk3IbWnRoi243U7fy9XYNx7pfrBGWRLyo1/Iqcx8AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAaFQAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAALrp2oAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAriEmCCCpWg5kCEwtVXCA/35V/FmlgadBETWkF2V/EsO0DKUyDLKb+gcxb6Adko9mkDg8IN0J1lWkBvgEMzXB1aNd+XI3uU7oQ=","Hash":"0xd4a6127409596471c97d2f2bb459b93fd428a85448f93c9d437de10e572ee624","CreatedAt":"2022-05-24T20:42:03.037917Z","BroadcastBeforeBlockNum":null,"State":"in_progress","TxType":0} ethTxAttemptID=2 evmChainID=1337 gasLimit=500000 logger=BulletproofTxManager.EthBroadcaster meta={"JobID": 0, "SubId": 0, "MaxLink": "", "RequestID": "0x0000000000000000000000000000000000000000000000000000000000000000", "RequestTxHash": "0x0000000000000000000000000000000000000000000000000000000000000000"} txHash=0xd4a6127409596471c97d2f2bb459b93fd428a85448f93c9d437de10e572ee624
2022-05-24T20:42:03.179Z [DEBUG] Finished processUnstartedEthTxs bulletprooftxmanager/eth_broadcaster.go:227 address=0x0eAB81866AF45BF7de799079491dB01B38826427 evmChainID=1337 id=eth_broadcaster logger=BulletproofTxManager.EthBroadcaster n=1 time=0.146440069
2022-05-24T20:42:03.680Z [DEBUG] Initiating callbacks headtracker/head_broadcaster.go:134 evmChainID=1337 headNum=171 logger=HeadBroadcaster numCallbacks=4
2022-05-24T20:42:03.680Z [DEBUG] BalanceMonitor: signalling balance worker services/balance_monitor.go:99 evmChainID=1337
2022-05-24T20:42:03.680Z [DEBUG] Finished callback in 19.242µs headtracker/head_broadcaster.go:150 blockNumber=171 callbackType=*services.promReporter evmChainID=1337 logger=HeadBroadcaster time=0.000019242
2022-05-24T20:42:03.680Z [DEBUG] Finished callback in 158.798µs headtracker/head_broadcaster.go:150 blockNumber=171 callbackType=*services.balanceMonitor evmChainID=1337 logger=HeadBroadcaster time=0.000158798
2022-05-24T20:42:03.680Z [DEBUG] Finished callback in 12.482µs headtracker/head_broadcaster.go:150 blockNumber=171 callbackType=*log.broadcaster evmChainID=1337 logger=HeadBroadcaster time=0.000012482
2022-05-24T20:42:03.680Z [DEBUG] Finished callback in 64.874µs headtracker/head_broadcaster.go:150 blockNumber=171 callbackType=*bulletprooftxmanager.BulletproofTxManager evmChainID=1337 logger=HeadBroadcaster time=0.000064874
2022-05-24T20:42:03.680Z [DEBUG] eth.Client#BalanceAt(...) eth/node.go:393 account=0x0eAB81866AF45BF7de799079491dB01B38826427 blockNumber=<nil> evmChainID=1337 logger=Node.primary-0-1337 mode=websocket nodeTier=primary
2022-05-24T20:42:03.680Z [DEBUG] Received head log/broadcaster.go:446 blockHash=0xa7051659e06881df8d835791e833294561a6c3ad013c23f4f82e4c28e8cf6d39 blockNumber=171 chainLen=58 evmChainID=1337 logger=LogBroadcaster parentHash=0x5b37fa53ccdb3f5d678912c43099351a96aa7fe6aa4cc60aed8892aaf2e0de1e
2022-05-24T20:42:03.680Z [DEBUG] processHead bulletprooftxmanager/eth_confirmer.go:200 evmChainID=1337 headNum=171 id=eth_confirmer logger=BulletproofTxManager.EthConfirmer
2022-05-24T20:42:03.680Z [DEBUG] fetching 1 blocks (16 in local history) gas/block_history_estimator.go:403 blockNum=171 evmChainID=1337 inHistory=16 logger=BulletproofTxManager.BlockHistoryEstimator n=1
2022-05-24T20:42:03.682Z [DEBUG] Batch fetching blocks 170 thru 170 gas/block_history_estimator.go:462 evmChainID=1337 logger=BulletproofTxManager.BlockHistoryEstimator
2022-05-24T20:42:03.682Z [DEBUG] eth.Client#BatchCall(...) eth/node.go:218 evmChainID=1337 logger=Node.primary-0-1337 mode=websocket nBatchElems=1 nodeTier=primary
2022-05-24T20:42:03.690Z [INFO] New ETH balance for 0x0eAB81866AF45BF7de799079491dB01B38826427: 1.996501480000000000 services/balance_monitor.go:122 address=0x0eAB81866AF45BF7de799079491dB01B38826427 ethBalance=1.996501480000000000 evmChainID=1337 logger=balance_log weiBalance=1996501480000000000
2022-05-24T20:42:03.709Z [DEBUG] Setting new default gas price: 20.00 Gwei gas/block_history_estimator.go:348 blocks=[155,156,157,158,159,160,161,162,163,164,165,166,167,168,169,170] evmChainID=1337 gasPriceGWei=20.00 gasPriceWei=20000000000 headNum=171 logger=BulletproofTxManager.BlockHistoryEstimator maxGasPriceWei=5000000000000
2022-05-24T20:42:03.719Z [DEBUG] Fetching receipts for 1 transaction attempts bulletprooftxmanager/eth_confirmer.go:263 blockNum=171 evmChainID=1337 logger=BulletproofTxManager.EthConfirmer
2022-05-24T20:42:03.719Z [DEBUG] eth.Client#NonceAt(...) eth/node.go:294 account=0x0eAB81866AF45BF7de799079491dB01B38826427 blockNumber=<nil> evmChainID=1337 logger=Node.primary-0-1337 mode=websocket nodeTier=primary
2022-05-24T20:42:03.726Z [DEBUG] There are 1 attempts from address 0x0eAB81866AF45BF7de799079491dB01B38826427, latest nonce for it is 2 and for the attempts' nonces: first = 1, last = 1 bulletprooftxmanager/eth_confirmer.go:317 evmChainID=1337 firstAttemptNonce=1 fromAddress=0x0eAB81866AF45BF7de799079491dB01B38826427 lastAttemptNonce=1 latestBlockNonce=2 logger=BulletproofTxManager.EthConfirmer nAttempts=1
2022-05-24T20:42:03.726Z [DEBUG] Fetching and saving 1 likely confirmed receipts. Skipping checking the others (0) bulletprooftxmanager/eth_confirmer.go:287 evmChainID=1337 logger=BulletproofTxManager.EthConfirmer
2022-05-24T20:42:03.727Z [DEBUG] Batch fetching receipts at indexes 0 until (excluded) 1 bulletprooftxmanager/eth_confirmer.go:349 blockNum=171 evmChainID=1337 logger=BulletproofTxManager.EthConfirmer
2022-05-24T20:42:03.727Z [DEBUG] eth.Client#BatchCall(...) eth/node.go:218 evmChainID=1337 logger=Node.primary-0-1337 mode=websocket nBatchElems=1 nodeTier=primary
2022-05-24T20:42:03.762Z [DEBUG] Got receipt for transaction bulletprooftxmanager/eth_confirmer.go:446 blockHash=0xa7051659e06881df8d835791e833294561a6c3ad013c23f4f82e4c28e8cf6d39 blockNumber=171 ethTxAttemptID=2 ethTxID=2 evmChainID=1337 gasUsed=87457 logger=BulletproofTxManager.EthConfirmer.batchFetchReceipts status=1 transactionIndex=0 txHash=0xd4a6127409596471c97d2f2bb459b93fd428a85448f93c9d437de10e572ee624
2022-05-24T20:42:03.774Z [DEBUG] Fetching and saving 1 likely confirmed receipts done bulletprooftxmanager/eth_confirmer.go:295 evmChainID=1337 logger=BulletproofTxManager.EthConfirmer time=0.047339773
2022-05-24T20:42:03.781Z [DEBUG] Finished CheckForReceipts bulletprooftxmanager/eth_confirmer.go:210 evmChainID=1337 headNum=171 id=eth_confirmer logger=BulletproofTxManager.EthConfirmer time=0.100296324
2022-05-24T20:42:03.800Z [DEBUG] Finished RebroadcastWhereNecessary bulletprooftxmanager/eth_confirmer.go:217 evmChainID=1337 headNum=171 id=eth_confirmer logger=BulletproofTxManager.EthConfirmer time=0.019738442
2022-05-24T20:42:03.804Z [DEBUG] Finished EnsureConfirmedTransactionsInLongestChain bulletprooftxmanager/eth_confirmer.go:224 evmChainID=1337 headNum=171 id=eth_confirmer logger=BulletproofTxManager.EthConfirmer time=0.003631405
2022-05-24T20:42:03.805Z [DEBUG] Finished ResumePendingTaskRuns bulletprooftxmanager/eth_confirmer.go:232 evmChainID=1337 headNum=171 id=eth_confirmer logger=BulletproofTxManager.EthConfirmer time=0.001331887
[NODE] Can’t create multi-variable response
Description
On version 1.4.0-root, 1.4.1-root (maybe 1.3.0 too), job pipeline tasks successful completes, but submit_tx step (ethtx task) don't send transaction to Operator contract. After downgrade to version 1.1.1, submit_tx sends transaction correctly!!!
Digging deep
Result of encode_tx step (ethabiencode task) and all previous steps in both Node version equals.
Temporary solve
Downgrade chainlink node to version 1.1.1
Steps to reproduce
Environment
Docker version 20.10.16, build aa7e414 docker-compose version 1.29.2, build unknown
Compose spec
./services/chainlink-node/.env.local
./services/db-chainlink-node/.env
./.env.local
./services/chainlink-node/.password:/chainlink/.password
./services/chainlink-node/.api:/chainlink/.api
multi_word_job.toml
This file equals to multi-variable job example from Chainlink official docs
MultiWordConsumer.sol
This file so close (only constructor modified) to multi-variable response example contract from Chainlink official docs