Привет!
Мы заметили очень странное поведение с Unifi v2.2.5 wifi контроллером, установленным в облаке (работающим на сервере Ubuntu 10.04 LTS в нашем дата-центре), который управляет одной площадкой Unifi AP, расположенной в удалённом гостиничном комплексе (около 60 внутренних точек доступа Unifi).
Все точки доступа изначально были добавлены и хорошо связывались с контроллером, но внезапно спустя некоторое время на контроллере все AP отмечались как «Disconnected». При этом выяснилось, что эти точки доступа действительно были включены и передавали данные контроллеру (через HTTP inform порт 8080), что мы проверили при помощи tcpdump как на сервере, так и на роутере hotspot (Mikrotik) у клиента.
Мы смогли зайти на Unifi AP по ssh, и вот что было в файле /var/log/messages:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ~~~~~~~~~~~
Apr 11 05:45:07 (none) user.err syslog: ace_reporter.reporter_fail(): server unreachable
Apr 11 05:45:07 (none) user.info syslog: ace_reporter.reporter_next_inform_url(): next inform url=http://unifi:8080/inform
Apr 11 05:45:12 (none) user.err syslog: mca-client.service(): Got no response within 5.00 seconds
Apr 11 05:45:12 (none) user.info syslog: mca-monitor.do_monitor(): failed to contact mcad. last_checkin=5 (max=200)
Apr 11 05:45:22 (none) user.err syslog: ace_reporter.reporter_inform(): Failed resolving URL 'http://unifi:8080/inform'
Apr 11 05:45:22 (none) user.err syslog: ace_reporter.reporter_fail(): server unreachable
Apr 11 05:45:22 (none) user.info syslog: ace_reporter.reporter_next_inform_url(): next inform url=http://xxxxxxxx.xxxxx.xxx.net:8080/inform
Apr 11 05:45:27 (none) user.err syslog: mca-client.service(): Got no response within 5.00 seconds
Apr 11 05:45:27 (none) user.info syslog: mca-monitor.do_monitor(): failed to contact mcad. last_checkin=5 (max=200)
Apr 11 05:45:42 (none) user.err syslog: mca-client.service(): Got no response within 5.00 seconds
Apr 11 05:45:42 (none) user.info syslog: mca-monitor.do_monitor(): failed to contact mcad. last_checkin=20 (max=200)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ~~~~~~~~~~~~~~~~~
Но после дальнейшего изучения мы выяснили, что если просто перезагрузить AP, его статус на контроллере сразу меняется на «Connected».
Дальше покопались в деталях и обнаружили, что если просто убить процесс агента «mcad», который работает на AP, без перезагрузки самой точки доступа, он автоматически перезапускается, и AP становится «Connected», как показано ниже:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ~~~~~~~~
На AP:
BZ.v2.2.5#
ps aux
PID USER VSZ STAT COMMAND
1 admin 1972 S init
...
452 admin 3572 S /bin/mcad
...
kill -9 452
cat /var/log/messages
Apr 11 05:47:12 (none) user.info syslog: mca-monitor.do_monitor(): failed to contact mcad. last_checkin=35 (max=200)
Apr 11 05:47:27 (none) user.err syslog: mca-client.service(): Got no response within 5.00 seconds
Apr 11 05:47:27 (none) user.info syslog: mca-monitor.do_monitor(): failed to contact mcad. last_checkin=50 (max=200)
Apr 11 05:47:30 (none) daemon.info init: process '/bin/mcad' (pid 452) exited. Scheduling for restart.
Apr 11 05:47:30 (none) daemon.info init: starting pid 19600, tty '/dev/null': '/bin/mcad'
Apr 11 05:47:30 (none) user.info syslog: ace_reporter.reporter_reload_config(): authkey=E16388941CC659E1D40891EA9C96C1D8
Apr 11 05:47:30 (none) user.info syslog: ace_reporter.reporter_set_managed(): enter MANAGED
BZ.v2.2.5#
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ~~~~~~~~~~~
На стороне сервера Unifi контроллера в файле /var/log/unifi/server.log:
WARN inform - from (, BZ2LR, 2.2.5.1080): state=UNKNOWN, ext_ip=203.143.33.217, dev_ip=192.168.100.254, conn_req_ip=unknown, up=490544
WARN devmgr - UNKNOWN->CONNECTED, state_expire=0
WARN event - AP was connected
WARN inform - <<< dev:
WARN inform - from (, BZ2LR, 2.2.5.1080): state=CONNECTED, ext_ip=203.143.33.217, dev_ip=192.168.100.254, conn_req_ip=unknown, up=490547
WARN inform - from (, BZ2LR, 2.2.5.1080): state=CONNECTED, ext_ip=203.143.33.217, dev_ip=192.168.100.254, conn_req_ip=203.143.33.217, up=490548
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ ~~~~~~~~~~~~~~
Такая ситуация происходила примерно дважды, и общий фактор в обоих случаях — статус «Disconnected» появлялся, когда мы на несколько минут прерывали связь между клиентской площадкой и дата-центром.
В чём может быть причина такого поведения и есть ли какое-то решение этой проблемы?
Заранее спасибо!
-- С уважением,
Supun Rathnayake
Lanka Communication Services (Pvt) Ltd.
65C, Dharmapala Mawatha,
Коломбо 07, Шри-Ланка.
Тел: +94-11-2437545
blog.lankacom.net
Мы заметили очень странное поведение с Unifi v2.2.5 wifi контроллером, установленным в облаке (работающим на сервере Ubuntu 10.04 LTS в нашем дата-центре), который управляет одной площадкой Unifi AP, расположенной в удалённом гостиничном комплексе (около 60 внутренних точек доступа Unifi).
Все точки доступа изначально были добавлены и хорошо связывались с контроллером, но внезапно спустя некоторое время на контроллере все AP отмечались как «Disconnected». При этом выяснилось, что эти точки доступа действительно были включены и передавали данные контроллеру (через HTTP inform порт 8080), что мы проверили при помощи tcpdump как на сервере, так и на роутере hotspot (Mikrotik) у клиента.
Мы смогли зайти на Unifi AP по ssh, и вот что было в файле /var/log/messages:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Apr 11 05:45:07 (none) user.err syslog: ace_reporter.reporter_fail(): server unreachable
Apr 11 05:45:07 (none) user.info syslog: ace_reporter.reporter_next_inform_url(): next inform url=http://unifi:8080/inform
Apr 11 05:45:12 (none) user.err syslog: mca-client.service(): Got no response within 5.00 seconds
Apr 11 05:45:12 (none) user.info syslog: mca-monitor.do_monitor(): failed to contact mcad. last_checkin=5 (max=200)
Apr 11 05:45:22 (none) user.err syslog: ace_reporter.reporter_inform(): Failed resolving URL 'http://unifi:8080/inform'
Apr 11 05:45:22 (none) user.err syslog: ace_reporter.reporter_fail(): server unreachable
Apr 11 05:45:22 (none) user.info syslog: ace_reporter.reporter_next_inform_url(): next inform url=http://xxxxxxxx.xxxxx.xxx.net:8080/inform
Apr 11 05:45:27 (none) user.err syslog: mca-client.service(): Got no response within 5.00 seconds
Apr 11 05:45:27 (none) user.info syslog: mca-monitor.do_monitor(): failed to contact mcad. last_checkin=5 (max=200)
Apr 11 05:45:42 (none) user.err syslog: mca-client.service(): Got no response within 5.00 seconds
Apr 11 05:45:42 (none) user.info syslog: mca-monitor.do_monitor(): failed to contact mcad. last_checkin=20 (max=200)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Но после дальнейшего изучения мы выяснили, что если просто перезагрузить AP, его статус на контроллере сразу меняется на «Connected».
Дальше покопались в деталях и обнаружили, что если просто убить процесс агента «mcad», который работает на AP, без перезагрузки самой точки доступа, он автоматически перезапускается, и AP становится «Connected», как показано ниже:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
На AP:
BZ.v2.2.5#
ps aux
PID USER VSZ STAT COMMAND
1 admin 1972 S init
...
452 admin 3572 S /bin/mcad
...
kill -9 452
cat /var/log/messages
Apr 11 05:47:12 (none) user.info syslog: mca-monitor.do_monitor(): failed to contact mcad. last_checkin=35 (max=200)
Apr 11 05:47:27 (none) user.err syslog: mca-client.service(): Got no response within 5.00 seconds
Apr 11 05:47:27 (none) user.info syslog: mca-monitor.do_monitor(): failed to contact mcad. last_checkin=50 (max=200)
Apr 11 05:47:30 (none) daemon.info init: process '/bin/mcad' (pid 452) exited. Scheduling for restart.
Apr 11 05:47:30 (none) daemon.info init: starting pid 19600, tty '/dev/null': '/bin/mcad'
Apr 11 05:47:30 (none) user.info syslog: ace_reporter.reporter_reload_config(): authkey=E16388941CC659E1D40891EA9C96C1D8
Apr 11 05:47:30 (none) user.info syslog: ace_reporter.reporter_set_managed(): enter MANAGED
BZ.v2.2.5#
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
На стороне сервера Unifi контроллера в файле /var/log/unifi/server.log:
WARN inform - from (, BZ2LR, 2.2.5.1080): state=UNKNOWN, ext_ip=203.143.33.217, dev_ip=192.168.100.254, conn_req_ip=unknown, up=490544
WARN devmgr - UNKNOWN->CONNECTED, state_expire=0
WARN event - AP was connected
WARN inform - <<< dev:
WARN inform - from (, BZ2LR, 2.2.5.1080): state=CONNECTED, ext_ip=203.143.33.217, dev_ip=192.168.100.254, conn_req_ip=unknown, up=490547
WARN inform - from (, BZ2LR, 2.2.5.1080): state=CONNECTED, ext_ip=203.143.33.217, dev_ip=192.168.100.254, conn_req_ip=203.143.33.217, up=490548
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Такая ситуация происходила примерно дважды, и общий фактор в обоих случаях — статус «Disconnected» появлялся, когда мы на несколько минут прерывали связь между клиентской площадкой и дата-центром.
В чём может быть причина такого поведения и есть ли какое-то решение этой проблемы?
Заранее спасибо!
-- С уважением,
Supun Rathnayake
Lanka Communication Services (Pvt) Ltd.
65C, Dharmapala Mawatha,
Коломбо 07, Шри-Ланка.
Тел: +94-11-2437545
blog.lankacom.net
