Error trying to call reward: context deadline exceeded
arthurk opened this issue · 7 comments
I get an Error trying to call reward: context deadline exceeded error message when I try to call reward. Read operations such as 1. Get node status, 2. Protocol Parameters, 3. List Registered Transcoders work fine. The problem is sending the reward transaction.
The transcoder node is connected to a local geth instance as described in this forum post: https://forum.livepeer.org/t/transcoder-tip-geth-light-client/247/7. Its running fine and showing that it has successfully imported the latest block headers:
INFO [06-05|17:36:09] Imported new block headers count=1 elapsed=4.677ms number=5737629 hash=e1eb1f…adf248 ignored=0
INFO [06-05|17:36:18] Imported new block headers count=1 elapsed=4.874ms number=5737630 hash=bf4d43…a21a3b ignored=0
INFO [06-05|17:36:18] Imported new block headers count=0 elapsed=67.166µs number=5737630 hash=bf4d43…a21a3b ignored=1
INFO [06-05|17:36:20] Imported new block headers count=1 elapsed=4.805ms number=5737631 hash=6e9876…2a75cb ignored=0
INFO [06-05|17:36:30] Imported new block headers count=1 elapsed=4.635ms number=5737632 hash=faadda…94fbae ignored=0
INFO [06-05|17:36:30] Imported new block headers count=0 elapsed=51.068µs number=5737632 hash=faadda…94fbae ignored=1
INFO [06-05|17:36:35] Imported new block headers count=1 elapsed=4.609ms number=5737633 hash=6fb31f…c1133d ignored=0
Here are the livepeer logs. It seems that the node is stuck after importing block 5737237 and is no longer printing the Setting LastSeenBlock to info message:
I0605 15:47:39.833128 17652 db.go:314] db: Setting LastSeenBlock to 5737215
I0605 15:47:44.491743 17652 db.go:314] db: Setting LastSeenBlock to 5737216
I0605 15:47:58.646088 17652 db.go:314] db: Setting LastSeenBlock to 5737217
I0605 15:48:01.400158 17652 db.go:314] db: Setting LastSeenBlock to 5737218
E0605 15:48:13.334104 17652 rewardservice.go:47] Error trying to call reward: context deadline exceeded
I0605 15:48:17.173136 17652 db.go:314] db: Setting LastSeenBlock to 5737219
I0605 15:48:24.221390 17652 db.go:314] db: Setting LastSeenBlock to 5737220
I0605 15:48:45.766915 17652 db.go:314] db: Setting LastSeenBlock to 5737221
I0605 15:49:03.988615 17652 db.go:314] db: Setting LastSeenBlock to 5737222
I0605 15:49:11.698493 17652 db.go:314] db: Setting LastSeenBlock to 5737223
I0605 15:49:16.916702 17652 db.go:314] db: Setting LastSeenBlock to 5737224
I0605 15:49:37.018876 17652 db.go:314] db: Setting LastSeenBlock to 5737225
I0605 15:49:51.409126 17652 db.go:314] db: Setting LastSeenBlock to 5737226
I0605 15:50:10.120793 17652 db.go:314] db: Setting LastSeenBlock to 5737227
I0605 15:50:18.080567 17652 db.go:314] db: Setting LastSeenBlock to 5737228
I0605 15:50:29.788452 17652 db.go:314] db: Setting LastSeenBlock to 5737229
I0605 15:50:53.635186 17652 db.go:314] db: Setting LastSeenBlock to 5737230
I0605 15:51:01.923819 17652 db.go:314] db: Setting LastSeenBlock to 5737231
I0605 15:51:06.497997 17652 db.go:314] db: Setting LastSeenBlock to 5737232
I0605 15:51:20.046918 17652 db.go:314] db: Setting LastSeenBlock to 5737233
I0605 15:51:25.643550 17652 db.go:314] db: Setting LastSeenBlock to 5737234
I0605 15:51:33.091698 17652 db.go:314] db: Setting LastSeenBlock to 5737235
I0605 15:51:53.554984 17652 db.go:314] db: Setting LastSeenBlock to 5737236
I0605 15:51:55.990390 17652 db.go:314] db: Setting LastSeenBlock to 5737237
I0605 15:52:02.147114 17652 webserver.go:1030] Calling reward
I0605 15:52:03.487191 17652 base.go:209]
******************************Eth Transaction******************************
Invoking transaction: "reward". Params: []
Transaction Failed: insufficient funds for gas * price + value
***************************************************************************
E0605 15:52:03.487219 17652 webserver.go:1033] Error calling reward: insufficient funds for gas * price + value
I0605 16:08:04.728942 17652 base.go:209]
******************************Eth Transaction******************************
Invoking transaction: "reward". Params: []
Transaction Failed: insufficient funds for gas * price + value
***************************************************************************
E0605 16:08:04.728968 17652 rewardservice.go:47] Error trying to call reward: insufficient funds for gas * price + value
I0605 16:38:04.212724 17652 base.go:207]
******************************Eth Transaction******************************
Invoking transaction: "reward". Hash: "0xe6888fab934b6647b9597d6e5cbdf92812d18e6ae25630f2da87cfce45b476f3". Params: []
***************************************************************************
E0605 16:48:04.212843 17652 rewardservice.go:47] Error trying to call reward: context deadline exceeded
I0605 16:48:51.656669 17652 webserver.go:1030] Calling reward
I0605 16:48:52.759703 17652 base.go:207]
******************************Eth Transaction******************************
Invoking transaction: "reward". Hash: "0x49d8134602916d513f9dda71e689d9fd88f5d4c6a11756774344115fcc888423". Params: []
***************************************************************************
E0605 16:58:52.759854 17652 webserver.go:1037] Error calling reward: context deadline exceeded
I0605 17:08:05.344791 17652 base.go:207]
******************************Eth Transaction******************************
Invoking transaction: "reward". Hash: "0x962b1733bbf368871947a27230a500d24a1a7cde8a6adc833a5820003265a63d". Params: []
***************************************************************************
E0605 17:18:05.345003 17652 rewardservice.go:47] Error trying to call reward: context deadline exceeded
I0605 17:29:06.530479 17652 webserver.go:1030] Calling reward
I0605 17:29:07.638823 17652 base.go:207]
******************************Eth Transaction******************************
Invoking transaction: "reward". Hash: "0x0cc26ecf9c993fce22b2b64175ecd7069fe18753be62ac6a3e8fadf9cd03f382". Params: []
***************************************************************************
After the Error calling reward: insufficient funds for gas message appeared some ether was transferred to cover the gas cost.
The full timeline of transactions leading up to the error is the following:
12:16:36: approve call -> OK
12:23:27: bond call -> OK
15:52:02: Reward call fails with insufficient gas error
16:21:13: Transferred 0.02 ether to the node address
16:38:04: Error trying to call reward: context deadline exceeded
After that point the reward call didn't work anymore and only shows Error trying to call reward: context deadline exceeded error. This means the error happened somewhere after the insufficient funds for gas error message appeared.
Hi @arthurk, there are a few potential issues.
- The local Geth node is not synced to the latest node, or the transaction is not making it into the transaction pool
- A previous transaction is waiting to be confirmed. Since Eth transactions are ordered by their nonces, they have to be confirmed in order also. We are working on a way to replay previous transactions so this doesn't happen in the future. (#446)
For the short term, my suggestion is to restart Geth and Livepeer on your machine and see if the transactions show up on etherscan. If not, manually trigger "reward".
Hey Eric,
- The geth node is synced to the latest node and continuously shows every few seconds that it successfully imported the latest block. I'll make sure to test sending a tx via geth console and see if it works.
- There is also no previous transaction (I checked via etherscan)
I've been manually invoking reward for all the transactions shown in the log. For now the only solution is to restart the livepeer node.
Just wanted to say that this happened again today. Pattern was the same: Once it hit the "Insufficient gas" error and I tried to call the reward the transcoder node stopped working completely
@arthurk Are you using the latest release (v0.2.4)? Did you once again see a context deadline exceeded error first followed by the insufficient gas errors?
Bump. @arthurk If this issue is still giving you trouble, please follow up with the node version you are using, log messages outputted by the node and any other details you think might be relevant! If not, I'll close this issue at the end of the week.