Чудный косяк .....
И так вчера было так
Сегодня в 7 утра товарищ попал в системную блокировку.
У него висел кредит!
Начало блокировки
Код: Выделить всё
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2014_01'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2013_12'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2013_11'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2013_10'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2013_09'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2014_02'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2014_03'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2014_04'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2014_05'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2014_06'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2014_07'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2014_08'
Oct 16 07:33:20 ?Debug : f9465700 UTM5 DBA: archive tables listing: table 'UTM5arc.ptr_2014_09'
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL SELECT query: SELECT id from payment_transactions WHERE id='46671'
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL SELECT query: 1 rows in 0.000 sec
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query: UPDATE credits SET status=2 WHERE id='2916'
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query takes 0.001 sec
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query: UPDATE payment_transactions SET comments_for_admins='CREDIT FIRED' WHERE id='46671'
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query takes 0.001 sec
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query: INSERT INTO blocks_info (account_id,block_type,start_date,expire_date,is_planning,flags) VALUES ('4','1','1413430400','2000000000','0','0')
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query takes 0.001 sec
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query: UPDATE accounts SET block_id='29955' WHERE id='4'
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query takes 0.001 sec
Oct 16 07:33:20 ?Debug : f9465700 StreamConnection: Sending message ID 0x2102
Oct 16 07:33:20 ?Debug : f9465700 RADIUS_Module: [3]: account ID <4> was sent
Oct 16 07:33:20 ?Debug : f9465700 StreamConnection: Sending message ID 0x500f
Oct 16 07:33:20 ?Debug : f9465700 DHCP_Module: account #4 update has been sent to [4]
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query: UPDATE blocks_info SET start_date='1413430400',expire_date='2000000000',is_planning='0' WHERE id='29955'
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query takes 0.001 sec
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query: UPDATE periodic_service_links SET start_block_unabon='0',start_block_unprepay='0',start_block_untel='0' WHERE id='5'
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query takes 0.001 sec
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query: UPDATE periodic_service_links SET start_block_unabon='0',start_block_unprepay='0',start_block_untel='0' WHERE id='3013'
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query takes 0.001 sec
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query: UPDATE accounts SET int_status='0' WHERE id='4'
Oct 16 07:33:20 ?Debug : f9465700 DBConnection_mysql: <0x1fa71f0> SQL query takes 0.001 sec
Oct 16 07:33:20 ?Debug : f9465700 TransactionQueueManager: push: using queue [1]
Oct 16 07:33:20 ?Debug : f9465700 TransactionQueueManager: push: transaction ptr [0x7fe7f46bdcd0] handler #2 ptr [0x7fe7f448a1b0]
Oct 16 07:33:20 ?Debug : f9465700 TransactionHandlerImpl: push: transaction ptr [f46bdcd0] (size 1, Events [ 17 ])
Oct 16 07:33:20 ?Debug : f9465700 TransactionQueueManager: push: using queue [1]
Oct 16 07:33:20 ?Debug : f9465700 TransactionQueueManager: push: transaction ptr [0x281d000] handler #2 ptr [0x7fe7f448a1b0]
Oct 16 07:33:20 ?Debug : f9465700 TransactionHandlerImpl: push: transaction ptr [0281d000] (size 1, Events [ 26 ])
Oct 16 07:33:20 ?Debug : f9465700 StreamConnection: Sending message ID 0x2102
Oct 16 07:33:20 ?Debug : f9465700 RADIUS_Module: [3]: account ID <3830> was sent
Вот дебаг сегодняшний радиуса когда его вышибло.
Код: Выделить всё
ct 16 07:40:02 ?Debug : 9c6de700 Tarifficator: got account ID 4 balance -49.1118 credit 2550 block_id 29955
Oct 16 07:40:02 ?Debug : 9c6de700 DAC: Disconnect-Request:
--- RADIUS Pkt ---
Code: [40] ID: [142]
Auth: Size 16; Data [0x00000000000000000000000000000000]
Attr: [1] Vendor: [0] Size 5; Data [0x6175746f31]
(User-Name=STRING:auto1)
Attr: [44] Vendor: [0] Size 19; Data [0x333433303632382d766c616e3830302d343132]
(Acct-Session-Id=STRING:3430628-vlan800-412)
Attr: [8] Vendor: [0] Size 4; Data [0xc0a8c809]
(Framed-IP-Address=IP:192.168.200.9)
Attr: [31] Vendor: [0] Size 47; Data [0x32303a63663a33303a38383a30643a6138202f2032303a63663a33303a38383a30643a6138202f20766c616e383030]
(Calling-Station-Id=STRING:20:cf:30:88:0d:a8 / 20:cf:30:88:0d:a8 / vlan800)
Oct 16 07:40:02 ?Debug : 9c6de700 DAC: Disconnect-Request has been sent to NAS 172.28.100.254 for SID '3430628-vlan800-412' login 'auto1'
Oct 16 07:40:02 ?Debug : 9c6de700 StreamConnection: Got message ID 0x2102
Oct 16 07:40:02 ?Debug : 9c6de700 Transport: got ACCOUNT_INFO event
Вот билинг
Код: Выделить всё
ct 16 07:40:02 ?Debug : f8c5d700 DBACharge: charge 0 for link 3013 account 4
Oct 16 07:40:02 ?Debug : f8c5d700 DBConnection_mysql: <0x1fa71f0> SQL query: UPDATE accounts SET balance='-49.1118221283' WHERE id='4'
Oct 16 07:40:02 ?Debug : f8c5d700 DBConnection_mysql: <0x1fa71f0> SQL query takes 0.000 sec
Oct 16 07:40:02 ?Debug : f8c5d700 DBConnection_mysql: <0x1fa71f0> SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_with_tax,service_id,service_type,slink_id,discount_date,charge_type,discount_period_id) VALUES ('4','-49.1118221283','-49.1118221283','0','0','131','3','3013','1413430802','3','54')
Oct 16 07:40:02 ?Debug : f8c5d700 DBConnection_mysql: <0x1fa71f0> SQL query takes 0.000 sec
Код: Выделить всё
Oct 16 07:42:03 ?Debug : f8c5d700 DBACharge: charge 0 for link 3013 account 4
Oct 16 07:42:03 ?Debug : f8c5d700 DBConnection_mysql: <0x1f8ea60> SQL query: UPDATE accounts SET balance='-49.1118221283' WHERE id='4'
Oct 16 07:42:03 ?Debug : f8c5d700 DBConnection_mysql: <0x1f8ea60> SQL query takes 0.000 sec
Oct 16 07:42:03 ?Debug : f8c5d700 DBConnection_mysql: <0x1f8ea60> SQL query: INSERT INTO discount_transactions_all(account_id,incoming_rest,outgoing_rest,discount,discount_with_tax,service_id,service_type,slink_id,discount_date,charge_type,discount_period_id) VALUES ('4','-49.1118221283','-49.1118221283','0','0','131','3','3013','1413430923','3','54')
Oct 16 07:42:03 ?Debug : f8c5d700 DBConnection_mysql: <0x1f8ea60> SQL query takes 0.000 sec
Почему так произошло? Пост дополнил еще дебагами.