go icon indicating copy to clipboard operation
go copied to clipboard

Horizon: context deadline exceeded

Open DreamHackchosenone opened this issue 3 years ago • 10 comments

How to reslove this error?

time="2022-05-30T11:46:22.683Z" level=error msg="failed to load the stellar-core info" err="http request errored: Get \"http://localhost:11626/info\": context deadline exceeded" pid=232692 stack="[main.go:43 client.go:67 app.go:228 app.go:440 asm_amd64.s:1581]"
time="2022-05-30T11:46:22.683Z" level=warning msg="error ticking app: context deadline exceeded" pid=232692
time="2022-05-30T11:46:24.542Z" level=info msg="Batch added to StateVerifier" pid=232692 sequence=41100479 service=ingest subservice=state_verify total=34050000```

Horizon 2.17.0
Ubuntu 20.04.3

DreamHackchosenone avatar May 31 '22 02:05 DreamHackchosenone

renice -15 $( pidof stellar-core ) renice -13 $( pidof horizon )

helps it for me

dpblnt avatar May 31 '22 10:05 dpblnt

Can you share more logs? Stellar-Core can become unresponsive when Horizon ingests state. In this case it's normal.

bartekn avatar May 31 '22 13:05 bartekn

Can you share more logs? Stellar-Core can become unresponsive when Horizon ingests state. In this case it's normal.

I'm sorry I can not, I run that node without logging. I just remember I had this issue on a synced horizon, and renice helped it on the fly. I observed this during heavy disk IO. In those cases even curl-ing stellar-core/info timed out. But I noticed that renice puts them before postresql's disk IO hungry processes. I'm afraid I could not reproduce this anyways, since I enabled filtering disk IO dropped from 101% to less then 10%.

dpblnt avatar May 31 '22 17:05 dpblnt

Can you share more logs? Stellar-Core can become unresponsive when Horizon ingests state. In this case it's normal.

These are duplicate logs How to avoid this situation?

DreamHackchosenone avatar Jun 01 '22 02:06 DreamHackchosenone

renice -15 $( pidof stellar-core ) renice -13 $( pidof horizon )

helps it for me

How it works? can you give me ref doc?

DreamHackchosenone avatar Jun 01 '22 02:06 DreamHackchosenone

renice -15 $( pidof stellar-core ) renice -13 $( pidof horizon ) helps it for me

How it works? can you give me ref doc?

Just paste it into the shell, on the linux running horizon. read man nice and man renice -- also linux commands It tells the linux kernel how to prioritize. This is not the solution, but it might ease load on your machine.

dpblnt avatar Jun 01 '22 06:06 dpblnt

renice -13

Thanks, i will try

DreamHackchosenone avatar Jun 01 '22 06:06 DreamHackchosenone

renice -15 $( pidof stellar-core ) renice -13 $( pidof horizon ) helps it for me

How it works? can you give me ref doc?

Just paste it into the shell, on the linux running horizon. read man nice and man renice -- also linux commands It tells the linux kernel how to prioritize. This is not the solution, but it might ease load on your machine.

Not work, still get same error

DreamHackchosenone avatar Jun 02 '22 01:06 DreamHackchosenone

here is one log from me, with LOG_LEVEL=warn got "ERROR read timeout reached" on client side (not horizon error code)

WARN[2022-06-02T16:26:03.439+03:00] Herder: surge pricing in effect! 1051 > 1000 pid=5468 service=ingest subservice=stellar-core ERRO[2022-06-02T16:26:30.882+03:00] failed to load the latest known ledger state from history DB err="canceling statement due to lack of response within timeout period" pid=5468 stack="[main.go:36 main.go:36 proc.go:6498 proc.go:6475 proc.go:6475 proc.go:6475 proc.go:238 asm_amd64.s:1581]" ERRO[2022-06-02T16:26:30.881+03:00] failed to load the latest known ledger's base fee and sequence number err="canceling statement due to lack of response within timeout period" pid=5468 stack="[main.go:36 main.go:36 proc.go:6498 proc.go:6475 proc.go:6475 proc.go:6475 proc.go:238 asm_amd64.s:1581]" ERRO[2022-06-02T16:27:35.178+03:00] error getting transactions by hashes error="canceling statement due to lack of response within timeout period" pid=5468 WARN[2022-06-02T16:27:35.180+03:00] error ticking app: context deadline exceeded pid=5468 WARN[2022-06-02T16:28:18.179+03:00] Herder: surge pricing in effect! 1032 > 1000 pid=5468 service=ingest subservice=stellar-core

stellar-core "startedOn" : "2022-05-22T17:35:34Z", "state" : "Synced!" "build" : "v19.0.1", horizon version 5fa51492e3053aaf74ed5f0b57758f7f07a6aed7

dpblnt avatar Jun 02 '22 13:06 dpblnt

and another one 2 minutes later

WARN[2022-06-02T16:30:49.822+03:00] could not load stellar-core info: http request errored: Get "http://localhost:11626/info": context deadline exceeded pid=5468 ERRO[2022-06-02T16:30:49.823+03:00] failed to load the stellar-core info err="http request errored: Get "http://localhost:11626/info": context deadline exceeded" pid=5468 stack="[main.go:43 client.go:67 app.go:228 app.go:440 asm_amd64.s:1581]" ERRO[2022-06-02T16:30:49.824+03:00] error getting transactions by hashes error="canceling statement due to lack of response within timeout period" pid=5468 WARN[2022-06-02T16:30:49.824+03:00] error ticking app: context deadline exceeded pid=5468 WARN[2022-06-02T16:31:01.687+03:00] Herder: surge pricing in effect! 1013 > 1000 pid=5468 service=ingest subservice=stellar-core

dpblnt avatar Jun 02 '22 13:06 dpblnt