Стабильность работы биллинга

Технические вопросы по UTM 5.0

Насколько стабильно работает ваша биллинговая система, до появления сбоя:

не более 1 часа непрерывной работы
0
Голосов нет
не более 3 часов непрерывной работы
0
Голосов нет
не более 6 часов непрерывной работы
0
Голосов нет
не более 12 часов непрерывной работы
4
14%
не более 1 суток непрерывной работы
3
11%
не более 3 суток непрерывной работы
0
Голосов нет
не более 7 суток непрерывной работы
5
18%
не более 14 суток непрерывной работы
1
4%
не более 30 суток непрерывной работы
15
54%
 
Всего голосов: 28

PEBA
Сообщения: 15
Зарегистрирован: Вт май 06, 2008 22:44

Стабильность работы биллинга

Сообщение PEBA »

Сталкивались ли с проблемой:

В хоте тестовой работы системы 5.2.1-005 выявлены ряд недостатков. А именно:
1. Постоянные зависания ядра системы (в логи ничего не пишет), при чем очень странно. Помогает лишь перезапуск сервера полностью.
Перестает производится запись в базу о трафике, не работает администрирование(админка просто виснет при запуске), не рабоает rfw (не добавляет записи в фаерволл, в лог пишет все время StreamFirewall: Got ping from core. Sending reply...) , только работает РАДИУС сервер (продолжает авторизировать пользователей).

2. Работа радиус сервера не удолетварительна, после нескольких часов интенсивной работы начинает выдавать уже ранее выданные IP из пула адресов которые есть в текущий момент у клиентов.
При чем настройки таймаутов не изменялись - все по умолчанию. До конца пула тоже не доходит.

Нагрузка создавалась в реальной сети при тесте одновременно 200 компов.
Если инетересуют подробные сведения(конфиги, логи) - напишу.

Проблемы вобще решаемые? или это проблема самого контруктива?
И стоит просто обратить внимание на другие платные биллинговые системы?

init
Сообщения: 123
Зарегистрирован: Пт окт 14, 2005 06:15

Сообщение init »

А почему нет варианта "более 30 суток непрерывной работы"? Мне такой нужен.

DiKe
Сообщения: 13
Зарегистрирован: Чт май 01, 2008 11:41

Сообщение DiKe »

Последний вариант. Просто после покупки не прошло больше...
Вот непонимаю а что вы хотите от биллинговой системы за 20 т.р.? Есть системы и за 10 т. у.е. и они так же с глюками.
В основном УТМ берется из-за сертификата, а если траблы появляются и решить их вам не в силу, обращайтесь в саппорт. иначе просто нет смысла брать его...
ИМХО

Аватара пользователя
Dewil
Сообщения: 82
Зарегистрирован: Вт окт 24, 2006 07:58
Откуда: Алтай
Контактная информация:

Сообщение Dewil »

Работать может и несколько месяцев без перезагрузки (пока не тормознешь на профилактику). В самом начале работы с этой биллинговой системой конечно были "глюки", сейчас, когда все отлажено, их фактически не наблюдается. Бывают случаи конечно когда сам что-то неправильно сделаешь, но это уже человеческий фактор:)

В целом, для этой ценовой категории, все работает стабильно. Многий функционал конечно реализован не так как хотелось бы, но тут опять же - ждать чего-то фантастического за 1-2к нельзя.

serjk
NetUP Team
Сообщения: 719
Зарегистрирован: Пн авг 14, 2006 08:56

Re: Стабильность работы биллинга

Сообщение serjk »

PEBA писал(а):Сталкивались ли с проблемой:

В хоте тестовой работы системы 5.2.1-005 выявлены ряд недостатков. А именно:
1. Постоянные зависания ядра системы (в логи ничего не пишет), при чем очень странно. Помогает лишь перезапуск сервера полностью.
Перестает производится запись в базу о трафике, не работает администрирование(админка просто виснет при запуске), не рабоает rfw (не добавляет записи в фаерволл, в лог пишет все время StreamFirewall: Got ping from core. Sending reply...) , только работает РАДИУС сервер (продолжает авторизировать пользователей).
системы?
Приведите конец debug.log в момент зависания. Какую БД вы используете?

Аватара пользователя
Magnum72
Сообщения: 1947
Зарегистрирован: Чт сен 22, 2005 06:54
Контактная информация:

Re: Стабильность работы биллинга

Сообщение Magnum72 »

serjk писал(а): Приведите конец debug.log в момент зависания. Какую БД вы используете?
А толку?

У меня пошли последнее время двойные блокировки, на мое обращение в хотлайн (тикет номер 2008050410000021) меня попросили предоставить дебаг лог, но у меня ротация 15 500 меговых файлов происходит меньше чем за сутки (все благодаря тому что вы уже третий год не можете сделать степерь деталицации логов), а первый ответ хотлайна был спустя двое суток (это при подключенной услуге мониторинга и тех обеспечения). На мое сообщение о том что это уже невозможно был дан ответ:
"К сожалению, без этой информации диагностика проблемы невозможна."

А нафига ее диагностировать скажите? Для того чтобы небыло двойных блокировок надо просто или добавить проверку на уже существование блокировки на аккаунте, или при снятии удалять блокировки не по ид, а по аккаунту..

Второй тикет открытый 2008050510000056 касающийся падений биллинга, меня просят предоставить дамп базы, скажите зачем? Вы имеете доступ к моему серверу и к базе данных...

Мне это напоминает анекдот про Олимпиаду 80 в Москве и туалетную бумагу в магазинах..

PEBA
Сообщения: 15
Зарегистрирован: Вт май 06, 2008 22:44

Re: Стабильность работы биллинга

Сообщение PEBA »

serjk писал(а): Приведите конец debug.log в момент зависания. Какую БД вы используете?
База INNODB.
Лог дебага в какой момент ?
Когда по второй проблеме ? когда начинает выдавать уже занятые IP с начала пула? тогда там лог оргомный только на почту
если по поводу зависания ядра то вот один из кусков
в момент 22:18:27 еще работает . Потом болт как видно из лога.

