Статус: Активный участник
Группы: Участники
Зарегистрирован: 10.07.2013(UTC) Сообщений: 42  Откуда: Нижний Новгород Сказал(а) «Спасибо»: 2 раз
|
Здравствуйте.
Схема работы следующая - iOS приложение создает секьюр туннель (stunnel) с сервером (на сервере Trusted TLS).
Проблема в слишком большом времени обработки каждого запроса (от 12 секунд и больше).
В логах при каждом запросе мы видим подозрительное "зависание" на 10-11 секунд.
Запустил приложение в TimeProfile, вижу, что запуск stunnel занимает не более 1.5 секунд работы процессора.
Конфиг stunnel:
pid = /var/mobile/Applications/4C7D3B90-8286-4CD3-9D9E-CA573E05E713/Documents/../Library/stunnel.pid
socket = a:SO_REUSEADDR=1
foreground = yes
debug = 4
socket = l:TCP_NODELAY=1
socket = r:TCP_NODELAY=1
[lk3app]
client = yes
accept = localhost:9443
connect = 10.0.1.144:443
mutual_auth=yes
cert=/var/mobile/Applications/4C7D3B90-8286-4CD3-9D9E-CA573E05E713/Documents/client.cer
verify=2
Логи с iOS приложения:
2013.09.19 13:15:57 LOG5[39644:82022400]: stunnel 4.18 on arm-apple-darwin
2013.09.19 13:15:57 LOG5[39644:82022400]: Threading:PTHREAD Sockets:SELECT,IPv4
2013.09.19 13:15:57 LOG6[39644:82022400]: file ulimit = 256 (can be changed with 'ulimit -n')
2013.09.19 13:15:57 LOG6[39644:82022400]: FD_SETSIZE = 1024 (some systems allow to increase this value)
2013.09.19 13:15:57 LOG5[39644:82022400]: 0 clients allowed
2013.09.19 13:15:57 LOG7[39644:82022400]: FD 15 in non-blocking mode
2013.09.19 13:15:57 LOG7[39644:82022400]: FD 16 in non-blocking mode
2013.09.19 13:15:57 LOG7[39644:82022400]: FD 17 in non-blocking mode
2013.09.19 13:15:57 LOG7[39644:82022400]: SO_REUSEADDR option set on accept socket
2013.09.19 13:15:57 LOG7[39644:82022400]: lk3app bound to 127.0.0.1:9443
2013.09.19 13:15:57 LOG7[39644:82022400]: Created pid file /var/mobile/Applications/4C7D3B90-8286-4CD3-9D9E-CA573E05E713/Documents/../Library/stunnel.pid
2013.09.19 13:15:58 LOG7[39644:82022400]: lk3app accepted FD=25 from 127.0.0.1:57433
2013.09.19 13:15:58 LOG7[39644:803954688]: client start
2013.09.19 13:15:58 LOG7[39644:803954688]: lk3app started
2013.09.19 13:15:58 LOG7[39644:803954688]: FD 25 in non-blocking mode
2013.09.19 13:15:58 LOG7[39644:803954688]: TCP_NODELAY option set on local socket
2013.09.19 13:15:58 LOG5[39644:803954688]: lk3app connected from 127.0.0.1:57433
2013.09.19 13:15:58 LOG7[39644:803954688]: FD 32 in non-blocking mode
2013.09.19 13:15:58 LOG7[39644:803954688]: lk3app connecting
2013.09.19 13:15:58 LOG7[39644:803954688]: connect_wait: waiting 10 seconds
2013.09.19 13:15:58 LOG7[39644:803954688]: connect_wait: connected
2013.09.19 13:15:58 LOG7[39644:803954688]: Remote FD=32 initialized
2013.09.19 13:15:58 LOG7[39644:803954688]: TCP_NODELAY option set on remote socket
2013.09.19 13:15:58 LOG7[39644:803954688]: start SSPI connect
2013.09.19 13:15:58 LOG5[39644:803954688]: mutual auth in on. try to read the certificate
2013.09.19 13:15:58 LOG7[39644:803954688]: open file /var/mobile/Applications/4C7D3B90-8286-4CD3-9D9E-CA573E05E713/Documents/client.cer with certificate
2013.09.19 13:16:09 LOG3[39644:803954688]: Credentials complete
2013.09.19 13:16:09 LOG7[39644:803954688]: 126 bytes of handshake data sent
2013.09.19 13:16:17 LOG5[39644:803954688]: 1448 bytes of handshake(in handshake loop) data received.
2013.09.19 13:16:17 LOG5[39644:803954688]: 714 bytes of handshake(in handshake loop) data received.
2013.09.19 13:16:17 LOG5[39644:803954688]: 2190 bytes of handshake data sent
2013.09.19 13:16:19 LOG5[39644:803954688]: 31 bytes of handshake(in handshake loop) data received.
2013.09.19 13:16:19 LOG5[39644:803954688]: Handshake was successful
2013.09.19 13:16:19 LOG5[39644:803954688]: PerformClientHandshake finish
2013.09.19 13:16:19 LOG5[39644:803954688]: Server subject: CN=10.0.1.144, O=My Company, C=RU, E=test@test.ru
...
Лог с сервера:
[Thu Sep 19 13:12:56 2013][info] [client 10.0.1.77] Connection to child 6 established (server 10.0.1.144:443)
[Thu Sep 19 13:12:56 2013] [info] Seeding PRNG with 144 bytes of entropy
[Thu Sep 19 13:13:14 2013] [debug] ssl_engine_io.c(1907): OpenSSL: read 11/11 bytes from BIO#7fc1df01af60 [mem: 7fc1df01b050] (BIO dump follows)
[Thu Sep 19 13:13:14 2013] [debug] ssl_engine_io.c(1840): +-------------------------------------------------------------------------+
[Thu Sep 19 13:13:14 2013] [debug] ssl_engine_io.c(1879): | 0000: 16 03 01 00 79 01 00 00-75 03 01 ....y...u.. |
[Thu Sep 19 13:13:14 2013] [debug] ssl_engine_io.c(1885): +-------------------------------------------------------------------------+
[Thu Sep 19 13:13:14 2013] [debug] ssl_engine_io.c(1907): OpenSSL: read 115/115 bytes from BIO#7fc1df01af60 [mem: 7fc1df01b05b] (BIO dump follows)
[Thu Sep 19 13:13:14 2013] [debug] ssl_engine_io.c(1840): +-------------------------------------------------------------------------+
...
Вопрос - чем это вызвано и можно ли это время уменьшить?
|
|
|
|
|
|
Статус: Сотрудник
Группы: Участники
Зарегистрирован: 06.02.2008(UTC)
Сообщений: 1,491
Откуда: Крипто-Про
Поблагодарили: 40 раз в 37 постах
|
По итогам переписки с пользователем выяснилось, что время тратилось на построение цепочки сертификатов -- в сертификате пользователя было много ссылок на корневой сертификат, точки распространения списка отзывов, адрес OCSP-службы и т.п.
При этом большинство адресов было не доступно(ссылки на внутренние ресурсы, которые не были доступны из интернета). Именно на обращения по этим адресам и выкачивание данных для построения цепочки и тратилось время. |
Татьяна
ООО Крипто-Про |
|
|
|
|
|
Быстрый переход
Вы не можете создавать новые темы в этом форуме.
Вы не можете отвечать в этом форуме.
Вы не можете удалять Ваши сообщения в этом форуме.
Вы не можете редактировать Ваши сообщения в этом форуме.
Вы не можете создавать опросы в этом форуме.
Вы не можете голосовать в этом форуме.
Important Information:
The Форум КриптоПро uses cookies. By continuing to browse this site, you are agreeing to our use of cookies.
More Details
Close
