Проблемы с OpenVPN - длительность сессии

ovcher пишет: Нет, буду копать.

Появилось время посмотреть логи, свои и "сервиса". У меня сложилось ощущение, что кто-то "коварный" раз в час (плюс/минус 2 секунды) "передергивает" подключение. Далее "Inactivity timeout" и по --ping-restart клиент "переподнимает" туннель. Этим "коварным" могло бы быть и мое оборудование, но "отрубаются" и линуксовые и виндовые клиенты, на разных интернет провайдерах. И ровно через час с момента поднятия соответствующего туннеля (т.е. получается эдакое "на первый-второй рассчитайсь").
ЗЫ. По крайней мере в настройках "своих" клиентов, "ежечасный" реконнект я не нашел.

От жеж гадкий openvpn... спасибо за анализ!
Я возьму паузу "на подумать". Прошу сообщить имя пользователя, при соединении которого наблюдался ежечасный обрыв.

Кстати (подумали тут)
Попробуйте вписать в свой ovpn файл следующую строку reneg-sec 0
Где-нибудь между:

auth-user-pass
reneg-sec 0
explicit-exit-notify 2

Перезапустите соединение и подождите часик-полтора.

Еще вопрос про inactivity timeout
Похоже он действительно срабатывает, по большей части, по ночам, когда нет трафика у пользователей.
Пришлите, пожалуйста, часть лога, где вы видели Inactivity timeout

Username Start time Stop time Station IP VPNKI IP
user1438 17.08.2017 10:55 109.252.107.144 172.16.4.164
user1438 17.08.2017 9:48 17.08.2017 10:48 109.252.107.144 172.16.4.164
user1438 17.08.2017 8:41 17.08.2017 9:41 109.252.107.144 172.16.4.164
user1438 17.08.2017 7:35 17.08.2017 8:35 109.252.107.144 172.16.4.164
user1438 17.08.2017 5:28 17.08.2017 7:28 109.252.107.144 172.16.4.164
user1438 17.08.2017 4:21 17.08.2017 5:21 109.252.107.144 172.16.4.164
user1438 17.08.2017 2:14 17.08.2017 4:14 109.252.107.144 172.16.4.164
user1438 17.08.2017 1:07 17.08.2017 2:07 109.252.107.144 172.16.4.164
user1438 17.08.2017 0:01 17.08.2017 1:01 109.252.107.144 172.16.4.164
user1438 16.08.2017 23:48 17.08.2017 0:00 109.252.107.144 172.16.4.164
user1438 16.08.2017 22:41 16.08.2017 23:41 109.252.107.144 172.16.4.164
user1438 16.08.2017 21:36 16.08.2017 22:36 109.252.107.144 172.16.4.164
user1438 16.08.2017 20:29 16.08.2017 21:29 109.252.107.144 172.16.4.164
user1438 16.08.2017 18:51 16.08.2017 19:09 109.252.107.144 172.16.4.164
user1438 16.08.2017 17:44 16.08.2017 18:44 109.252.107.144 172.16.4.164
user1438 16.08.2017 16:37 16.08.2017 17:37 109.252.107.144 172.16.4.164
user1438 16.08.2017 15:30 16.08.2017 16:30 109.252.107.144 172.16.4.164
user1438 16.08.2017 13:23 16.08.2017 15:23 109.252.107.144 172.16.4.164
user1438 16.08.2017 12:16 16.08.2017 13:16 109.252.107.144 172.16.4.164
Параметр чуть позже

ЗЫ. user1438 - linux
А вот Windows