------------------------------------------------------
?Debug : Apr 28 22:18:27 UTM5 DBA: Checking for rehash: flags 3, balance 2.535 (old 2.535), credit 0.000
?Debug : Apr 28 22:18:27 Radius: Account '639': 2.535/0.000 send...
?Debug : Apr 28 22:18:27 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b600cedc
?Debug : Apr 28 22:18:27 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b600cedc
?Debug : Apr 28 22:18:27 DBCtx: SQL query: UPDATE accounts SET balance='2.5348' WHERE id = '639'
?Debug : Apr 28 22:18:27 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,
?Debug : Apr 28 22:18:27 BusLogic: currently blm with code 38 executing
?Debug : Apr 28 22:18:27 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 28 22:18:27 DBCtx: SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='14923245' WHERE id='297222'
?Debug : Apr 28 22:18:27 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_da
?Debug : Apr 28 22:18:27 DBCtx: SQL query: COMMIT
?Debug : Apr 28 22:18:27 DBCtx: DB transaction commit
?Debug : Apr 28 22:18:27 DBA:Ctx: Pushing back free context
-Stats : Apr 28 22:18:27 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 28 22:18:27 BusClassif: aggregation interval reached for slink <6567> ip <-1408199604> tclass <10>
?Debug : Apr 28 22:18:27 UTM5 DBA: DBAccess instance created
?Debug : Apr 28 22:18:27 DBA:Ctx: Looking for free context
?Debug : Apr 28 22:18:27 DBCtx: SQL query: BEGIN
?Debug : Apr 28 22:18:27 DBCtx: DB transaction begin
?Debug : Apr 28 22:18:27 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='1105' AND tclass_id='10'
?Debug : Apr 28 22:18:27 DBCtx: SQL query: UPDATE downloaded SET qnt='552022870', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='1105' AND tclass_id='10'
?Debug : Apr 28 22:18:27 UTM5 DBA: Discount:0.000000 p.u. for link:6567 account 1781
?Debug : Apr 28 22:18:27 UTM5 DBA: Checking for rehash: flags 3, balance 375.286 (old 375.286), credit 400.000
?Debug : Apr 28 22:18:27 Radius: Account '1781': 375.286/400.000 send...
?Debug : Apr 28 22:18:27 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b600cedc
?Debug : Apr 28 22:18:27 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b600cedc
?Debug : Apr 28 22:18:27 DBCtx: SQL query: UPDATE accounts SET balance='375.286' WHERE id = '1781'
?Debug : Apr 28 22:18:27 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,
?Debug : Apr 28 22:18:27 BusLogic: currently blm with code 38 executing
?Debug : Apr 28 22:18:27 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 28 22:18:27 DBCtx: SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='425837098' WHERE id='297367'
?Debug : Apr 28 22:18:27 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_da
?Debug : Apr 28 22:18:27 DBCtx: SQL query: COMMIT
?Debug : Apr 28 22:18:27 DBCtx: DB transaction commit
?Debug : Apr 28 22:18:27 DBA:Ctx: Pushing back free context
-Stats : Apr 28 22:18:27 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 28 22:18:50 FW@127.0.0.1: Ping reply received
?Debug : Apr 28 22:19:20 FW@127.0.0.1: Ping reply received
Info : Apr 28 22:19:31 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:36351
Info : Apr 28 22:19:31 RPCConn: Connection from: 127.0.0.1:36351
Info : Apr 28 22:19:31 RPCConn<natuska1803@10.0.4.112>: Access granted to <natuska1803@10.0.4.112> (UID: 918)
Info : Apr 28 22:19:31 RPCConn<natuska1803@10.0.4.112>: Connection terminated by peer
?Debug : Apr 28 22:19:31 RPCConn<natuska1803@10.0.4.112>: Session stored for UID 918 and IP 7004000a
?Debug : Apr 28 22:19:31 RPCConn<natuska1803@10.0.4.112>: Session closed...
Info : Apr 28 22:19:32 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:36352
Info : Apr 28 22:19:32 RPCConn: Connection from: 127.0.0.1:36352
Notice: Apr 28 22:19:32 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 28 22:19:32 RPCConn: Session restored for <natuska1803@10.0.4.112>
Info : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Access granted to <natuska1803@10.0.4.112> (UID: 918)
?Debug : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Real Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 28 22:19:32 DBCtx: SQL SELECT query: SELECT login, password, basic_account, is_blocked, create_date, last_change_date,
?Debug : Apr 28 22:19:32 DBCtx: SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='918'
?Debug : Apr 28 22:19:32 DBCtx: SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='918'
?Debug : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Call 0xffffbffa (__rpcs_get_user_info) finished...
?Debug : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Stream cleared
?Debug : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Real Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Call 0xffffbfab (__rpcs_user5_get_accounts) finished...
?Debug : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Stream cleared
Info : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Connection terminated by peer
?Debug : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Session stored for UID 918 and IP 7004000a
?Debug : Apr 28 22:19:32 RPCConn<natuska1803@10.0.4.112>: Session closed...
?Debug : Apr 28 22:19:50 FW@127.0.0.1: Ping reply received
?Debug : Apr 28 22:20:20 FW@127.0.0.1: Ping reply received
Info : Apr 28 22:20:50 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:47160
Info : Apr 28 22:20:50 RPCConn: Connection from: 127.0.0.1:47160
Info : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Access granted to <alexa@10.0.2.240> (UID: 772)
Info : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Connection terminated by peer
?Debug : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Session stored for UID 772 and IP f002000a
?Debug : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Session closed...
Info : Apr 28 22:20:50 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:47161
Info : Apr 28 22:20:50 RPCConn: Connection from: 127.0.0.1:47161
Notice: Apr 28 22:20:50 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 28 22:20:50 RPCConn: Session restored for <alexa@10.0.2.240>
Info : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Access granted to <alexa@10.0.2.240> (UID: 772)
?Debug : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Real Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 28 22:20:50 DBCtx: SQL SELECT query: SELECT login, password, basic_account, is_blocked, create_date, last_change_date,
?Debug : Apr 28 22:20:50 DBCtx: SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='772'
?Debug : Apr 28 22:20:50 DBCtx: SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='772'
?Debug : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Call 0xffffbffa (__rpcs_get_user_info) finished...
?Debug : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Stream cleared
?Debug : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Real Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Call 0xffffbfab (__rpcs_user5_get_accounts) finished...
?Debug : Apr 28 22:20:50 RPCConn<alexa@10.0.2.240>: Stream cleared

PEBA
Сообщения: 15
Зарегистрирован: Вт май 06, 2008 22:44

Re: Стабильность работы биллинга

Сообщение PEBA »

Magnum72 писал(а):
serjk писал(а): Приведите конец debug.log в момент зависания. Какую БД вы используете?
А толку?

У меня пошли последнее время двойные блокировки, на мое обращение в хотлайн (тикет номер 2008050410000021) меня попросили предоставить дебаг лог, но у меня ротация 15 500 меговых файлов происходит меньше чем за сутки (все благодаря тому что вы уже третий год не можете сделать степерь деталицации логов), а первый ответ хотлайна был спустя двое суток (это при подключенной услуге мониторинга и тех обеспечения). На мое сообщение о том что это уже невозможно был дан ответ:
"К сожалению, без этой информации диагностика проблемы невозможна."

А нафига ее диагностировать скажите? Для того чтобы небыло двойных блокировок надо просто или добавить проверку на уже существование блокировки на аккаунте, или при снятии удалять блокировки не по ид, а по аккаунту..

Второй тикет открытый 2008050510000056 касающийся падений биллинга, меня просят предоставить дамп базы, скажите зачем? Вы имеете доступ к моему серверу и к базе данных...

Мне это напоминает анекдот про Олимпиаду 80 в Москве и туалетную бумагу в магазинах..
Увы тогда какой толк в тех. поддержке вообще?
Уже 7 мая проблема была устраненна?

Аватара пользователя
XoRe
Сообщения: 458
Зарегистрирован: Ср янв 10, 2007 16:04

Re: Стабильность работы биллинга

Сообщение XoRe »

PEBA писал(а):Проблемы вобще решаемые? или это проблема самого контруктива?
Имхо, это проблема вашей ситуации.
Биллинг может работать месяцами без перезагрузки, зависаний и глюков.
Напишите, какая у вас ОС, какое железо, сколько места на разделах, какая средняя загрузка системы, и собсно какая версия биллинга стоит и т.д.

P.S.
У вас стоит демоверсия?

PEBA
Сообщения: 15
Зарегистрирован: Вт май 06, 2008 22:44

Re: Стабильность работы биллинга

Сообщение PEBA »

XoRe писал(а): Имхо, это проблема вашей ситуации.
Биллинг может работать месяцами без перезагрузки, зависаний и глюков.
Не могу отрицать того что сделали мы все идеально.
Но за месаца не верю... мы же не дети, что бы верить в сказки :)
XoRe писал(а): Напишите, какая у вас ОС, какое железо, сколько места на разделах, какая средняя загрузка системы, и собсно какая версия биллинга стоит и т.д.
Debian, 4*2.4Ггц/2Гб/2*500Гб

Файловая система Разм Исп Дост Исп% смонтирована на
/dev/sda3 182G 48G 98G 33% /
tmpfs 1010M 0 1010M 0% /lib/init/rw
udev 10M 40K 10M 1% /dev
tmpfs 1010M 0 1010M 0% /dev/shm
/dev/sda1 183M 12M 133M 9% /boot
/dev/drbd0 184G 49G 126G 28% /sync_database


Загрузка машины
18:59:30 up 5:00, 341 users, load average: 1.20, 1.13, 1.04

Памяти
Mem: 2066676k total, 2007252k used, 59424k free, 129324k buffers
Swap: 1951888k total, 352k used, 1951536k free, 1338308k cached

Нагрузка создается реальными клиентами, под заманчивым бесплатным доступом, что создает хорошие пиковые нагрузки.

Версия для теста выбрана 5.2.1-005 не демо, так как руководство перед покупкой, для смены старой самописной билинг системы, поставило задачу проверить и сделать оценку. И мне как админу положить голову за продукт который себя так будет вести, не очень хочется. Ведь обслуживать буду его я, значит и крайний буду я. А качество услуги прежде всего...

