Очень странное поведение proxy

[yanda.a]

Доброго времени суток!
Есть zabbix server, который занимается мониторингом локальных серверов (не более 15). Также, есть zabbix proxy, который собирает данные с серверов в ДЦ. Proxy используется исключительно для того, чтобы минимизировать потери данных при отсутствии связи с ДЦ, так как количество серверов тоже в пределах 15.

Изначально стояла версия 4.2.0, которая отлично работала, пока не выяснилось, что есть проблемы с lld на хостах, работающих через proxy. Ок, обновили zabbix до версии 4.2.7 и началось непонятное поведение. Сначала начал смущать тот факт, что Last Seen прокси не обновлялся. То есть, после перезапуска прокси счетчик времени не сбрасывался. Также, данные с хостов, работающих через proxy приходили с очень большой задержкой (примерно 7 часов), как мы думали. Далее, приняли решение обновиться до актуальной версии - 4.4.0. С счетчиком last seen ситуация не изменилась, как и с неактуальными данными.

К proxy подключен хост, с которого собирается статистика по интерфейса. Также, для этого хоста есть calculated item, который является суммой входящего и исходящего трафика этого интерфейса, и все эти три элемента данных собраны в один график (это важно, так как ниже будет скриншот этого графика). На графике видно, что calculated item актуален по времени, а вот элементы данных, из которых он построен - не совсем, но, как мне кажется, данные актуальны, неактуально время. Время на zabbix server и zabbix proxy идентично, единственное что - различные часовые пояса.



Подскажите, как можно отыскать причину подобного поведения?

[yanda.a]

По поводу графика понял, в принципе это логично. В моем случае получается следующая ситуация. Прокси отправляет данные очень медленно, а сам сервер не смотрит на дату данных, по которым он вычисляет значение (используется last()), вот и получается такой интересный эффект.

Собственно, причина медленной отправки - прокси отправляет данные маленькими порциями, по 10 событий.

End of proxy_get_hist_data() lastid:1860452 records_num:10 size:~815 more:1

И это при том, что события в базе есть (запрос взят из debug-лога):

mysql> select count(*) from proxy_history where id>1860449 order by id limit 991;
+----------+
| count(*) |
+----------+
|   509523 |
+----------+
1 row in set (0.20 sec)

А вот весь вывод лога, относящийся к получения записей из таблицы proxy_history:

25751:20191025:091418.271 In proxy_get_hist_data()
25751:20191025:091418.271 In proxy_get_history_data() lastid:1860422
25751:20191025:091418.279 proxy_get_history_data() 2 record(s) missing. Waiting 0.100000 sec, retrying.
25751:20191025:091418.382 proxy_get_history_data() 2 record(s) missing. No more retries.
25751:20191025:091418.383 proxy_get_history_data() 2 record(s) missing. Waiting 0.100000 sec, retrying.
25751:20191025:091418.486 proxy_get_history_data() 2 record(s) missing. No more retries.
25751:20191025:091418.486 proxy_get_history_data() 2 record(s) missing. Waiting 0.100000 sec, retrying.
25751:20191025:091418.590 proxy_get_history_data() 2 record(s) missing. No more retries.
25751:20191025:091418.596 proxy_get_history_data() 2 record(s) missing. Waiting 0.100000 sec, retrying.
25751:20191025:091418.615 proxy_get_history_data() 2 record(s) missing. No more retries.
25751:20191025:091418.617 proxy_get_history_data() 2 record(s) missing. Waiting 0.100000 sec, retrying.
25751:20191025:091418.721 proxy_get_history_data() 2 record(s) missing. No more retries.
25751:20191025:091418.721 proxy_get_history_data() 2 record(s) missing. Waiting 0.100000 sec, retrying.
25751:20191025:091418.825 proxy_get_history_data() 2 record(s) missing. No more retries.
25751:20191025:091418.825 proxy_get_history_data() 2 record(s) missing. Waiting 0.100000 sec, retrying.
25751:20191025:091418.929 proxy_get_history_data() 2 record(s) missing. No more retries.
25751:20191025:091418.929 proxy_get_history_data() 2 record(s) missing. Waiting 0.100000 sec, retrying.
25751:20191025:091419.033 proxy_get_history_data() 2 record(s) missing. No more retries.
25751:20191025:091419.033 proxy_get_history_data() 2 record(s) missing. Waiting 0.100000 sec, retrying.
25751:20191025:091419.137 proxy_get_history_data() 2 record(s) missing. No more retries.
25751:20191025:091419.137 proxy_get_history_data() 2 record(s) missing. Waiting 0.100000 sec, retrying.
25751:20191025:091419.240 proxy_get_history_data() 2 record(s) missing. No more retries.
25751:20191025:091419.240 End of proxy_get_history_data() data_num:10
25751:20191025:091419.240 End of proxy_get_hist_data() lastid:1860452 records_num:10 size:~815 more:1

А вот функция:

static int    proxy_get_history_data(zbx_uint64_t lastid, zbx_history_data_t **data, size_t *data_alloc,
        char **string_buffer, size_t *string_buffer_alloc, int *more)
{
...
    int            retries = 1, total_retries = 10;
...

try_again:
...

    while (NULL != (row = DBfetch(result)))
    {
...
        if (1 < id - lastid)
        {
            /* At least one record is missing. It can happen if some DB syncer process has */
            /* started but not yet committed a transaction or a rollback occurred in a DB syncer. */
            if (0 < retries--)
            {
                /* limit the number of total retries to avoid being stuck */
                /* in history full of 'holes' for a long time             */
                if (0 >= total_retries--)
                    break;

                DBfree_result(result);
                zabbix_log(LOG_LEVEL_DEBUG, "%s() " ZBX_FS_UI64 " record(s) missing."
                        " Waiting " ZBX_FS_DBL " sec, retrying.",
                        __func__, id - lastid - 1,
                        t_sleep.tv_sec + t_sleep.tv_nsec / 1e9);
                nanosleep(&t_sleep, &t_rem);
                goto try_again;
            }
            else
            {
                zabbix_log(LOG_LEVEL_DEBUG, "%s() " ZBX_FS_UI64 " record(s) missing. No more retries.",
                        __func__, id - lastid - 1);
            }
        }

        retries = 1;

 ...

    if (ZBX_MAX_HRECORDS != data_num && 1 == retries)
        *more = ZBX_PROXY_DATA_DONE;

    zabbix_log(LOG_LEVEL_DEBUG, "End of %s() data_num:" ZBX_FS_SIZE_T, __func__, data_num);

    return data_num;
}

Здесь немного подробнее. Zabbix думает, что history syncer не успел закоммитить транзакцию и пытается сделать повторную попытку прочесть записи из базы. За каждую итерацию он получает только одну запись. Так как количество попыток 10 - мы имеем ровно 10 записей на выходе, вместо 1000.

Теперь вопрос, почему у нас есть разрывы в primary key. Дело в том, что в нашем окружении используется galera cluster, а для него рекомендуется использовать auto_increment_increment > 1.

PS: это уже не вопрос, а скорее объяснение происходящего, вдруг кому поможет.