services/horizon: reduce repetitive log output related to obtaining core status info

[sreuland]

What version are you using?

2.15.1

What did you do?

ran Horizon with ingest enabled, analyzing historical ingestion log output later

What did you expect to see?

sensible stream of log statements

What did you see instead?

when debugging prior issues on staging, noticed the logs tended to be full of repetitiion of these types of outputs:

time="2022-03-03T17:45:36.920Z" level=warning msg="could not load stellar-core info: http request errored: Get \"http://127.0.0.1:11626/info\": context deadline exceeded" pid=1443500

time="2022-03-03T17:45:36.920Z" level=error msg="failed to load the stellar-core info" err="http request errored: Get \"http://127.0.0.1:11626/info\": context deadline exceeded" pid=1443500 stack="[main.go:43 client.go:67 app.go:223 app.go:435 asm_amd64.s:1581]"

time="2022-03-03T17:45:38.085Z" level=error msg="Cannot connect to Captive Stellar-Core HTTP server" error="http request errored: Get \"http://localhost:11626/info\": context deadline exceeded (Client.Timeout exceeded while awaiting headers)" pid=1443500 service=ingest

[Droppix]

Jun 20 19:16:11 horizon-basic stellar-horizon[36844]: time="2022-06-20T19:16:11.657Z" level=warning msg="error ticking app: context deadline exceeded" pid=36844
Jun 20 19:16:13 horizon-basic stellar-horizon[36844]: time="2022-06-20T19:16:13.790Z" level=info msg="Processing ledger entry changes" pid=36844 processed_entries=2900000 progress="10.>
Jun 20 19:16:14 horizon-basic stellar-horizon[36844]: time="2022-06-20T19:16:14.051Z" level=info msg="Processing ledger entry changes" pid=36844 processed_entries=2950000 progress="10.>
Jun 20 19:16:16 horizon-basic stellar-horizon[36844]: time="2022-06-20T19:16:16.658Z" level=warning msg="could not load stellar-core info: http request errored: Get "http://127.0.0.1:>
Jun 20 19:16:16 horizon-basic stellar-horizon[36844]: time="2022-06-20T19:16:16.658Z" level=error msg="failed to load the stellar-core info" err="http request errored: Get "http://127>
Jun 20 19:16:16 horizon-basic stellar-horizon[36844]: time="2022-06-20T19:16:16.659Z" level=warning msg="error ticking app: context deadline exceeded" pid=36844
Jun 20 19:16:21 horizon-basic stellar-horizon[36844]: time="2022-06-20T19:16:21.343Z" level=info msg="Processing ledger entry changes" pid=36844 processed_entries=3000000 progress="10.>
Jun 20 19:16:21 horizon-basic stellar-horizon[36844]: time="2022-06-20T19:16:21.660Z" level=warning msg="could not load stellar-core info: http request errored: Get "http://127.0.0.1:>
Jun 20 19:16:21 horizon-basic stellar-horizon[36844]: time="2022-06-20T19:16:21.660Z" level=error msg="failed to load the stellar-core info" err="http request errored: Get "http://127>

[hasharmujahid]

I am facing the same error " level=warning msg="could not load stellar-core info: http request errored: Get "http://127.0.0.1:11626/info\": context deadline exceeded" pid=6685
Jul 25 06:35:58 horizon stellar-horizon[6685]: time="2023-07-25T06:35:58.377Z" level=error msg="failed to load the stellar-core info" err="http request errored: Get "http://127.0.0.1:11626/info\": context deadline exceede"

[sreuland]

I think on latest Horizon 2.26.0 release, this repetitive log output has been reduced per #4860.

@urvisavla , do you think #4860 resolves/obsoletes this ticket now?

[urvisavla]

I think on latest Horizon 2.26.0 release, this repetitive log output has been reduced per #4860.

@urvisavla , do you think #4860 resolves/obsoletes this ticket now?

We are handling the case when the STELLAR_CORE_URL is set to "localhost" which explains why the errors are still being logged since the URL specified here is 127.0.0.1. I will update the fix to handle both "localhost" and "127.0.0.1" and once that is done, we can close this issue.