работает очень странно, иногда и держится сервер и 2 дня, а обычно часов 6-10 после чего происходит сбой чего либо...
То радиус глючит, то ядро виснет. Ну а про самопроизвольное отключение инета уже молчу...

serjk
NetUP Team
Сообщения: 719
Зарегистрирован: Пн авг 14, 2006 08:56

Сообщение serjk »

Из приведенного вами участка лога видно только, что система работает в нормальном режиме. Нужен конец лога в тот момент, когда ядро перестало отвечать на запросы админки. Например, запустить админку, и, увидев, что она не загружается до конца, скопировать конец debug.log

PEBA
Сообщения: 15
Зарегистрирован: Вт май 06, 2008 22:44

Сообщение PEBA »

serjk писал(а):Из приведенного вами участка лога видно только, что система работает в нормальном режиме. Нужен конец лога в тот момент, когда ядро перестало отвечать на запросы админки. Например, запустить админку, и, увидев, что она не загружается до конца, скопировать конец debug.log
Хорошо, ротация логов уже вытеснила, но ждать следующего раза не долго надо:)
З.Ы. 10метров детального лога набегает за 15 минут :) вот это скорость :)

PEBA
Сообщения: 15
Зарегистрирован: Вт май 06, 2008 22:44

Сообщение PEBA »