Username Start time Stop time Station IP VPNKI IP
user1473 17.08.2017 13:04 130.193.66.14 172.16.4.195
user1473 17.08.2017 11:57 17.08.2017 12:57 130.193.66.14 172.16.4.195
user1473 17.08.2017 9:50 17.08.2017 11:50 130.193.66.14 172.16.4.195
user1473 17.08.2017 8:43 17.08.2017 9:43 130.193.66.14 172.16.4.195
user1473 17.08.2017 6:43 17.08.2017 6:56 109.252.107.144 172.16.4.195
user1473 17.08.2017 0:12 17.08.2017 0:47 109.252.107.144 172.16.4.195
user1473 16.08.2017 18:38 16.08.2017 19:22 130.193.66.14 172.16.4.195
user1473 16.08.2017 17:25 16.08.2017 18:25 130.193.66.14 172.16.4.195
user1473 16.08.2017 15:18 16.08.2017 17:18 130.193.66.14 172.16.4.195
user1473 16.08.2017 13:12 16.08.2017 15:12 130.193.66.14 172.16.4.195
user1473 16.08.2017 12:05 16.08.2017 13:05 130.193.66.14 172.16.4.195
user1473 16.08.2017 10:58 16.08.2017 11:58 130.193.66.14 172.16.4.195
user1473 16.08.2017 9:51 16.08.2017 10:51 130.193.66.14 172.16.4.195
user1473 16.08.2017 9:50 16.08.2017 9:51 130.193.66.14 172.16.4.195
user1473 16.08.2017 8:43 16.08.2017 9:43 130.193.66.14 172.16.4.195
user1473 16.08.2017 6:55 16.08.2017 7:05 109.252.107.144 172.16.4.195
user1473 16.08.2017 6:52 16.08.2017 6:54 109.252.107.144 172.16.4.195
user1473 15.08.2017 21:32 15.08.2017 22:00 109.252.107.144 172.16.4.195

user1473 выключаю сам, поэтому не всегда понятно, когда "сам", а когда нет (как правило с 10-до 18 стараюсь, чтобы висело, т.к. пропавший пинг - критерий в "консоле user1438" не наживать лишний раз на клавиши)
Справедливости ради для user1438
17.08.2017 2:14 - сессия длилась 2 часа, но ровно (17.08.2017 4:14)
17.08.2017 10:55 - пока не рассоединялось

ЗЫЫ. И вот мой лог для user1438

Aug 17 10:56:03 openvpn-cli[2591]: [VPNKI] Inactivity timeout (--ping-restart), restarting
Aug 17 10:56:03 openvpn-cli[2591]: /sbin/ifconfig tun0 0.0.0.0
Aug 17 10:56:03 openvpn-cli[2591]: ovpnc.script tun0 1500 1560 172.16.4.164 255.255.0.0 init
Aug 17 10:56:03 vpnc-script: tun0 down
Aug 17 10:56:03 openvpn-cli[2591]: SIGUSR1[soft,ping-restart] received, process restarting
Aug 17 10:56:05 openvpn-cli[2591]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
Aug 17 10:56:05 openvpn-cli[2591]: UDPv4 link local: [undef]
Aug 17 10:56:05 openvpn-cli[2591]: UDPv4 link remote: [AF_INET]193.232.49.4:33340
Aug 17 10:56:06 openvpn-cli[2591]: [VPNKI] Peer Connection Initiated with [AF_INET]193.232.49.4:33340
Aug 17 10:56:09 openvpn-cli[2591]: TUN/TAP device tun0 opened
Aug 17 10:56:09 openvpn-cli[2591]: do_ifconfig, tt->ipv6=0, tt->did_ifconfig_ipv6_setup=0
Aug 17 10:56:09 openvpn-cli[2591]: /sbin/ifconfig tun0 172.16.4.164 netmask 255.255.0.0 mtu 1500 broadcast 172.16.255.255
Aug 17 10:56:09 openvpn-cli[2591]: ovpnc.script tun0 1500 1560 172.16.4.164 255.255.0.0 init
Aug 17 10:56:09 vpnc-script: tun0 up
Aug 17 10:56:09 openvpn-cli[2591]: Initialization Sequence Completed

Перезапустите соединение и подождите часик-полтора.

Скорее всего я "его" потерял совсем. (До вечера)

Сам клиент user1438 поднялся, но маршрут "в сеть" - нет.
В итоге по адресу 172.16.4.164 "все" доступно, а по 192.168.1.1 (на том же аппарате) - уже нет. По опыту - только последовательная остановка/запуск, что приведет к отключению до "физического доступа" к внутренней сети. Для меня - нежелательно.
Но для статистки в данной теме - подойдет

user1438 2017-08-17 13:33:46

Такая же ерунда наблюдается. Раз в час реконнект

Это явно где-то у нас, мы ищем дурацкие таймеры... их там много. Потерпите

Либо после

reneg-sec 0

либо Вы что-то делаете, но
Линуксовый user1438 держится с 2017-08-17 13:33:46
Виндовый user1473 держится с 2017-08-17 15:08:09
Логи везде "чистые".
Правда и маршрут до "сети" лег, т.е. "еще не все решено" (с)

