roman-struchev / tinkoff-invest

Торговый робот для Тинкофф Инвестиций. Разработан в рамках Tinkoff Invest Robot Contest
http://invest.struchev.site
Apache License 2.0
50 stars 20 forks source link

[elegram.org/...] global : Update listener failure #3

Closed shizlkazizl closed 2 years ago

shizlkazizl commented 2 years ago

Привет!

invest-app | 2022-07-23 12:01:45.057 INFO 1 --- [elegram.org/...] global : Update listener failure invest-app | invest-app | java.net.SocketTimeoutException: timeout invest-app | at okhttp3.internal.http2.Http2Stream$StreamTimeout.newTimeoutException(Http2Stream.kt:677) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http2.Http2Stream$StreamTimeout.exitAndThrowIfTimedOut(Http2Stream.kt:686) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http2.Http2Stream.takeHeaders(Http2Stream.kt:143) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http2.Http2ExchangeCodec.readResponseHeaders(Http2ExchangeCodec.kt:96) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.kt:106) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:79) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201) ~[okhttp-4.9.1.jar!/:na] invest-app | at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:517) ~[okhttp-4.9.1.jar!/:na] invest-app | at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na] invest-app | at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na] invest-app | at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]

После этой ошибки, торговля прекращается. Контейнеры продолжают работать, статистика через web доступна, но не обновляется.

Запущено через docker compose на Mac OS.

roman-struchev commented 2 years ago

Привет, эта ошибка вероятно происходит в com.pengrad.telegrambot.Callback#onFailure, но сам ее не ловил. В любом случае, попробую разобраться.

Вы запускаете в режиме теста (./gradlew test) с подключенными телеграмм нотификациями? При отключенных telegram нотификациях тоже слушатель свечей завершает работу (торговля прекращается)? Можете скинуть полный stacktrace?

shizlkazizl commented 2 years ago

Супер, спасибо.

Нет, запускал так:

docker build -t romanew/invest:latest -f Dockerfile.App .

docker-compose -f docker-compose-app-with-db-local.yml up

Телеграм сконфигурирован в docker-compose-app-with-db-local.yml. Пробовал отключать нотификацию, но через какое-то время торговля тоже прекращается, и появляется такая ошибка:

invest-app | 2022-07-23 13:59:51.766 ERROR 1 --- [ult-executor-28] c.s.i.s.candle.CandleListenerService : An error in candles_stream, listener will be restarted invest-app | invest-app | io.grpc.StatusRuntimeException: UNAVAILABLE: io exception invest-app | at io.grpc.Status.asRuntimeException(Status.java:535) ~[grpc-api-1.43.0.jar!/:1.43.0] invest-app | at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:479) ~[grpc-stub-1.44.0.jar!/:1.44.0] invest-app | at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) ~[grpc-api-1.43.0.jar!/:1.43.0] invest-app | at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) ~[grpc-api-1.43.0.jar!/:1.43.0] invest-app | at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) ~[grpc-api-1.43.0.jar!/:1.43.0] invest-app | at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:562) ~[grpc-core-1.44.0.jar!/:1.44.0] invest-app | at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:70) ~[grpc-core-1.44.0.jar!/:1.44.0] invest-app | at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:743) ~[grpc-core-1.44.0.jar!/:1.44.0] invest-app | at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:722) ~[grpc-core-1.44.0.jar!/:1.44.0] invest-app | at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) ~[grpc-core-1.44.0.jar!/:1.44.0] invest-app | at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133) ~[grpc-core-1.44.0.jar!/:1.44.0] invest-app | at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na] invest-app | at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na] invest-app | at java.base/java.lang.Thread.run(Unknown Source) ~[na:na] invest-app | Caused by: io.grpc.netty.shaded.io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection reset by peer invest-app | invest-app | 2022-07-23 13:59:52.169 WARN 1 --- [ult-executor-28] c.s.i.s.n.NotificationService : Listening candle events.. invest-app | 2022-07-23 13:59:52.251 DEBUG 1 --- [ult-executor-28] r.t.p.core.InvestApi$LoggingInterceptor : Готовится вызов метода MarketDataStream сервиса tinkoff.public.invest.api.contract.v1.MarketDataStreamService. invest-app | 2022-07-23 13:59:52.400 DEBUG 1 --- [ult-executor-28] r.t.p.core.InvestApi$LoggingInterceptor : Пришло сообщение от потока MarketDataStream сервиса tinkoff.public.invest.api.contract.v1.MarketDataStreamService.