serjk писал(а):Из приведенного вами участка лога видно только, что система работает в нормальном режиме. Нужен конец лога в тот момент, когда ядро перестало отвечать на запросы админки. Например, запустить админку, и, увидев, что она не загружается до конца, скопировать конец debug.log
вот что то в старых логах нашел
?Debug : Apr 29 09:46:34 BusClassif: aggregation interval reached for slink <7871> ip <-1408200636> tclass <10>
?Debug : Apr 29 09:46:34 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:46:34 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:46:34 DBCtx: SQL query: BEGIN
?Debug : Apr 29 09:46:34 DBCtx: DB transaction begin
?Debug : Apr 29 09:46:34 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='317' AND tclass_id='10'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE downloaded SET qnt='300426282', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='317' AND tclass_id='10'
?Debug : Apr 29 09:46:34 UTM5 DBA: Discount:0.000000 p.u. for link:7871 account 119
?Debug : Apr 29 09:46:34 UTM5 DBA: Checking for rehash: flags 3, balance 6.218 (old 6.218), credit 2.000
?Debug : Apr 29 09:46:34 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 Radius: Account '119': 6.218/2.000 send...
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE accounts SET balance='6.218' WHERE id = '119'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,discount_date,comment,discount_period_id) VALUES('119','6.218','6.218','0','0','0','148','3','7871','1209451594','IP discount','1201')
?Debug : Apr 29 09:46:34 BusLogic: currently blm with code 39 executing
?Debug : Apr 29 09:46:34 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='635963' WHERE id='300063'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('1319037','119','0','0','148','7871','1209451594','1209448800','1209416400','1206997200','10','0','-1408200636','1555','1201')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: COMMIT
?Debug : Apr 29 09:46:34 DBCtx: DB transaction commit
?Debug : Apr 29 09:46:34 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:46:34 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:46:34 BusClassif: aggregation interval reached for slink <7185> ip <-1408200693> tclass <10>
?Debug : Apr 29 09:46:34 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:46:34 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:46:34 DBCtx: SQL query: BEGIN
?Debug : Apr 29 09:46:34 DBCtx: DB transaction begin
?Debug : Apr 29 09:46:34 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='1168' AND tclass_id='10'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE downloaded SET qnt='70883726', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='1168' AND tclass_id='10'
?Debug : Apr 29 09:46:34 UTM5 DBA: Discount:0.000000 p.u. for link:7185 account 1899
?Debug : Apr 29 09:46:34 UTM5 DBA: Checking for rehash: flags 3, balance 106.023 (old 106.023), credit 0.000
?Debug : Apr 29 09:46:34 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 Radius: Account '1899': 106.023/0.000 send...
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE accounts SET balance='106.023' WHERE id = '1899'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,discount_date,comment,discount_period_id) VALUES('1899','106.023','106.023','0','0','0','144','3','7185','1209451594','IP discount','1201')
?Debug : Apr 29 09:46:34 BusLogic: currently blm with code 39 executing
?Debug : Apr 29 09:46:34 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='1081742' WHERE id='300168'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('1319038','1899','0','0','144','7185','1209451594','1209448800','1209416400','1206997200','10','0','-1408200693','795','1201')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: COMMIT
?Debug : Apr 29 09:46:34 DBCtx: DB transaction commit
?Debug : Apr 29 09:46:34 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:46:34 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:46:34 BusClassif: aggregation interval reached for slink <8521> ip <-1408200687> tclass <20>
?Debug : Apr 29 09:46:34 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:46:34 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:46:34 DBCtx: SQL query: BEGIN
?Debug : Apr 29 09:46:34 DBCtx: DB transaction begin
?Debug : Apr 29 09:46:34 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='925' AND tclass_id='20'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE downloaded SET qnt='41180880', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='925' AND tclass_id='20'
?Debug : Apr 29 09:46:34 UTM5 DBA: Discount:0.000000 p.u. for link:8521 account 13
?Debug : Apr 29 09:46:34 UTM5 DBA: Checking for rehash: flags 3, balance -317.914 (old -317.914), credit 400.000
?Debug : Apr 29 09:46:34 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 Radius: Account '13': -317.914/400.000 send...
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE accounts SET balance='-317.914' WHERE id = '13'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,discount_date,comment,discount_period_id) VALUES('13','-317.914','-317.914','0','0','0','140','3','8521','1209451594','IP discount','1201')
?Debug : Apr 29 09:46:34 BusLogic: currently blm with code 39 executing
?Debug : Apr 29 09:46:34 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='91528' WHERE id='299979'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('1319039','13','0','0','140','8521','1209451594','1209448800','1209416400','1206997200','20','0','-1408200687','4938','1201')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: COMMIT
?Debug : Apr 29 09:46:34 DBCtx: DB transaction commit
?Debug : Apr 29 09:46:34 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:46:34 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:46:34 BusClassif: aggregation interval reached for slink <7598> ip <-1408200610> tclass <20>
?Debug : Apr 29 09:46:34 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:46:34 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:46:34 DBCtx: SQL query: BEGIN
?Debug : Apr 29 09:46:34 DBCtx: DB transaction begin
?Debug : Apr 29 09:46:34 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='1298' AND tclass_id='20'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE downloaded SET qnt='26056034', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='1298' AND tclass_id='20'
?Debug : Apr 29 09:46:34 UTM5 DBA: Discount:0.000000 p.u. for link:7598 account 2113
?Debug : Apr 29 09:46:34 UTM5 DBA: Checking for rehash: flags 3, balance 2.256 (old 2.256), credit 0.000
?Debug : Apr 29 09:46:34 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 Radius: Account '2113': 2.256/0.000 send...
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE accounts SET balance='2.256' WHERE id = '2113'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,discount_date,comment,discount_period_id) VALUES('2113','2.256','2.256','0','0','0','144','3','7598','1209451594','IP discount','1201')
?Debug : Apr 29 09:46:34 BusLogic: currently blm with code 39 executing
?Debug : Apr 29 09:46:34 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO dtagg_iptraffic(slink_id, discounted,discounted_without_tax, base_cost, bytes, tclass, ipid) VALUES('7598','0.000000','0.000000','0.000000','96', '20', '-1408200610')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('1319040','2113','0','0','144','7598','1209451594','1209448800','1209416400','1206997200','20','0','-1408200610','96','1201')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: COMMIT
?Debug : Apr 29 09:46:34 DBCtx: DB transaction commit
?Debug : Apr 29 09:46:34 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:46:34 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:46:34 BusClassif: aggregation interval reached for slink <7185> ip <-1408200693> tclass <20>
?Debug : Apr 29 09:46:34 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:46:34 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:46:34 DBCtx: SQL query: BEGIN
?Debug : Apr 29 09:46:34 DBCtx: DB transaction begin
?Debug : Apr 29 09:46:34 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='1168' AND tclass_id='20'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE downloaded SET qnt='6825951', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='1168' AND tclass_id='20'
?Debug : Apr 29 09:46:34 UTM5 DBA: Discount:0.000000 p.u. for link:7185 account 1899
?Debug : Apr 29 09:46:34 UTM5 DBA: Checking for rehash: flags 3, balance 106.023 (old 106.023), credit 0.000
?Debug : Apr 29 09:46:34 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 Radius: Account '1899': 106.023/0.000 send...
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE accounts SET balance='106.023' WHERE id = '1899'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,discount_date,comment,discount_period_id) VALUES('1899','106.023','106.023','0','0','0','144','3','7185','1209451594','IP discount','1201')
?Debug : Apr 29 09:46:34 BusLogic: currently blm with code 39 executing
?Debug : Apr 29 09:46:34 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='41665' WHERE id='300169'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('1319041','1899','0','0','144','7185','1209451594','1209448800','1209416400','1206997200','20','0','-1408200693','1976','1201')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: COMMIT
?Debug : Apr 29 09:46:34 DBCtx: DB transaction commit
?Debug : Apr 29 09:46:34 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:46:34 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:46:34 BusClassif: aggregation interval reached for slink <7143> ip <-1408204751> tclass <20>
?Debug : Apr 29 09:46:34 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:46:34 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:46:34 DBCtx: SQL query: BEGIN
?Debug : Apr 29 09:46:34 DBCtx: DB transaction begin
?Debug : Apr 29 09:46:34 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='425' AND tclass_id='20'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE downloaded SET qnt='8000976', discounted='0', downed_as_prepaid='10081' WHERE downloaded_id='425' AND tclass_id='20'
?Debug : Apr 29 09:46:34 UTM5 DBA: Discount:0.000000 p.u. for link:7143 account 677
?Debug : Apr 29 09:46:34 UTM5 DBA: Checking for rehash: flags 3, balance 14.614 (old 14.614), credit 0.000
?Debug : Apr 29 09:46:34 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 Radius: Account '677': 14.614/0.000 send...
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE accounts SET balance='14.6136' WHERE id = '677'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,discount_date,comment,discount_period_id) VALUES('677','14.6136','14.6136','0','0','0','23','3','7143','1209451594','IP discount','1201')
?Debug : Apr 29 09:46:34 BusLogic: currently blm with code 39 executing
?Debug : Apr 29 09:46:34 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='3380293' WHERE id='299026'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('1319042','677','0','0','23','7143','1209451594','1209448800','1209416400','1206997200','20','0','-1408204751','4848','1201')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: COMMIT
?Debug : Apr 29 09:46:34 DBCtx: DB transaction commit
?Debug : Apr 29 09:46:34 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:46:34 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:46:34 BusClassif: aggregation interval reached for slink <3569> ip <-1408204779> tclass <20>
?Debug : Apr 29 09:46:34 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:46:34 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:46:34 DBCtx: SQL query: BEGIN
?Debug : Apr 29 09:46:34 DBCtx: DB transaction begin
?Debug : Apr 29 09:46:34 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='711' AND tclass_id='20'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE downloaded SET qnt='14740202', discounted='0', downed_as_prepaid='40493' WHERE downloaded_id='711' AND tclass_id='20'
?Debug : Apr 29 09:46:34 UTM5 DBA: Discount:0.000000 p.u. for link:3569 account 1147
?Debug : Apr 29 09:46:34 UTM5 DBA: Checking for rehash: flags 3, balance 0.280 (old 0.280), credit 0.000
?Debug : Apr 29 09:46:34 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 Radius: Account '1147': 0.280/0.000 send...
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE accounts SET balance='0.2803' WHERE id = '1147'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,discount_date,comment,discount_period_id) VALUES('1147','0.2803','0.2803','0','0','0','23','3','3569','1209451594','IP discount','1201')
?Debug : Apr 29 09:46:34 BusLogic: currently blm with code 39 executing
?Debug : Apr 29 09:46:34 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='320' WHERE id='300160'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('1319043','1147','0','0','23','3569','1209451594','1209448800','1209416400','1206997200','20','0','-1408204779','120','1201')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: COMMIT
?Debug : Apr 29 09:46:34 DBCtx: DB transaction commit
?Debug : Apr 29 09:46:34 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:46:34 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:46:34 BusClassif: aggregation interval reached for slink <1760> ip <-1408204752> tclass <10>
?Debug : Apr 29 09:46:34 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:46:34 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:46:34 DBCtx: SQL query: BEGIN
?Debug : Apr 29 09:46:34 DBCtx: DB transaction begin
?Debug : Apr 29 09:46:34 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='410' AND tclass_id='10'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE downloaded SET qnt='21150716', discounted='0', downed_as_prepaid='21150716' WHERE downloaded_id='410' AND tclass_id='10'
?Debug : Apr 29 09:46:34 UTM5 DBA: Discount:0.000000 p.u. for link:1760 account 647
?Debug : Apr 29 09:46:34 UTM5 DBA: Checking for rehash: flags 3, balance 49.438 (old 49.438), credit 0.000
?Debug : Apr 29 09:46:34 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 Radius: Account '647': 49.438/0.000 send...
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE accounts SET balance='49.4385' WHERE id = '647'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,discount_date,comment,discount_period_id) VALUES('647','49.4385','49.4385','0','0','0','23','3','1760','1209451594','IP discount','1201')
?Debug : Apr 29 09:46:34 BusLogic: currently blm with code 39 executing
?Debug : Apr 29 09:46:34 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='2308509' WHERE id='298170'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('1319044','647','0','0','23','1760','1209451594','1209448800','1209416400','1206997200','10','0','-1408204752','80','1201')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: COMMIT
?Debug : Apr 29 09:46:34 DBCtx: DB transaction commit
?Debug : Apr 29 09:46:34 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:46:34 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:46:34 BusClassif: aggregation interval reached for slink <1760> ip <-1408204752> tclass <20>
?Debug : Apr 29 09:46:34 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:46:34 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:46:34 DBCtx: SQL query: BEGIN
?Debug : Apr 29 09:46:34 DBCtx: DB transaction begin
?Debug : Apr 29 09:46:34 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='410' AND tclass_id='20'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE downloaded SET qnt='9431478', discounted='0', downed_as_prepaid='91726' WHERE downloaded_id='410' AND tclass_id='20'
?Debug : Apr 29 09:46:34 UTM5 DBA: Discount:0.000000 p.u. for link:1760 account 647
?Debug : Apr 29 09:46:34 UTM5 DBA: Checking for rehash: flags 3, balance 49.438 (old 49.438), credit 0.000
?Debug : Apr 29 09:46:34 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 Radius: Account '647': 49.438/0.000 send...
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE accounts SET balance='49.4385' WHERE id = '647'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,discount_date,comment,discount_period_id) VALUES('647','49.4385','49.4385','0','0','0','23','3','1760','1209451594','IP discount','1201')
?Debug : Apr 29 09:46:34 BusLogic: currently blm with code 39 executing
?Debug : Apr 29 09:46:34 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE dtagg_iptraffic SET discounted='0.000000', discounted_without_tax='0.000000', bytes='1194003' WHERE id='298169'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('1319045','647','0','0','23','1760','1209451594','1209448800','1209416400','1206997200','20','0','-1408204752','80','1201')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: COMMIT
?Debug : Apr 29 09:46:34 DBCtx: DB transaction commit
?Debug : Apr 29 09:46:34 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:46:34 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:46:34 BusClassif: aggregation interval reached for slink <8432> ip <-1408200607> tclass <20>
?Debug : Apr 29 09:46:34 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:46:34 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:46:34 DBCtx: SQL query: BEGIN
?Debug : Apr 29 09:46:34 DBCtx: DB transaction begin
?Debug : Apr 29 09:46:34 DBCtx: SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='1437' AND tclass_id='20'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE downloaded SET qnt='25721660', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='1437' AND tclass_id='20'
?Debug : Apr 29 09:46:34 UTM5 DBA: Discount:0.000000 p.u. for link:8432 account 1719
?Debug : Apr 29 09:46:34 UTM5 DBA: Checking for rehash: flags 3, balance 0.671 (old 0.671), credit 0.000
?Debug : Apr 29 09:46:34 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 HSPlugin: Rehash: Target: 10; Action: 1; Ptr: b6003edc
?Debug : Apr 29 09:46:34 Radius: Account '1719': 0.671/0.000 send...
?Debug : Apr 29 09:46:34 DBCtx: SQL query: UPDATE accounts SET balance='0.6707' WHERE id = '1719'
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_without_tax,discount_with_tax,service_id,service_type,slink_id,discount_date,comment,discount_period_id) VALUES('1719','0.6707','0.6707','0','0','0','148','3','8432','1209451594','IP discount','1201')
?Debug : Apr 29 09:46:34 BusLogic: currently blm with code 39 executing
?Debug : Apr 29 09:46:34 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO dtagg_iptraffic(slink_id, discounted,discounted_without_tax, base_cost, bytes, tclass, ipid) VALUES('8432','0.000000','0.000000','0.000000','192', '20', '-1408200607')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: INSERT INTO discount_transactions_iptraffic_all(id,account_id,discount,discount_with_tax,service_id,slink_id,discount_date,discount_date_hour,discount_date_day,discount_date_month,t_class,base_cost,ipid,bytes,discount_period_id) VALUES('1319046','1719','0','0','148','8432','1209451594','1209448800','1209416400','1206997200','20','0','-1408200607','192','1201')
?Debug : Apr 29 09:46:34 DBCtx: SQL query: COMMIT
?Debug : Apr 29 09:46:34 DBCtx: DB transaction commit
?Debug : Apr 29 09:46:34 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:46:34 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:46:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:47:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:47:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:48:23 FW@127.0.0.1: Ping reply received
Info : Apr 29 09:48:51 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:49069
Info : Apr 29 09:48:51 RPCConn: Connection from: 127.0.0.1:49069
Notice: Apr 29 09:48:51 RPCConn: Bad username: gunin from <gunin@127.0.0.1>.
Info : Apr 29 09:48:51 RPCConn: Access rejected to <127.0.0.1:49069>
?Debug : Apr 29 09:48:51 RPCConn: Session closed...
?Debug : Apr 29 09:48:53 FW@127.0.0.1: Ping reply received
Info : Apr 29 09:49:08 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:49070
Info : Apr 29 09:49:08 RPCConn: Connection from: 127.0.0.1:49070
Notice: Apr 29 09:49:08 RPCConn: Bad username: gunin from <gunin@127.0.0.1>.
Info : Apr 29 09:49:08 RPCConn: Access rejected to <127.0.0.1:49070>
?Debug : Apr 29 09:49:08 RPCConn: Session closed...
?Debug : Apr 29 09:49:23 FW@127.0.0.1: Ping reply received
Info : Apr 29 09:49:37 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:49071
Info : Apr 29 09:49:37 RPCConn: Connection from: 127.0.0.1:49071
Info : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Access granted to <gunit@10.0.4.141> (UID: 924)
Info : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Connection terminated by peer
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Session stored for UID 924 and IP 8d04000a
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Session closed...
Info : Apr 29 09:49:37 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:49072
Info : Apr 29 09:49:37 RPCConn: Connection from: 127.0.0.1:49072
Notice: Apr 29 09:49:37 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 29 09:49:37 RPCConn: Session restored for <gunit@10.0.4.141>
Info : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Access granted to <gunit@10.0.4.141> (UID: 924)
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Real Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 09:49:37 DBCtx: SQL SELECT query: SELECT login, password, basic_account, is_blocked, create_date, last_change_date, who_create, who_change, is_juridical, full_name, juridical_address, actual_address, work_telephone, home_telephone, mobile_telephone, web_page, icq_number, tax_number, kpp_number, bank_id, bank_account, comments, discount_period_id, email, house_id, flat_number, entrance, floor, district, building, passport, personal_manager, connect_date, is_send_invoice, advance_payment FROM users WHERE id='924' AND is_deleted=0
?Debug : Apr 29 09:49:37 DBCtx: SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='924'
?Debug : Apr 29 09:49:37 DBCtx: SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='924'
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Call 0xffffbffa (__rpcs_get_user_info) finished...
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Stream cleared
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Real Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Call 0xffffbfab (__rpcs_user5_get_accounts) finished...
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Stream cleared
Info : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Connection terminated by peer
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Session stored for UID 924 and IP 8d04000a
?Debug : Apr 29 09:49:37 RPCConn<gunit@10.0.4.141>: Session closed...
Info : Apr 29 09:49:44 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:49073
Info : Apr 29 09:49:44 RPCConn: Connection from: 127.0.0.1:49073
Notice: Apr 29 09:49:44 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 29 09:49:44 RPCConn: Session restored for <gunit@10.0.4.141>
Info : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Access granted to <gunit@10.0.4.141> (UID: 924)
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Call: 0xffffbfc9 (rpcf_user5_get_currency_list)
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Real Call: 0xffffbfc9 (rpcf_user5_get_currency_list)
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Call 0xffffbfc9 (rpcf_user5_get_currency_list) finished...
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Stream cleared
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Call: 0xffffbfee (__rpcs_user5_payments_report)
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Real Call: 0xffffbfee (__rpcs_user5_payments_report)
?Debug : Apr 29 09:49:44 UTM5 DBA: DBAccess instance created
?Debug : Apr 29 09:49:44 DBA:Ctx: Looking for free context
?Debug : Apr 29 09:49:44 DBCtx: SQL SELECT query: SELECT id, name FROM payment_methods
?Debug : Apr 29 09:49:44 DBCtx: SQL SELECT query: SELECT id, payment_incurrency, currency_id, currency_rate, payment_absolute,actual_date, payment_enter_date, method, who_receive, comments_for_user,comments_for_admins, account_id, payment_ext_number FROM payment_transactions WHERE payment_enter_date>='1206997200' AND payment_enter_date<='1209451784' AND account_id='1839' ORDER BY payment_enter_date DESC
?Debug : Apr 29 09:49:44 DBA:Ctx: Pushing back free context
-Stats : Apr 29 09:49:44 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Call 0xffffbfee (__rpcs_user5_payments_report) finished...
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Stream cleared
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Call: 0xffffbfd7 (__rpcs_user5_tpayment)
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Real Call: 0xffffbfd7 (__rpcs_user5_tpayment)
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Call 0xffffbfd7 (__rpcs_user5_tpayment) finished...
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Stream cleared
Info : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Connection terminated by peer
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Session stored for UID 924 and IP 8d04000a
?Debug : Apr 29 09:49:44 RPCConn<gunit@10.0.4.141>: Session closed...
?Debug : Apr 29 09:49:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:50:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:50:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:51:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:51:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:52:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:52:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:53:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:53:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:54:23 FW@127.0.0.1: Ping reply received
Info : Apr 29 09:54:26 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:47611
Info : Apr 29 09:54:26 RPCConn: Connection from: 127.0.0.1:47611
Info : Apr 29 09:54:26 RPCConn<metrolog@10.0.2.232>: Access granted to <metrolog@10.0.2.232> (UID: 441)
Info : Apr 29 09:54:26 RPCConn<metrolog@10.0.2.232>: Connection terminated by peer
?Debug : Apr 29 09:54:26 RPCConn<metrolog@10.0.2.232>: Session stored for UID 441 and IP e802000a
?Debug : Apr 29 09:54:26 RPCConn<metrolog@10.0.2.232>: Session closed...
Info : Apr 29 09:54:26 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:47612
Info : Apr 29 09:54:26 RPCConn: Connection from: 127.0.0.1:47612
Notice: Apr 29 09:54:26 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 29 09:54:26 RPCConn: Session restored for <metrolog@10.0.2.232>
Info : Apr 29 09:54:26 RPCConn<metrolog@10.0.2.232>: Access granted to <metrolog@10.0.2.232> (UID: 441)
?Debug : Apr 29 09:54:26 RPCConn<metrolog@10.0.2.232>: Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 09:54:26 RPCConn<metrolog@10.0.2.232>: Real Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 09:54:26 DBCtx: SQL SELECT query: SELECT login, password, basic_account, is_blocked, create_date, last_change_date, who_create, who_change, is_juridical, full_name, juridical_address, actual_address, work_telephone, home_telephone, mobile_telephone, web_page, icq_number, tax_number, kpp_number, bank_id, bank_account, comments, discount_period_id, email, house_id, flat_number, entrance, floor, district, building, passport, personal_manager, connect_date, is_send_invoice, advance_payment FROM users WHERE id='441' AND is_deleted=0
?Debug : Apr 29 09:54:26 DBCtx: SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='441'
?Debug : Apr 29 09:54:26 DBCtx: SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='441'
?Debug : Apr 29 09:54:26 RPCConn<metrolog@10.0.2.232>: Call 0xffffbffa (__rpcs_get_user_info) finished...
?Debug : Apr 29 09:54:26 RPCConn<metrolog@10.0.2.232>: Stream cleared
?Debug : Apr 29 09:54:27 RPCConn<metrolog@10.0.2.232>: Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 29 09:54:27 RPCConn<metrolog@10.0.2.232>: Real Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 29 09:54:27 RPCConn<metrolog@10.0.2.232>: Call 0xffffbfab (__rpcs_user5_get_accounts) finished...
?Debug : Apr 29 09:54:27 RPCConn<metrolog@10.0.2.232>: Stream cleared
Info : Apr 29 09:54:27 RPCConn<metrolog@10.0.2.232>: Connection terminated by peer
?Debug : Apr 29 09:54:27 RPCConn<metrolog@10.0.2.232>: Session stored for UID 441 and IP e802000a
?Debug : Apr 29 09:54:27 RPCConn<metrolog@10.0.2.232>: Session closed...
?Debug : Apr 29 09:54:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:55:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:55:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:56:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:56:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:57:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:57:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:58:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:58:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 09:59:23 FW@127.0.0.1: Ping reply received
Warn : Apr 29 09:59:43 RPCConn<init@10.0.0.2>: Session closed
?Debug : Apr 29 09:59:43 RPCConn<init@10.0.0.2>: Session stored for UID -1 from <10.0.0.2>
?Debug : Apr 29 09:59:43 RPCConn<init@10.0.0.2>: Session closed...
Warn : Apr 29 09:59:43 RPCConn<init@10.0.0.2>: Session closed
?Debug : Apr 29 09:59:43 RPCConn<init@10.0.0.2>: Session stored for UID -1 from <10.0.0.2>
?Debug : Apr 29 09:59:43 RPCConn<init@10.0.0.2>: Session closed...
Warn : Apr 29 09:59:43 RPCConn<init@10.0.0.2>: Session closed
?Debug : Apr 29 09:59:43 RPCConn<init@10.0.0.2>: Session stored for UID -1 from <10.0.0.2>
?Debug : Apr 29 09:59:43 RPCConn<init@10.0.0.2>: Session closed...
?Debug : Apr 29 09:59:53 FW@127.0.0.1: Ping reply received
Info : Apr 29 09:59:59 RPCServer@0.0.0.0: Client connecting: 10.0.0.2:1123
Info : Apr 29 09:59:59 RPCConn: Connection from: 10.0.0.2:1123
Info : Apr 29 10:00:00 RPCConn: Card user <init@10.0.0.2> is connecting
?Debug : Apr 29 10:00:00 DBA Groups: Group: -1 from 1
-Stats : Apr 29 10:00:00 DBA Groups: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
Info : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Access granted to <init@10.0.0.2> (UID: -1)
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Call: 0x0045 (Get-Core-Version)
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Real Call: 0x0045 (Get-Core-Version)
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Call 0x0045 (Get-Core-Version) finished...
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Call: 0x0046 (Get-Core-BUILD)
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Real Call: 0x0046 (Get-Core-BUILD)
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Call 0x0046 (Get-Core-BUILD) finished...
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Call: 0x2910 (rpcf_get_currency_list)
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Real Call: 0x2910 (rpcf_get_currency_list)
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Call 0x2910 (rpcf_get_currency_list) finished...
?Debug : Apr 29 10:00:00 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Call: 0x2400 (rpcf_get_groups_list)
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Real Call: 0x2400 (rpcf_get_groups_list)
?Debug : Apr 29 10:00:01 DBA:Ctx: Looking for free context
?Debug : Apr 29 10:00:01 DBCtx: SQL SELECT query: SELECT id, group_name FROM groups
?Debug : Apr 29 10:00:01 DBA:Ctx: Pushing back free context
-Stats : Apr 29 10:00:01 DBA Groups: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Call 0x2400 (rpcf_get_groups_list) finished...
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Apr 29 10:00:01 RPCConn<init@10.0.0.2>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Apr 29 10:00:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:00:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:01:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:01:53 FW@127.0.0.1: Ping reply received
Info : Apr 29 10:02:17 RPCServer@0.0.0.0: Client connecting: 10.0.0.2:1249
Info : Apr 29 10:02:17 RPCConn: Connection from: 10.0.0.2:1249
Info : Apr 29 10:02:17 RPCConn: Card user <init@10.0.0.2> is connecting
?Debug : Apr 29 10:02:17 DBA Groups: Group: -1 from 1
-Stats : Apr 29 10:02:17 DBA Groups: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
Info : Apr 29 10:02:17 RPCConn<init@10.0.0.2>: Access granted to <init@10.0.0.2> (UID: -1)
?Debug : Apr 29 10:02:17 RPCConn<init@10.0.0.2>: Call: 0x0045 (Get-Core-Version)
?Debug : Apr 29 10:02:17 RPCConn<init@10.0.0.2>: Real Call: 0x0045 (Get-Core-Version)
?Debug : Apr 29 10:02:17 RPCConn<init@10.0.0.2>: Call 0x0045 (Get-Core-Version) finished...
?Debug : Apr 29 10:02:17 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Call: 0x0046 (Get-Core-BUILD)
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Real Call: 0x0046 (Get-Core-BUILD)
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Call 0x0046 (Get-Core-BUILD) finished...
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Call: 0x2910 (rpcf_get_currency_list)
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Real Call: 0x2910 (rpcf_get_currency_list)
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Call 0x2910 (rpcf_get_currency_list) finished...
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Apr 29 10:02:18 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:02:19 RPCConn<init@10.0.0.2>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:02:19 RPCConn<init@10.0.0.2>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:02:19 RPCConn<init@10.0.0.2>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Apr 29 10:02:19 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:02:19 RPCConn<init@10.0.0.2>: Call: 0x2400 (rpcf_get_groups_list)
?Debug : Apr 29 10:02:19 RPCConn<init@10.0.0.2>: Real Call: 0x2400 (rpcf_get_groups_list)
?Debug : Apr 29 10:02:19 DBA:Ctx: Looking for free context
?Debug : Apr 29 10:02:19 DBCtx: SQL SELECT query: SELECT id, group_name FROM groups
?Debug : Apr 29 10:02:19 DBA:Ctx: Pushing back free context
-Stats : Apr 29 10:02:19 DBA Groups: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 10:02:19 RPCConn<init@10.0.0.2>: Call 0x2400 (rpcf_get_groups_list) finished...
?Debug : Apr 29 10:02:19 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:02:19 RPCConn<init@10.0.0.2>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Apr 29 10:02:19 RPCConn<init@10.0.0.2>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Apr 29 10:02:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:02:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:03:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:03:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:04:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:04:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:05:23 FW@127.0.0.1: Ping reply received
Notice: Apr 29 10:05:27 ModMap: Log file reopened
-Stats : Apr 29 10:05:27 UTM5 Config: Stats for 2435s. (uptime 2435). Events: 0 (all 0); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 UTM5 DBA: Stats for 2435s. (uptime 2435). Events: 0 (all 0); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 DBA:Ctx: Stats for 2435s. (uptime 2435). Events: 0 (all 0); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 DBAGiga: Stats for 2427s. (uptime 2427). Events: 0 (all 0); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 DBARadius: Stats for 2427s. (uptime 2427). Events: 0 (all 0); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 ModFWMan: Stats for 2427s. (uptime 2427). Events: 0 (all 0); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 FW@127.0.0.1: Stats for 2405s. (uptime 2405). Events: 18418 (all 18418); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 HSPlugin: Stats for 2427s. (uptime 2427). Events: 0 (all 0); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 UTM5 Logger: Stats for 2435s. (uptime 2435). Events: 556521 (all 556521); Errors: 8175 (all 8175)
-Stats : Apr 29 10:05:27 NFBuffer: queue size 159765
-Stats : Apr 29 10:05:27 NFBuffer: Stats for 2427s. (uptime 2427). Events: 278183 (all 278183); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 Radius: Stats for 2427s. (uptime 2427). Events: 7954 (all 7954); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 Rehash: Stats for 2435s. (uptime 2435). Events: 0 (all 0); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 RPCServer@0.0.0.0: Stats for 2427s. (uptime 2427). Events: 36 (all 36); Errors: 5 (all 5)
-Stats : Apr 29 10:05:27 StreamManager: Stats for 2427s. (uptime 2427). Events: 0 (all 0); Errors: 0 (all 0)
-Stats : Apr 29 10:05:27 UTMCtx: Stats for 2435s. (uptime 2435). Events: 0 (all 0); Errors: 15 (all 15)
-Stats : Apr 29 10:05:27 ModMap: Stats for 2435s. (uptime 2435). Events: 16 (all 16); Errors: 3 (all 3)
?Debug : Apr 29 10:05:27 BusClassif: BusClassif::giga_commit called.
?Debug : Apr 29 10:05:27 BusClassif: Comitting raw traffic ...
?Debug : Apr 29 10:05:27 BusClassif: flush: enumerating store
Info : Apr 29 10:05:27 BusClassif: Periodic clean thread stopped.
Info : Apr 29 10:05:43 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:48362
Info : Apr 29 10:05:43 RPCConn: Connection from: 127.0.0.1:48362
Info : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Access granted to <famyly@10.0.4.49> (UID: 843)
Info : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Connection terminated by peer
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Session stored for UID 843 and IP 3104000a
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Session closed...
Info : Apr 29 10:05:43 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:48363
Info : Apr 29 10:05:43 RPCConn: Connection from: 127.0.0.1:48363
Notice: Apr 29 10:05:43 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 29 10:05:43 RPCConn: Session restored for <famyly@10.0.4.49>
Info : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Access granted to <famyly@10.0.4.49> (UID: 843)
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Real Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 10:05:43 DBCtx: SQL SELECT query: SELECT login, password, basic_account, is_blocked, create_date, last_change_date, who_create, who_change, is_juridical, full_name, juridical_address, actual_address, work_telephone, home_telephone, mobile_telephone, web_page, icq_number, tax_number, kpp_number, bank_id, bank_account, comments, discount_period_id, email, house_id, flat_number, entrance, floor, district, building, passport, personal_manager, connect_date, is_send_invoice, advance_payment FROM users WHERE id='843' AND is_deleted=0
?Debug : Apr 29 10:05:43 DBCtx: SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='843'
?Debug : Apr 29 10:05:43 DBCtx: SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='843'
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Call 0xffffbffa (__rpcs_get_user_info) finished...
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Stream cleared
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Real Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Call 0xffffbfab (__rpcs_user5_get_accounts) finished...
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Stream cleared
Info : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Connection terminated by peer
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Session stored for UID 843 and IP 3104000a
?Debug : Apr 29 10:05:43 RPCConn<famyly@10.0.4.49>: Session closed...
?Debug : Apr 29 10:05:53 FW@127.0.0.1: Ping reply received
Info : Apr 29 10:06:16 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:48364
Info : Apr 29 10:06:16 RPCConn: Connection from: 127.0.0.1:48364
Info : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Access granted to <pavlenko@10.0.4.34> (UID: 826)
Info : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Connection terminated by peer
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Session stored for UID 826 and IP 2204000a
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Session closed...
Info : Apr 29 10:06:16 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:48365
Info : Apr 29 10:06:16 RPCConn: Connection from: 127.0.0.1:48365
Notice: Apr 29 10:06:16 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 29 10:06:16 RPCConn: Session restored for <pavlenko@10.0.4.34>
Info : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Access granted to <pavlenko@10.0.4.34> (UID: 826)
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Real Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 10:06:16 DBCtx: SQL SELECT query: SELECT login, password, basic_account, is_blocked, create_date, last_change_date, who_create, who_change, is_juridical, full_name, juridical_address, actual_address, work_telephone, home_telephone, mobile_telephone, web_page, icq_number, tax_number, kpp_number, bank_id, bank_account, comments, discount_period_id, email, house_id, flat_number, entrance, floor, district, building, passport, personal_manager, connect_date, is_send_invoice, advance_payment FROM users WHERE id='826' AND is_deleted=0
?Debug : Apr 29 10:06:16 DBCtx: SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='826'
?Debug : Apr 29 10:06:16 DBCtx: SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='826'
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Call 0xffffbffa (__rpcs_get_user_info) finished...
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Stream cleared
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Real Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Call 0xffffbfab (__rpcs_user5_get_accounts) finished...
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Stream cleared
Info : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Connection terminated by peer
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Session stored for UID 826 and IP 2204000a
?Debug : Apr 29 10:06:16 RPCConn<pavlenko@10.0.4.34>: Session closed...
?Debug : Apr 29 10:06:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:06:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:07:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:07:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:08:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:08:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:09:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:09:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:10:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:10:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:11:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:11:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:12:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:12:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:13:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:13:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:14:23 FW@127.0.0.1: Ping reply received
Info : Apr 29 10:14:49 RPCServer@0.0.0.0: Client connecting: 10.0.0.2:1610
Info : Apr 29 10:14:49 RPCConn: Connection from: 10.0.0.2:1610
Info : Apr 29 10:14:49 RPCConn: Card user <init@10.0.0.2> is connecting
?Debug : Apr 29 10:14:49 DBA Groups: Group: -1 from 1
-Stats : Apr 29 10:14:49 DBA Groups: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
Info : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Access granted to <init@10.0.0.2> (UID: -1)
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Call: 0x0045 (Get-Core-Version)
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Real Call: 0x0045 (Get-Core-Version)
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Call 0x0045 (Get-Core-Version) finished...
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Call: 0x0046 (Get-Core-BUILD)
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Real Call: 0x0046 (Get-Core-BUILD)
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Call 0x0046 (Get-Core-BUILD) finished...
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Apr 29 10:14:49 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Call: 0x2910 (rpcf_get_currency_list)
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Real Call: 0x2910 (rpcf_get_currency_list)
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Call 0x2910 (rpcf_get_currency_list) finished...
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Call: 0x2400 (rpcf_get_groups_list)
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Real Call: 0x2400 (rpcf_get_groups_list)
?Debug : Apr 29 10:14:50 DBA:Ctx: Looking for free context
?Debug : Apr 29 10:14:50 DBCtx: SQL SELECT query: SELECT id, group_name FROM groups
?Debug : Apr 29 10:14:50 DBA:Ctx: Pushing back free context
-Stats : Apr 29 10:14:50 DBA Groups: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Call 0x2400 (rpcf_get_groups_list) finished...
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Stream cleared
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Apr 29 10:14:50 RPCConn<init@10.0.0.2>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Apr 29 10:14:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:15:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:15:53 FW@127.0.0.1: Ping reply received
Info : Apr 29 10:16:02 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:52329
Info : Apr 29 10:16:02 RPCConn: Connection from: 127.0.0.1:52329
Info : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Access granted to <indigo@10.0.5.47> (UID: 1118)
Info : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Connection terminated by peer
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Session stored for UID 1118 and IP 2f05000a
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Session closed...
Info : Apr 29 10:16:02 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:52330
Info : Apr 29 10:16:02 RPCConn: Connection from: 127.0.0.1:52330
Notice: Apr 29 10:16:02 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 29 10:16:02 RPCConn: Session restored for <indigo@10.0.5.47>
Info : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Access granted to <indigo@10.0.5.47> (UID: 1118)
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Real Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 10:16:02 DBCtx: SQL SELECT query: SELECT login, password, basic_account, is_blocked, create_date, last_change_date, who_create, who_change, is_juridical, full_name, juridical_address, actual_address, work_telephone, home_telephone, mobile_telephone, web_page, icq_number, tax_number, kpp_number, bank_id, bank_account, comments, discount_period_id, email, house_id, flat_number, entrance, floor, district, building, passport, personal_manager, connect_date, is_send_invoice, advance_payment FROM users WHERE id='1118' AND is_deleted=0
?Debug : Apr 29 10:16:02 DBCtx: SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='1118'
?Debug : Apr 29 10:16:02 DBCtx: SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='1118'
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Call 0xffffbffa (__rpcs_get_user_info) finished...
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Stream cleared
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Real Call: 0xffffbfab (__rpcs_user5_get_accounts)
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Call 0xffffbfab (__rpcs_user5_get_accounts) finished...
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Stream cleared
Info : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Connection terminated by peer
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Session stored for UID 1118 and IP 2f05000a
?Debug : Apr 29 10:16:02 RPCConn<indigo@10.0.5.47>: Session closed...
Info : Apr 29 10:16:08 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:52331
Info : Apr 29 10:16:08 RPCConn: Connection from: 127.0.0.1:52331
Notice: Apr 29 10:16:08 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 29 10:16:08 RPCConn: Session restored for <indigo@10.0.5.47>
Info : Apr 29 10:16:08 RPCConn<indigo@10.0.5.47>: Access granted to <indigo@10.0.5.47> (UID: 1118)
?Debug : Apr 29 10:16:08 RPCConn<indigo@10.0.5.47>: Call: 0xffffbfdd (__rpcs_user5_get_services)
?Debug : Apr 29 10:16:08 RPCConn<indigo@10.0.5.47>: Real Call: 0xffffbfdd (__rpcs_user5_get_services)
?Debug : Apr 29 10:16:08 RPCConn<indigo@10.0.5.47>: Call 0xffffbfdd (__rpcs_user5_get_services) finished...
?Debug : Apr 29 10:16:08 RPCConn<indigo@10.0.5.47>: Stream cleared
Info : Apr 29 10:16:08 RPCConn<indigo@10.0.5.47>: Connection terminated by peer
?Debug : Apr 29 10:16:08 RPCConn<indigo@10.0.5.47>: Session stored for UID 1118 and IP 2f05000a
?Debug : Apr 29 10:16:08 RPCConn<indigo@10.0.5.47>: Session closed...
Info : Apr 29 10:16:10 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:52332
Info : Apr 29 10:16:10 RPCConn: Connection from: 127.0.0.1:52332
Notice: Apr 29 10:16:10 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 29 10:16:10 RPCConn: Session restored for <indigo@10.0.5.47>
Info : Apr 29 10:16:10 RPCConn<indigo@10.0.5.47>: Access granted to <indigo@10.0.5.47> (UID: 1118)
?Debug : Apr 29 10:16:10 RPCConn<indigo@10.0.5.47>: Call: 0xffffbfdc (__rpcs_user5_get_services_info)
?Debug : Apr 29 10:16:10 RPCConn<indigo@10.0.5.47>: Real Call: 0xffffbfdc (__rpcs_user5_get_services_info)
?Debug : Apr 29 10:16:10 DBCtx: SQL SELECT query: SELECT t_class_name,graph_color,is_display,is_fill,time_range_id,dont_save,local_traf_policy from t_class where id='10'
?Debug : Apr 29 10:16:10 DBCtx: SQL SELECT query: SELECT t_class_name,graph_color,is_display,is_fill,time_range_id,dont_save,local_traf_policy from t_class where id='20'
?Debug : Apr 29 10:16:10 DBCtx: SQL SELECT query: SELECT t_class_name,graph_color,is_display,is_fill,time_range_id,dont_save,local_traf_policy from t_class where id='30'
?Debug : Apr 29 10:16:10 DBCtx: SQL SELECT query: SELECT t_class_name,graph_color,is_display,is_fill,time_range_id,dont_save,local_traf_policy from t_class where id='10'
?Debug : Apr 29 10:16:10 DBCtx: SQL SELECT query: SELECT t_class_name,graph_color,is_display,is_fill,time_range_id,dont_save,local_traf_policy from t_class where id='20'
?Debug : Apr 29 10:16:10 DBCtx: SQL SELECT query: SELECT t_class_name,graph_color,is_display,is_fill,time_range_id,dont_save,local_traf_policy from t_class where id='30'
?Debug : Apr 29 10:16:23 FW@127.0.0.1: Ping reply received
Info : Apr 29 10:16:37 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:52333
Info : Apr 29 10:16:37 RPCConn: Connection from: 127.0.0.1:52333
Notice: Apr 29 10:16:37 RPCConn: Service <web@127.0.0.1> is connecting
Warn : Apr 29 10:16:37 RPCConn: Unable to restore Session Key for IP <10.0.5.47>
Info : Apr 29 10:16:37 RPCConn: Access rejected to <127.0.0.1:52333>
?Debug : Apr 29 10:16:37 RPCConn: Session closed...
?Debug : Apr 29 10:16:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:17:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:17:53 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:18:23 FW@127.0.0.1: Ping reply received
?Debug : Apr 29 10:18:53 FW@127.0.0.1: Ping reply received
Info : Apr 29 10:19:09 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:36820
Info : Apr 29 10:19:09 RPCConn: Connection from: 127.0.0.1:36820
Info : Apr 29 10:19:09 RPCConn<vano2@10.0.0.2>: Access granted to <vano2@10.0.0.2> (UID: 6)
Info : Apr 29 10:19:09 RPCConn<vano2@10.0.0.2>: Connection terminated by peer
?Debug : Apr 29 10:19:09 RPCConn<vano2@10.0.0.2>: Session stored for UID 6 and IP 200000a
?Debug : Apr 29 10:19:09 RPCConn<vano2@10.0.0.2>: Session closed...
Info : Apr 29 10:19:09 RPCServer@0.0.0.0: Client connecting: 127.0.0.1:36821
Info : Apr 29 10:19:09 RPCConn: Connection from: 127.0.0.1:36821
Notice: Apr 29 10:19:09 RPCConn: Service <web@127.0.0.1> is connecting
?Debug : Apr 29 10:19:09 RPCConn: Session restored for <vano2@10.0.0.2>
Info : Apr 29 10:19:09 RPCConn<vano2@10.0.0.2>: Access granted to <vano2@10.0.0.2> (UID: 6)
?Debug : Apr 29 10:19:09 RPCConn<vano2@10.0.0.2>: Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 10:19:09 RPCConn<vano2@10.0.0.2>: Real Call: 0xffffbffa (__rpcs_get_user_info)
?Debug : Apr 29 10:19:09 DBCtx: SQL SELECT query: SELECT login, password, basic_account, is_blocked, create_date, last_change_date, who_create, who_change, is_juridical, full_name, juridical_address, actual_address, work_telephone, home_telephone, mobile_telephone, web_page, icq_number, tax_number, kpp_number, bank_id, bank_account, comments, discount_period_id, email, house_id, flat_number, entrance, floor, district, building, passport, personal_manager, connect_date, i