Мы не делаем, мы пока наблюдаем.
Насчет маршрута до сети - (возможно?), он мог не передаться из-за высокой нагрузки на наш сервер. Тут было под 100%.
Пришлось выключить всякий интерактив из веб-части. В частности, всякие автообновления статусов туннелей пришлось пустить под нож. Было 5 сек, теперь там 10 минут. Серверу полегчало. Немного.
Ждем результат reneg-sec 0/
Есть там всякие таймеры, но ... надо понять сначала с reneg-sec 0

Как там reneg-sec 0 поживает?

Поясню что мы тут думаем.
В борьбе с зависшими сессиями, некоторое время, назад мы наткнулись на баг (?) со стороны OpenVPN. Он выглядит следующим образом. По умолчанию, процедура обмена ключами согласуется между сервером и клиентом в момент подключения и период рекеинга составляет 1 час. Так как мы используем UDP (что не гарантирует доставку), то, видимо, что-то не так происходит в процедуре рекеинга и второй (именно второй) рекей не проходит. При этом туннель не отключается, а просто перестает ходить трафик из-за отсутствия согласованного шифрования. Что интересно, но непрохождение этого трафика не означает, что сработает inactivity timeout и туннель будет отключен. Точнее, мы так и не поняли, а должны ли вообще шифроваться служебные пинги? Получается, что раз Inactivity Timeout не сработал, то значит служебные пинги не шифруются и все равно ходят. Поэтому туннель трафик не пропускал, но продолжал висеть до следующего рекея, который проходил нормально и хождение трафика возобновлялось.

Мы решили это побороть двумя действиями. Первое - увеличить время рекеинга до 48 часов и, одновременно, ввести перезапуск сессий пользователей каждые 24 часа. Таким образом, рекеинг просто никогда бы не наступил, а пользователи не теряли бы трафик.
Это мы сделали, но, тем не менее, какие-то клиенты OpenVPN (не все) ПО-ПРЕЖНЕМУ пытаются каждый час начать процедуру рекеинга, хотя их на сервере никто не ждет. Возможно, у них это вшито по-умолчанию. Но только в этот раз, невыполненный рекеинг приводит к обрыву сессии по Inactivity Timeout со стороны клиента. В общем все кривовато и не так как ожидалось. Поэтому ...

Есть предложение жестко принудить клиентское ПО OpenVPN не выполнять процедуру рекеинга, поставив параметр reneg-sec 0 в файле .ovpn (отдельной строкой перед тегом <ca>) или скачав новую версию файла с персональной страницы.

Линуксовый (user1438) вчера "до" 2017-08-18 00:01:07 и сегодня "после" ни разу не переконнектился, Канал держит.
Виндовый (user1473) я запустил только 2017-08-18 08:59:58. Но вчера с 2017-08-17 15:08:09 до 2017-08-17 19:15:48 стоял "как влитой".

"Про роутинг"

он мог не передаться из-за высокой нагрузки на наш сервер

Вчера я по-правильному (с пинанием колеса) в 2017-08-17 22:29:52 перезапустил user1438
Из-за не корректного рестарта в 2017-08-17 13:33:46 "у Вас" (Инструменты->Таблица маршрутов) не понялся этот маршрут

192.168.1.0/24 via 172.16.4.164 dev tun0

Поверьте, пжалуйста
Наверное не плохо было бы добавить кнопку "инициализировать маршруты" на страничку "инструменты" (если много туннелей - не логично) или в настройки каждого туннеля.

У вас openvpn держится с установленным reneg-sec 0 ?

Посмотрел, сейчас этот маршрут имеется. Адрес 172.16.4.164 и 192.168.1.1 пингуются с сервера
Вы видите маршрут на странице Инструменты и проходят ли пинги?

admin пишет: У вас openvpn держится с установленным reneg-sec 0 ?

Да. У обоих клиентов.

admin пишет: Посмотрел, сейчас этот маршрут имеется. Адрес 172.16.4.164 и 192.168.1.1 пингуются с сервера
Вы видите маршрут на странице Инструменты и проходят ли пинги?