Если подскажите как скинуть stacktrace — запросто. У меня совсем мало опыта(

roman-struchev commented 2 years ago

An error in candles_stream, listener will be restarted - эта ошибка уже понятна, попробую воспроизвести и поправить, спасибо!

roman-struchev commented 2 years ago

За последние несколько дней у меня было несколько обрывов соединения, но листенер после обрыва переподключался самостоятельно и начинал заного слушать поток свечей, вот пример лога.

  1. Обрыв
    2022-08-15T06:35:09.433351000Z 2022-08-15 06:35:09.093 ERROR 1 --- [ault-executor-5] c.s.i.s.candle.CandleListenerService     : An error in candles_stream, listener will be restarted
    2022-08-15T06:35:09.434341000Z io.grpc.StatusRuntimeException: UNAVAILABLE: io exception
    2022-08-15T06:35:09.434713000Z  at io.grpc.Status.asRuntimeException(Status.java:535) ~[grpc-api-1.43.0.jar!/:1.43.0]
    2022-08-15T06:35:09.435133000Z  at io.grpc.stub.ClientCalls$StreamObserverToCallListenerAdapter.onClose(ClientCalls.java:479) ~[grpc-stub-1.44.0.jar!/:1.44.0]
    2022-08-15T06:35:09.435501000Z  at io.grpc.PartialForwardingClientCallListener.onClose(PartialForwardingClientCallListener.java:39) ~[grpc-api-1.43.0.jar!/:1.43.0]
    2022-08-15T06:35:09.435881000Z  at io.grpc.ForwardingClientCallListener.onClose(ForwardingClientCallListener.java:23) ~[grpc-api-1.43.0.jar!/:1.43.0]
    2022-08-15T06:35:09.436284000Z  at io.grpc.ForwardingClientCallListener$SimpleForwardingClientCallListener.onClose(ForwardingClientCallListener.java:40) ~[grpc-api-1.43.0.jar!/:1.43.0]
    2022-08-15T06:35:09.436662000Z  at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:562) ~[grpc-core-1.44.0.jar!/:1.44.0]
    2022-08-15T06:35:09.437121000Z  at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:70) ~[grpc-core-1.44.0.jar!/:1.44.0]
    2022-08-15T06:35:09.437541000Z  at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:743) ~[grpc-core-1.44.0.jar!/:1.44.0]
    2022-08-15T06:35:09.437911000Z  at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:722) ~[grpc-core-1.44.0.jar!/:1.44.0]
    2022-08-15T06:35:09.438307000Z  at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) ~[grpc-core-1.44.0.jar!/:1.44.0]
    2022-08-15T06:35:09.438671000Z  at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133) ~[grpc-core-1.44.0.jar!/:1.44.0]
    2022-08-15T06:35:09.439097000Z  at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
    2022-08-15T06:35:09.439474000Z  at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
    2022-08-15T06:35:09.439862000Z  at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
    2022-08-15T06:35:09.440288000Z Caused by: io.grpc.netty.shaded.io.netty.channel.unix.Errors$NativeIoException: readAddress(..) failed: Connection timed out
  2. Восстановление соединения
    2022-08-15T06:35:09.513712000Z 2022-08-15 06:35:09.511  WARN 1 --- [ault-executor-5] c.s.i.s.n.NotificationService            : Listening candle events..
    2022-08-15T06:35:09.594216000Z 2022-08-15 06:35:09.590 DEBUG 1 --- [ault-executor-5] r.t.p.core.InvestApi$LoggingInterceptor  : Готовится вызов метода MarketDataStream сервиса tinkoff.public.invest.api.contract.v1.MarketDataStreamService.
    2022-08-15T06:35:09.685250000Z 2022-08-15 06:35:09.683 DEBUG 1 --- [ault-executor-5] r.t.p.core.InvestApi$LoggingInterceptor  : Пришло сообщение от потока MarketDataStream сервиса tinkoff.public.invest.api.contract.v1.MarketDataStreamService.
  3. Новые собития по свечкам
    2022-08-15T06:59:58.174903000Z 2022-08-15 06:59:58.120 DEBUG 1 --- [ault-executor-7] c.s.i.service.processor.PurchaseService  : Observe candle event: CandleDomainEntity(id=87082, figi=BBG00178PGX3, highestPrice=414.200000000, lowestPrice=414.200000000, openPrice=414.200000000, closingPrice=414.200000000, dateTime=2022-08-15T06:59Z, interval=1min, version=0)
    2022-08-15T07:00:00.965484000Z 2022-08-15 07:00:00.955 DEBUG 1 --- [ault-executor-7] r.t.p.core.InvestApi$LoggingInterceptor  : Пришло сообщение от потока MarketDataStream сервиса tinkoff.public.invest.api.contract.v1.MarketDataStreamService.
    2022-08-15T07:00:00.970579000Z 2022-08-15 07:00:00.967 DEBUG 1 --- [ault-executor-7] c.s.i.service.processor.PurchaseService  : Observe candle event: CandleDomainEntity(id=87083, figi=BBG00178PGX3, highestPrice=414.200000000, lowestPrice=414.200000000, openPrice=414.200000000, closingPrice=414.200000000, dateTime=2022-08-15T07:00Z, interval=1min, version=0)
    2022-08-15T07:00:02.587500000Z 2022-08-15 07:00:02.586 DEBUG 1 --- [ault-executor-7] r.t.p.core.InvestApi$LoggingInterceptor  : Пришло сообщение от потока MarketDataStream сервиса tinkoff.public.invest.api.contract.v1.MarketDataStreamService.
    2022-08-15T07:00:02.598858000Z 2022-08-15 07:00:02.595 DEBUG 1 --- [ault-executor-7] c.s.i.service.processor.PurchaseService  : Observe candle event: CandleDomainEntity(id=87083, figi=BBG00178PGX3, highestPrice=414.600000000, lowestPrice=414.200000000, openPrice=414.200000000, closingPrice=414.600000000, dateTime=2022-08-15T07:00Z, interval=1min, version=1)
    2022-08-15T07:00:03.041864000Z 2022-08-15 07:00:03.037 DEBUG 1 --- [ault-executor-7] r.t.p.core.InvestApi$LoggingInterceptor  : Пришло сообщение от потока MarketDataStream сервиса tinkoff.public.invest.api.contract.v1.MarketDataStreamService.
    2022-08-15T07:00:03.045724000Z 2022-08-15 07:00:03.044 DEBUG 1 --- [ault-executor-7] c.s.i.service.processor.PurchaseService  : Observe candle event: CandleDomainEntity(id=87083, figi=BBG00178PGX3, highestPrice=417.000000000, lowestPrice=414.200000000, openPrice=414.200000000, closingPrice=417.000000000, dateTime=2022-08-15T07:00Z, interval=1min, version=2)

Если проблема у вас все еще есть, отправьте пожалуйста свежий лог как слушатель отвалился в торговое время и в течении нескольких минут коннект не востановился. Также проверьте пожалуйста, что используете последнюю версию исходного кода, т.к. несколько месяцев назад я правил подобную проблему