Непонятки с rotate'ом логов NetFlow.
Добрый день.
Коллектор работает в автономном режиме - слушает потоки NetFlow с 2-х источников по разным портам и пишет логи.
Основной трафик проходит через 1-й роутер - большие логи, у 2-го (резервного) - трафик почти нулевой.
Вот вывод команды ./netflow.sh status:
Код:
Traffic collector for IPN v 4.6 build 210 from 27.07.2009 14:43:31
Started: 07.08.2009 10:29:46 Uptime: 0 d 02:38:27
Memory total: 31 129 600; max: 238 616 576; free: 11 305 024
FlowListener: queue_size: 0; threads_active: 0; largest: 1; core: 1; pool_size: 1; recv_socket_buf_size: 131 071; recv_buf_size: 8 388 608; packets: 16685
FlowListener: queue_size: 0; threads_active: 0; largest: 1; core: 1; pool_size: 1; recv_socket_buf_size: 131 071; recv_buf_size: 8 388 608; packets: 118
Flow loader: ru.bitel.bgbilling.server.util.ip.datalog.hourly.IPHourlyDataLogger@58df0438 [files: 2]
Конфиг коллектора:
Код:
...
# *********************************************************
# * Загрузка логов - поток NetFlow сохраняется в лог-файл *
# *********************************************************
#загружать логи
load=1
# Слушаем поток с Cisco 7200 на 20002 порту
collector.capture.flow.port.1=20002
collector.capture.flow.port.1.type=netflow
collector.capture.flow.port.1.sources=1
collector.capture.flow.port.1.thread.count=1
# Поток с Zebra - на 20003
collector.capture.flow.port.2=20003
collector.capture.flow.port.2.type=netflow
collector.capture.flow.port.2.sources=2
collector.capture.flow.port.2.thread.count=1
#
#размер блока (default = 512*1024 = 524364)
datalog.flow.chunk.size=393216
#сжатие логов
datalog.flow.compression.type=1
# *********************************************************
# *********************************************************
# * Обрабока логов - загрузка логов в БД биллинга *
# *********************************************************
#обрабатывать логи
process=1
#код источника Cisco 7200 в БД - 1, Zebra - 2
process.sources=1,2
#количество обработчиков часовых логов
#т.е. если необходимо обработать несколько часов, то их будут обрабатывать указанное кол-во потоков,
#на каждый час - один поток
process.thread.count=1
#количество потоков - обработчиков часового лога
#указанное количество потоков будет обрабатывать часовой лог
#(не действует для старого формата логов и для логов snmp)
process.datalog.thread.count=1
#частота генерации заданий на обработку логов в минутах
#если опция не указана - генерация происходит только на границе часа
generate.minutes=60
# *********************************************************
Слушатели для 2-х источниов сконфигурированы идентично, обрабока (и rotate) должна происходить раз в час - по-умолчанию.
Для первого источника так и есть:
Код:
-rw-r--r-- 1 root root 3507435 Aug 7 12:00 log_2009-08-07-11.000.bgdl
-rw-r--r-- 1 root root 3511054 Aug 7 13:00 log_2009-08-07-12.000.bgdl
-rw-r--r-- 1 root root 129202 Aug 7 13:02 log_2009-08-07-13.000.bgdl
Однако rotate по логам для 2-го источника выполняется как-то непредсказуемо:
Код:
-rw-r--r-- 1 root root 7378 Aug 7 11:09 log_2009-08-07-11.000.bgdl
-rw-r--r-- 1 root root 11485 Aug 7 11:25 log_2009-08-07-11.001.bgdl
-rw-r--r-- 1 root root 7589 Aug 7 11:41 log_2009-08-07-11.002.bgdl
-rw-r--r-- 1 root root 6587 Aug 7 11:57 log_2009-08-07-11.003.bgdl
-rw-r--r-- 1 root root 2549 Aug 7 12:00 log_2009-08-07-11.004.bgdl
-rw-r--r-- 1 root root 6127 Aug 7 12:13 log_2009-08-07-12.000.bgdl
-rw-r--r-- 1 root root 6364 Aug 7 12:29 log_2009-08-07-12.001.bgdl
-rw-r--r-- 1 root root 5748 Aug 7 12:45 log_2009-08-07-12.002.bgdl
-rw-r--r-- 1 root root 5468 Aug 7 13:00 log_2009-08-07-12.003.bgdl
-rw-r--r-- 1 root root 60 Aug 7 13:00 log_2009-08-07-13.000.bgdl
В dataloader.log все в порядке - обработка на границе часа по обоим источникам:
Код:
8-07/12:00:50 INFO [Thread-13] dataloader - Processing source:1 time: 2009-08-07 11:00:00.0
08-07/12:00:51 INFO [Thread-13] dataloader - proccess [ 07-08-2009 11:00:00; mid => 2; param => 1 ] Bean create => 11 Processed lines => 189840; inserts => 129; errors => 0; time => 685 ms.
08-07/12:00:51 INFO [Thread-13] dataloader - Processing source:2 time: 2009-08-07 11:00:00.0
08-07/12:00:51 INFO [Thread-13] dataloader - proccess [ 07-08-2009 11:00:00; mid => 2; param => 2 ] Bean create => 11 Processed lines => 1546; inserts => 13; errors => 0; time => 62 ms.
08-07/13:00:52 INFO [Thread-13] dataloader - Processing source:1 time: 2009-08-07 12:00:00.0
08-07/13:00:53 INFO [Thread-13] dataloader - proccess [ 07-08-2009 12:00:00; mid => 2; param => 1 ] Bean create => 11 Processed lines => 188850; inserts => 130; errors => 0; time => 536 ms.
08-07/13:00:53 INFO [Thread-13] dataloader - Processing source:2 time: 2009-08-07 12:00:00.0
08-07/13:00:53 INFO [Thread-13] dataloader - proccess [ 07-08-2009 12:00:00; mid => 2; param => 2 ] Bean create => 8 Processed lines => 780; inserts => 13; errors => 0; time => 72 ms.
А в loader.conf картина иная:
Код:
08-07/12:00:00 INFO [flow-p-2-t-1] HourlyDataLogEntry - Create dataLog file: /opt/BGBillingServer/Netflow/log/source_1/2009/2009-08/2009-08-07/log_2009-08-07-12.000.bgdl
08-07/12:00:50 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Close dataLog file [/opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-11.004.bgdl]
08-07/12:00:50 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Close dataLog file [/opt/BGBillingServer/Netflow/log/source_1/2009/2009-08/2009-08-07/log_2009-08-07-11.000.bgdl]
08-07/12:00:53 INFO [flow-p-3-t-1] HourlyDataLogEntry - Create dataLog file: /opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-12.000.bgdl
08-07/12:05:46 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=3]...
08-07/12:13:46 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=3]...
08-07/12:13:46 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-12.000.bgdl]
08-07/12:13:48 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Close dataLog file [/opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-12.000.bgdl]
08-07/12:14:24 INFO [flow-p-3-t-1] HourlyDataLogEntry - Create dataLog file: /opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-12.001.bgdl
08-07/12:21:46 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=3]...
08-07/12:29:46 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=3]...
08-07/12:29:46 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-12.001.bgdl]
08-07/12:29:48 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Close dataLog file [/opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-12.001.bgdl]
08-07/12:31:36 INFO [flow-p-3-t-1] HourlyDataLogEntry - Create dataLog file: /opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-12.002.bgdl
08-07/12:37:46 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=3]...
08-07/12:45:46 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=3]...
08-07/12:45:46 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Remove dataLog file from writers map [/opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-12.002.bgdl]
08-07/12:45:48 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Close dataLog file [/opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-12.002.bgdl]
08-07/12:47:50 INFO [flow-p-3-t-1] HourlyDataLogEntry - Create dataLog file: /opt/BGBillingServer/Netflow/log/source_2/2009/2009-08/2009-08-07/log_2009-08-07-12.003.bgdl
08-07/12:53:46 INFO [hrlydtlggr-p-1-t-1] HourlyDataLoggerTracker - Checking data log files to close [hours=3]...
Почему процесс HourlyDataLoggerTracker делает rotate логов каждые 10-15 минут (хотя в конфиге четко сказано, что каждый час), и почему только для второго источника?