Аватара пользователя
XoRe
Сообщения: 458
Зарегистрирован: Ср янв 10, 2007 16:04

Сообщение XoRe »

2PEBA:
Могу сказать то, что есть.

Система:
> uptime
12:43PM up 83 days, 23:08, 1 user, load averages: 0.00, 0.00, 0.00

Утм:
В админке "дополнительно" -> "статистика" -> "Время работы(uptime):
154:47:25
Т.е. около 6 дней.
Но это связано с тем, что я ковырялся в настройках и перезагружал биллинг, чтоб он нормально принял настройки.
А до этого нормально работало аж с момента перезагрузки сервера, т.е. 77 дней (83 - 6).
Постоянные зависания ядра системы (в логи ничего не пишет), при чем очень странно. Помогает лишь перезапуск сервера полностью.
А что видно без перезагрузки?
Т.е. когда ядро зависает, вы его убиваете и просто снова пытаетесь запустить?

Kayfolom
Сообщения: 746
Зарегистрирован: Вс фев 12, 2006 17:15

Сообщение Kayfolom »

2PEBA:
Попробуй посмотреть mysqladmin processlist во время зависания админки.
У меня обычно в такой смтуации там висит какой нибудь запрос с Time превышающим все остальные на 2 порядка.
Если есть такой, то mysqladmin kill его. У меня в таком случае админка сразу размораживается.
Как будто ядро открывает транзакцию, пихает запросы, но забывает сделать COMMIT и ждет до упора. В Дебаг логе поищи следующий после подвисания SQL error - он может вылезти через 10-20 минут.

Закрыто