Сейчас (!) - да. Но когда в 2017-08-17 13:33:46 я добавил клиенту user1438 параметр reneg-sec 0 и клиент перезапустился (штатно!!!), то маршрут пропал. И вчера после 2017-08-17 13:33:46 я мог войти (ssh) только на устройство с ip 172.16.4.164 (естественно подняв второй туннель user1473).
- route на 172.16.4.164 (он же 192.168.1.1) и на остальных компьютерах сети были корректные
- tracert c 172.16.4.195 до 192.168.1.1 доходил до 172.16.0.1 и все
Мне ("моему клиенту") для корректного поднятия туннеля необходимо выключить, выдержать паузу (до письма) и снова включить. Только тогда "появляется" эта строка в таблице маршрутизации.
При этом при "реконнекте" (то, что обсуждаете в данной ветке) маршрут, видимо, не удалялся, т.е. не поднимался и, в итоге, "оставался".

Вчера был тяжелый день по загрузке на сервер, может быть это повлияло. Давайте посмотрим сегодня.
Я правильно понимаю, что ваш клиент ждет получения оповещения по почте об отключении/включении туннеля?
Если не секрет - почему вы делает так, в чем причина?

admin пишет: Вчера был тяжелый день по загрузке на сервер, может быть это повлияло. Давайте посмотрим сегодня.

Я не планирую перезапускать клиента, т.к. для меня пусть без маршрутизации, с "ежечасными" реконнектами, с упавшим socks'прокси, "непубликацией" и т.д. (решу) главное, чтобы туннель 1438 был поднят. Т.е. не находясь у компьютеров сети 192.168.1.0, я клиента перезапускать не буду.

admin пишет: Я правильно понимаю, что ваш клиент ждет получения оповещения по почте об отключении/включении туннеля?

Нет. Это "лженаука" статистика. Пока не выдержать "паузу", соизмеримую со времене прихода письма, ничего (с большой долей вероятности) не получится

admin пишет: Если не секрет - почему вы делает так, в чем причина?

До какого-то часа (дня) X что-то (?) падало редко и реконнект не помогал. tun0 "жил", что было с пингами^* я узнать (по объективным причинам) не мог. Я искал критерий перезапуска остановки и запуска клиента. Либо Ваше письмо (оно не приходило при "пропадании связи"), либо "лампочки" статуса (они не краснели), либо "письмо с большой земли" (от меня) - пока лень.
^* скорее всего пинги до 172.16.0.1 доходили, а дальше, в моей конфигурации (1473 - аварийный вариант) пинговать некого.
^X День X в моем понимании это когда Вы отключили регистрацию в Амстердаме. Опять же "после не значит вследствии" (c), но "проблемы" начались примерно тогда.

Понятно. Прекращение регистрации в Амстердаме совпадаем с началом обновления сервера OpenVPN до следующей версии на нашей стороне. Видимо все после этого и началось.
Еще один нюанс. Возможно вам пригодится. Как я уже писал, мы используем UDP и при обрыве соединения со стороны клиента сервер не может никак узнать о том, что клиент отключился. Если бы была сессия TCP то сервер бы узнал, а тут нет. Для извещения сервера мы ввели параметр explicit-exit notify 2 в файлы .ovpn. В соответствии с этим параметром, клиент дважды посылает на сервер данные о своем отключении. До тех пор, пока сервер не узнал, что соединение оборвалось клиент будет числиться "подключенным" и при повторном соединении его не пустят из-за ограничения "один логин - одна сессия". Затем наступит таймаут неактивности соединения, который сейчас составляет 2 минуты и сервер, в итоге, оборвет соединение. И только через 2 минуты он будет готов принимать соединение от этого клиента вновь.
В вашем случае, если случается событие, при котором клиент не успел послать explicit-exit notify, или эти пакеты потерялись по дороге, то 2-3 минуты это время, которое нужно выждать перед установкой нового соединения. Это самый печальный, но редкий случай, так как в нормальных ситуациях соединение должно устанавливаться моментально. Вы можете поставить explicit-exit notify 5 - хуже не будет.
Мы думали о том, чтобы запустить подключение OpenVPN для клиентов по TCP. Это возможно, но нагрузка на сервер существенно увеличится из-за необходимости поддерживать и TCP и UDP инстансы для клиента. Но однозначно, работа по TCP была бы четче и проблем было бы меньше. Если вам кажется, что это было бы верным решением, то можно в качестве теста попробовать сделать сервер на TCP порту.