Статус: Новичок
Группы: Участники
Зарегистрирован: 05.10.2023(UTC) Сообщений: 2
|
При отправке 5 000 одинаковых запросов с клиента на сервер, на некоторых из них (примерно 5-10 на 5 000) происходит "зависание". Окружение клиента: JTLS + JCP 2.0.41940-A + Liberica JDK 11.0.17+7 TLS v1.2 Запросы/сертификаты/версии/машины используются одни и те же, канал одинаковый Проблема проявляется в фазе Generate pre-master-key. При корректной отправке запроса лог JCP фазы Generate pre-master-key выглядит так:
Код:02.10.2023 03:40:53.057 FINE ru.CryptoPro.ssl.cl_18 a: Generate pre-master-key.
02.10.2023 03:40:53.057 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineInit: ENTRY
02.10.2023 03:40:53.058 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineInit: RETURN
02.10.2023 03:40:53.058 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineGenerateKey: ENTRY
02.10.2023 03:40:53.065 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineGenerateKey: RETURN
02.10.2023 03:40:53.065 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher engineSetMode: ENTRY
02.10.2023 03:40:53.066 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher engineSetMode: RETURN
02.10.2023 03:40:53.066 FINER ru.CryptoPro.Crypto.Key.GostExchKeyPairGenerator initialize: ENTRY
02.10.2023 03:40:53.066 FINER ru.CryptoPro.Crypto.Key.GostExchKeyPairGenerator initialize: RETURN
02.10.2023 03:40:53.066 FINER ru.CryptoPro.Crypto.Key.GostEphExchKeyPairGenerator generateKeyPair: ENTRY
02.10.2023 03:40:53.086 FINER ru.CryptoPro.Crypto.Key.GostEphExchKeyPairGenerator generateKeyPair: RETURN
02.10.2023 03:40:53.086 FINER ru.CryptoPro.Crypto.Key.KeyAgreement engineInit: ENTRY
02.10.2023 03:40:53.087 FINER ru.CryptoPro.Crypto.Key.KeyAgreement engineInit: RETURN
02.10.2023 03:40:53.087 FINER ru.CryptoPro.Crypto.Key.KeyAgreement engineDoPhase: ENTRY
02.10.2023 03:40:53.091 FINER ru.CryptoPro.Crypto.Key.KeyAgreement engineDoPhase: RETURN
02.10.2023 03:40:53.091 FINER ru.CryptoPro.Crypto.Key.KeyAgreement engineGenerateSecret: ENTRY
02.10.2023 03:40:53.100 FINER ru.CryptoPro.Crypto.Key.KeyAgreement engineGenerateSecret: RETURN
02.10.2023 03:40:53.100 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher engineInit: ENTRY
02.10.2023 03:40:53.100 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher engineInit: RETURN
02.10.2023 03:40:53.100 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher engineWrap: ENTRY
02.10.2023 03:40:53.100 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher engineWrap: RETURN
02.10.2023 03:40:53.101 FINE ru.CryptoPro.ssl.cl_45 f: *** ClientKeyExchange
Перед возникновением проблемы последние строки в логе JCP выглядят следующим образом:
Код:02.10.2023 03:41:30.822 FINE ru.CryptoPro.ssl.cl_18 a: Generate pre-master-key.
02.10.2023 03:41:30.822 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineInit: ENTRY
02.10.2023 03:41:30.822 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineInit: RETURN
02.10.2023 03:41:30.822 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineGenerateKey: ENTRY
02.10.2023 03:41:30.830 FINER ru.CryptoPro.Crypto.Cipher.GostMac engineDoFinal: ENTRY
02.10.2023 03:41:30.830 FINER ru.CryptoPro.Crypto.Cipher.GostMac engineDoFinal: RETURN
02.10.2023 03:41:30.830 FINE ru.CryptoPro.ssl.cl_76 a: MAC computed: ... DD
02.10.2023 03:41:30.830 FINE ru.CryptoPro.ssl.cl_9 a: Begin encrypt...
02.10.2023 03:41:30.830 ALL ru.CryptoPro.ssl.cl_9 a: Plaintext before ENCRYPTION: len = 6
...
02.10.2023 03:41:30.830 FINE ru.CryptoPro.ssl.cl_9 a: Encrypted...
02.10.2023 03:41:30.831 ALL ru.CryptoPro.ssl.cl_76 a: [Raw write]: length = 11
...
02.10.2023 03:41:30.831 FINE ru.CryptoPro.ssl.SSLSocketImpl c: Finalizer , called closeSocket(selfInitiated)
02.10.2023 03:41:30.831 FINER ru.CryptoPro.Crypto.Cipher.BaseGostCipher engineDoFinal: ENTRY
02.10.2023 03:41:30.831 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher getUnprocessedDataSize: ENTRY
02.10.2023 03:41:30.831 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher getUnprocessedDataSize: RETURN
02.10.2023 03:41:30.832 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineGenerateKey: RETURN
02.10.2023 03:41:30.832 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher engineSetMode: ENTRY
02.10.2023 03:41:30.832 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher engineSetMode: RETURN
02.10.2023 03:41:30.832 FINER ru.CryptoPro.Crypto.Key.GostExchKeyPairGenerator initialize: ENTRY
02.10.2023 03:41:30.832 FINER ru.CryptoPro.Crypto.Key.GostExchKeyPairGenerator initialize: RETURN
02.10.2023 03:41:30.833 FINER ru.CryptoPro.Crypto.Key.GostEphExchKeyPairGenerator generateKeyPair: ENTRY
02.10.2023 03:41:30.840 FINER ru.CryptoPro.Crypto.Cipher.BaseGostCipher engineDoFinal: RETURN
02.10.2023 03:41:30.841 FINER ru.CryptoPro.Crypto.Cipher.BaseGostCipher engineDoFinal: ENTRY
02.10.2023 03:41:30.841 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher getUnprocessedDataSize: ENTRY
02.10.2023 03:41:30.841 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher getUnprocessedDataSize: RETURN
02.10.2023 03:41:30.850 FINER ru.CryptoPro.Crypto.Cipher.BaseGostCipher engineDoFinal: RETURN
02.10.2023 03:41:30.850 FINE ru.CryptoPro.ssl.SSLSocketImpl close: Finalizer called close()
02.10.2023 03:41:30.850 FINE ru.CryptoPro.ssl.SSLSocketImpl d: Finalizer, called closeInternal(true)
02.10.2023 03:41:30.850 FINE ru.CryptoPro.ssl.SSLSocketImpl a: Finalizer, SEND TLSv1.2 ALERT: warning, description = close_notify
02.10.2023 03:41:30.859 FINER ru.CryptoPro.Crypto.Cipher.GostMac engineDoFinal: ENTRY
02.10.2023 03:41:30.860 FINER ru.CryptoPro.Crypto.Cipher.GostMac engineDoFinal: RETURN
02.10.2023 03:41:30.860 FINE ru.CryptoPro.ssl.cl_76 a: MAC computed: ... 46
02.10.2023 03:41:30.860 FINE ru.CryptoPro.ssl.cl_9 a: Begin encrypt...
02.10.2023 03:41:30.860 ALL ru.CryptoPro.ssl.cl_9 a: Plaintext before ENCRYPTION: len = 6
...
02.10.2023 03:41:30.860 FINE ru.CryptoPro.ssl.cl_9 a: Encrypted...
02.10.2023 03:41:30.860 ALL ru.CryptoPro.ssl.cl_76 a: [Raw write]: length = 11
...
02.10.2023 03:41:30.860 FINE ru.CryptoPro.ssl.SSLSocketImpl c: Finalizer , called closeSocket(selfInitiated)
02.10.2023 03:41:30.861 FINER ru.CryptoPro.Crypto.Cipher.BaseGostCipher engineDoFinal: ENTRY
02.10.2023 03:41:30.861 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher getUnprocessedDataSize: ENTRY
02.10.2023 03:41:30.861 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher getUnprocessedDataSize: RETURN
02.10.2023 03:41:30.869 FINER ru.CryptoPro.Crypto.Cipher.BaseGostCipher engineDoFinal: RETURN
02.10.2023 03:41:30.869 FINER ru.CryptoPro.Crypto.Cipher.BaseGostCipher engineDoFinal: ENTRY
02.10.2023 03:41:30.869 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher getUnprocessedDataSize: ENTRY
02.10.2023 03:41:30.869 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher getUnprocessedDataSize: RETURN
02.10.2023 03:41:30.878 FINER ru.CryptoPro.Crypto.Cipher.BaseGostCipher engineDoFinal: RETURN
02.10.2023 03:41:30.879 FINE ru.CryptoPro.ssl.SSLSocketImpl close: Finalizer called close()
02.10.2023 03:41:30.879 FINE ru.CryptoPro.ssl.SSLSocketImpl d: Finalizer, called closeInternal(true)
02.10.2023 03:41:30.879 FINE ru.CryptoPro.ssl.SSLSocketImpl a: Finalizer, SEND TLSv1.2 ALERT: warning, description = close_notify
02.10.2023 03:41:30.889 FINER ru.CryptoPro.Crypto.Cipher.GostMac engineDoFinal: ENTRY
02.10.2023 03:41:30.889 FINER ru.CryptoPro.Crypto.Cipher.GostMac engineDoFinal: RETURN
02.10.2023 03:41:30.889 FINE ru.CryptoPro.ssl.cl_76 a: MAC computed: ... 3E
02.10.2023 03:41:30.889 FINE ru.CryptoPro.ssl.cl_9 a: Begin encrypt...
02.10.2023 03:41:30.889 ALL ru.CryptoPro.ssl.cl_9 a: Plaintext before ENCRYPTION: len = 6
...
02.10.2023 03:41:30.889 FINE ru.CryptoPro.ssl.cl_9 a: Encrypted...
02.10.2023 03:41:30.890 ALL ru.CryptoPro.ssl.cl_76 a: [Raw write]: length = 11
Видно, что в отличие от корректного сценария Код:02.10.2023 03:40:53.058 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineInit: RETURN
02.10.2023 03:40:53.058 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineGenerateKey: ENTRY
02.10.2023 03:40:53.065 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineGenerateKey: RETURN
02.10.2023 03:40:53.065 FINER ru.CryptoPro.Crypto.Cipher.GostCoreCipher engineSetMode: ENTRY
, в логе при возникновении проблемы нет возврата из метода ru.CryptoPro.Crypto.Key.GostKeyGenerator engineGenerateKeyКод:02.10.2023 03:41:30.822 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineInit: RETURN
02.10.2023 03:41:30.822 FINER ru.CryptoPro.Crypto.Key.GostKeyGenerator engineGenerateKey: ENTRY
02.10.2023 03:41:30.830 FINER ru.CryptoPro.Crypto.Cipher.GostMac engineDoFinal: ENTRY
Так же появляются фрагменты вида: Код:02.10.2023 03:41:30.850 FINE ru.CryptoPro.ssl.SSLSocketImpl close: Finalizer called close()
02.10.2023 03:41:30.850 FINE ru.CryptoPro.ssl.SSLSocketImpl d: Finalizer, called closeInternal(true)
02.10.2023 03:41:30.850 FINE ru.CryptoPro.ssl.SSLSocketImpl a: Finalizer, SEND TLSv1.2 ALERT: warning, description = close_notify
...
02.10.2023 03:41:30.860 FINE ru.CryptoPro.ssl.SSLSocketImpl c: Finalizer , called closeSocket(selfInitiated)
...
Алерт close_notify согласно спецификации TLS v1.2 означает окончание передачи данных, и может быть отправлен любой стороной. Возможно, здесь имеет место ситуация, что клиент в одностороннем порядке закрывает соединение, но причина непонятна: нет ни исключения, ни какого-либо другого алерта со стороны клиента/сервера. Так как нет возможности подробнее залогировать метод ru.CryptoPro.Crypto.Key.GostKeyGenerator#engineGenerateKey или посмотреть его содержимое, то прошу подсказать, в чем может быть проблема. Отредактировано пользователем 6 октября 2023 г. 8:45:42(UTC)
| Причина: Не указана
|
|
|
|
Статус: Новичок
Группы: Участники
Зарегистрирован: 05.10.2023(UTC) Сообщений: 2
|
Есть ли возможность в JCP включить логирование по потокам? Форматер в JUL не поддерживает паттерны для вывода имени или ID потока, но может есть какие-то настройки в JCP. В логах было бы удобнее разбираться, понимая, какому из потоков принадлежат записи.
|
|
|
|
Быстрый переход
Вы не можете создавать новые темы в этом форуме.
Вы не можете отвечать в этом форуме.
Вы не можете удалять Ваши сообщения в этом форуме.
Вы не можете редактировать Ваши сообщения в этом форуме.
Вы не можете создавать опросы в этом форуме.
Вы не можете голосовать в этом форуме.
Important Information:
The Форум КриптоПро uses cookies. By continuing to browse this site, you are agreeing to our use of cookies.
More Details
Close