День добрый.
Хронология событий была такая (время дано в UTC+2):
Сервер резервного копирования не работал по техническим причинам.
08:10 - сбой сервера по питанию в связи с переключение электричества в помещении с сервером.
09:38 - запуск основного сервера Wialon. Запуск прошел штатно, автоматически. В логах ошибок нет, базы открылись нормально.
Выдержка из trace.log
2015/02/25 09:38:06:764: storage_service::initialize(/var/lib/wialonb3/storage)
2015/02/25 09:38:06:871: storage_service::open_environment: initializing properties environment (cache: size: 16 MB, chunks: 1)...
2015/02/25 09:38:06:872: storage_service::open_environment: preloading databases...
2015/02/25 09:38:17:234: storage_service::open_environment: opening database environment...
2015/02/25 09:38:18:626: storage_service::open_environment: opening databases...
2015/02/25 09:38:18:627: storage_messages_env::open_environment: opening database environment (cache: size: 64 MB, chunks: 1)...
2015/02/25 09:38:55:856: storage_messages_env::open_environment: opening databases...
2015/02/25 09:38:56:310: storage_messages_env::open_environment: registered v2 17 database: left: 0, right: 0, count: 39577942, new-count: 3219169
2015/02/25 09:38:56:318: storage_messages_env::open_environment: registered v2 29 database: left: 0, right: 0, count: 75319561, new-count: 1487196
2015/02/25 09:38:56:318: storage_messages_env::open_environment: registered v2 30 database: left: 0, right: 0, count: 70200526, new-count: 2792198
2015/02/25 09:38:56:336: storage_messages_env::open_environment: registered v2 26 database: left: 0, right: 0, count: 50700462, new-count: 7977000
2015/02/25 09:38:56:336: storage_messages_env::open_environment: registered v2 33 database: left: 0, right: 0, count: 3024490, new-count: 24957
2015/02/25 09:38:56:344: storage_messages_env::open_environment: registered v2 22 database: left: 0, right: 0, count: 56548176, new-count: 11082861
2015/02/25 09:38:56:348: storage_messages_env::open_environment: registered v2 20 database: left: 0, right: 0, count: 58404448, new-count: 5951347
2015/02/25 09:38:56:348: storage_messages_env::open_environment: registered v2 31 database: left: 0, right: 0, count: 45029542, new-count: 3730050
2015/02/25 09:38:56:351: storage_messages_env::open_environment: registered v2 28 database: left: 0, right: 0, count: 117268945, new-count: 21622859
2015/02/25 09:38:56:363: storage_messages_env::open_environment: registered v2 25 database: left: 0, right: 0, count: 54833394, new-count: 1165643
2015/02/25 09:38:56:363: storage_messages_env::open_environment: registered v2 21 database: left: 0, right: 0, count: 47455583, new-count: 8627625
2015/02/25 09:38:56:363: storage_messages_env::open_environment: registered v2 23 database: left: 0, right: 0, count: 35605711, new-count: 3816866
2015/02/25 09:38:56:373: storage_messages_env::open_environment: registered v2 27 database: left: 0, right: 0, count: 87045907, new-count: 8266350
2015/02/25 09:38:56:380: storage_messages_env::open_environment: registered v2 18 database: left: 0, right: 0, count: 47292617, new-count: 1060269
2015/02/25 09:38:56:381: storage_messages_env::open_environment: registered v2 32 database: left: 0, right: 0, count: 25132034, new-count: 3580596
2015/02/25 09:38:56:381: storage_messages_env::open_environment: registered v1 1 database: left: 0, right: -1, count: 11616, new-count: 0
2015/02/25 09:38:56:393: storage_messages_env::open_environment: registered v2 24 database: left: 0, right: 0, count: 34084274, new-count: 3001971
2015/02/25 09:38:56:393: storage_messages_env::open_environment: registered v2 19 database: left: 0, right: 0, count: 52838402, new-count: 3640714
2015/02/25 09:38:56:393: storage_messages_env::open_environment: opened 18 databases with 900373630 messages and 91047671 new messages, fragmentation level is 10%.
09:50 - Поступила информация, что сообщения от объектов не поступают в Web-интерфейс, т.е. нет сообщений от объектов с 8:10. Выборочна проверка логов от устройств показала, что сообщения поступают и в логах отображаются.
09:55 - Было выбрано устройство для проверки. Выяснилось, что сообщения от устройства в логах есть, но через веб-интерфейс не отображаются. В логе ошибок все еще пусто. В основном логе ошибок нет.
10:01 - Предпринята попытка штатно остановить wialon: /etc/init.d/wialonb3 stop
Выдержка из trace.log:
2015/02/25 10:01:34:541: sighandler: 15
2015/02/25 10:01:34:541: sighandler: 15
2015/02/25 10:01:34:541: Stopping ADF service...
2015/02/25 10:01:34:541: adf_terminate()
2015/02/25 10:01:34:541: events_disp::on_adf_terminating: storing HTTP users logout events...
...
2015/02/25 10:01:34:542: events_disp::on_adf_terminating: stored XX HTTP users logout events
2015/02/25 10:01:34:542: avl_server::on_core_terminating('AVL Server')
2015/02/25 10:01:34:542: avl_gsm_device::end_comm('modem1', 'e06da0769f1e0a624da2d9caf3a6bc8f')
2015/02/25 10:01:34:543: avl_gsm_device::end_comm('SMPP', 'ed8876bcd8f1d0dc74bbdcb988962501')
2015/02/25 10:01:34:615: http_service::delete_server('mt_4-hw_start.tcl')
2015/02/25 10:01:34:616: storage_messages_env::on_core_terminating: syncing messages environment...
2015/02/25 10:01:34:617: storage_messages_env::on_core_terminating: done syncing messages environment
Но видимо что-то идет не так и пользователи вновь логинятся на останавливаемый сервер.
2015/02/25 10:01:39:616: Wialon login - user: 'user1'; host: 'XXX.XXX.XXX.XXX'; service: 'maps.baltgps.ru';
2015/02/25 10:01:39:616: storage_user::store_user_history('user' => 'login', 104, 1424851299)
И выполнять отчеты
015/02/25 10:03:52:436: User 'user' executing report '1.отчет подробный ' over object 'XXX' (avl_unit) from '21:00:00 24/02/2015' to '20:59:59' /0/
10:06 - сервис все еще не остановлен, на повторный stop и kill -15 не реагирует, принято решение послать kill -9 и перезапустить сервис.
10:06 - сервис Wialon перезапущен, в логах ошибок нет, файл error.log пустой.по результатам проверки потеряны сообщения за 2 часа с 8:10 до 10:06.
Выдержка из trace.log:
2015/02/25 10:06:27:108: storage_service::initialize(/var/lib/wialonb3/storage)
2015/02/25 10:06:27:109: storage_service::open_environment: initializing properties environment (cache: size: 16 MB, chunks: 1)...
2015/02/25 10:06:27:109: storage_service::open_environment: preloading databases...
2015/02/25 10:06:27:149: storage_service::open_environment: opening database environment...
2015/02/25 10:06:27:479: storage_service::open_environment: opening databases...
2015/02/25 10:06:27:479: storage_messages_env::open_environment: opening database environment (cache: size: 64 MB, chunks: 1)...
2015/02/25 10:06:27:556: storage_messages_env::open_environment: opening databases...
2015/02/25 10:06:27:556: storage_messages_env::open_environment: registered v2 17 database: left: 0, right: 0, count: 39577942, new-count: 3219169
2015/02/25 10:06:27:556: storage_messages_env::open_environment: registered v2 29 database: left: 0, right: 0, count: 75319561, new-count: 1487196
2015/02/25 10:06:27:556: storage_messages_env::open_environment: registered v2 30 database: left: 0, right: 0, count: 70200526, new-count: 2792198
2015/02/25 10:06:27:556: storage_messages_env::open_environment: registered v2 26 database: left: 0, right: 0, count: 50700462, new-count: 7977000
2015/02/25 10:06:27:556: storage_messages_env::open_environment: registered v2 33 database: left: 0, right: 0, count: 3024490, new-count: 24957
2015/02/25 10:06:27:556: storage_messages_env::open_environment: registered v2 22 database: left: 0, right: 0, count: 56548176, new-count: 11082861
2015/02/25 10:06:27:556: storage_messages_env::open_environment: registered v2 20 database: left: 0, right: 0, count: 58404448, new-count: 5951347
2015/02/25 10:06:27:556: storage_messages_env::open_environment: registered v2 31 database: left: 0, right: 0, count: 45029542, new-count: 3730050
2015/02/25 10:06:27:556: storage_messages_env::open_environment: registered v2 28 database: left: 0, right: 0, count: 117268945, new-count: 21622859
2015/02/25 10:06:27:557: storage_messages_env::open_environment: registered v2 25 database: left: 0, right: 0, count: 54833394, new-count: 1165643
2015/02/25 10:06:27:557: storage_messages_env::open_environment: registered v2 21 database: left: 0, right: 0, count: 47455583, new-count: 8627625
2015/02/25 10:06:27:557: storage_messages_env::open_environment: registered v2 23 database: left: 0, right: 0, count: 35605711, new-count: 3816866
2015/02/25 10:06:27:557: storage_messages_env::open_environment: registered v2 27 database: left: 0, right: 0, count: 87045907, new-count: 8266350
2015/02/25 10:06:27:557: storage_messages_env::open_environment: registered v2 18 database: left: 0, right: 0, count: 47292617, new-count: 1060269
2015/02/25 10:06:27:557: storage_messages_env::open_environment: registered v2 32 database: left: 0, right: 0, count: 25132034, new-count: 3580596
2015/02/25 10:06:27:557: storage_messages_env::open_environment: registered v1 1 database: left: 0, right: -1, count: 11616, new-count: 0
2015/02/25 10:06:27:557: storage_messages_env::open_environment: registered v2 24 database: left: 0, right: 0, count: 34084274, new-count: 3001971
2015/02/25 10:06:27:557: storage_messages_env::open_environment: registered v2 19 database: left: 0, right: 0, count: 52838402, new-count: 3640714
2015/02/25 10:06:27:557: storage_messages_env::open_environment: opened 18 databases with 900373630 messages and 91047671 new messages, fragmentation level is 10%.
Так как резервный сервер не был запущен был найден и скопирован, на всякий случай, файл sync.cache.1391175119.
По логам все в порядке - ошибок нет, базы открылись, и сообщения по логам от устройств поступали но в базу они почему-то не попали.