UTM5_rfw rsh cisco

Технические вопросы по UTM 5.0
Ответить
gagarin
Сообщения: 16
Зарегистрирован: Пт мар 06, 2015 15:10

UTM5_rfw rsh cisco

Сообщение gagarin »

Уважаемые коллеги!
Подскажите, если кто сталкивался.
Пытаюсь включать/выключать тестовому пользователю интернет, дебаг cisco пишет, что все ок, но правила в это время не появляются, если писать руками из терминала, где установлен UTM - все ok.

rfw5.cfg

rfw_name=192.168.115.223
core_host=127.0.0.1
core_port=12758
rfw_login=init
rfw_password=init
firewall_type=cisco
rfw_ssl_type=none
firewall_path=/etc/rc.d/init.d/utm5_rfw.sh
dont_fork=yes
cisco_ip=192.168.115.223
log_level=3
log_file_main=/netup/utm5/log/rfw.log
log_file_debug=/netup/utm5/log/rfw.log
log_file_critical=/netup/utm5/log/rfw.log

Cisco debug:

Mar 6 12:25:22.516: RCMD: [514 <- 192.168.115.15:1023] recv 1022\0
Mar 6 12:25:22.716: RCMD: [514 <- 192.168.115.15:1023] recv netup\0netup\0clear access-template 105 test1 host 192.168.93.99 any\0
Mar 6 12:25:22.716: RCMD: [514 -> 192.168.115.15:1023] send <OK>
Mar 6 12:25:22.816: RCMD: [514 <- 192.168.115.15:1021] recv 1020\0
Mar 6 12:25:23.016: RCMD: [514 <- 192.168.115.15:1021] recv netup\0netup\0clear access-template 106 test2 any host 192.168.93.99\0
Mar 6 12:25:23.016: RCMD: [514 -> 192.168.115.15:1021] send <OK>
telecom#
Mar 6 12:25:31.620: RCMD: [514 <- 192.168.115.15:1023] recv 1022\0
Mar 6 12:25:31.820: RCMD: [514 <- 192.168.115.15:1023] recv netup\0netup\0access-template 105 test1 host 192.168.93.99 any\0
Mar 6 12:25:31.820: RCMD: [514 -> 192.168.115.15:1023] send <OK>
Mar 6 12:25:31.920: RCMD: [514 <- 192.168.115.15:1021] recv 1020\0
Mar 6 12:25:32.120: RCMD: [514 <- 192.168.115.15:1021] recv netup\0netup\0access-template 106 test2 any host 192.168.93.99\0
Mar 6 12:25:32.120: RCMD: [514 -> 192.168.115.15:1021] send <OK>

Аксес листы:

telecom#sh access-lists
Standard IP access list 1
10 permit 192.168.93.0, wildcard bits 0.0.0.255 (52781 matches)
20 permit 192.168.115.0, wildcard bits 0.0.0.255
Standard IP access list 10
30 permit 192.168.115.15 (54 matches)
20 permit 192.168.93.20 (20 matches)
10 permit 192.168.93.1 log (10 matches)
Extended IP access list 105
10 Dynamic TEST1 permit ip any any
20 permit ip host 192.168.115.15 any
30 permit ip host 192.168.93.20 any (105743 matches)
Extended IP access list 106
10 Dynamic TEST2 permit ip any any
permit ip any host 192.168.93.25
permit ip any host 192.168.93.21
20 permit ip any host 192.168.115.15
30 permit ip any host 192.168.93.20 (32856 matches)

rfw.log

?Debug : Mar 06 15:25:32 StreamFirewall: Got ping from core. Sending reply...
?Debug : Mar 06 15:26:02 StreamFirewall: Got ping from core. Sending reply...
?Debug : Mar 06 15:26:24 StreamFirewall: Got 'exec' command...
?Debug : Mar 06 15:26:24 FWCntl: Send rule<clear access-template 105 test1 host 192.168.93.99 any> to remote cisco <192.168.115.223>
?Debug : Mar 06 15:26:24 FWCntl: Call RSH: host 192.168.115.223, port 514, login netup, pass , cmd clear access-template 105 test1 host 192.168.93.99 any
Notice: Mar 06 15:26:24 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:24 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:24 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:24 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
?Debug : Mar 06 15:26:24 StreamFirewall: Got 'exec' command...
?Debug : Mar 06 15:26:24 FWCntl: Send rule<clear access-template 106 test2 any host 192.168.93.99> to remote cisco <192.168.115.223>
?Debug : Mar 06 15:26:24 FWCntl: Call RSH: host 192.168.115.223, port 514, login netup, pass , cmd clear access-template 106 test2 any host 192.168.93.99
Notice: Mar 06 15:26:25 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:25 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:25 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:25 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
?Debug : Mar 06 15:26:26 StreamFirewall: Got 'exec' command...
?Debug : Mar 06 15:26:26 FWCntl: Send rule<access-template 105 test1 host 192.168.93.99 any> to remote cisco <192.168.115.223>
?Debug : Mar 06 15:26:26 FWCntl: Call RSH: host 192.168.115.223, port 514, login netup, pass , cmd access-template 105 test1 host 192.168.93.99 any
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
?Debug : Mar 06 15:26:27 StreamFirewall: Got 'exec' command...
?Debug : Mar 06 15:26:27 FWCntl: Send rule<access-template 106 test2 any host 192.168.93.99> to remote cisco <192.168.115.223>
?Debug : Mar 06 15:26:27 FWCntl: Call RSH: host 192.168.115.223, port 514, login netup, pass , cmd access-template 106 test2 any host 192.168.93.99
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>

Debug.log

?Debug : Mar 06 15:26:18 TransactionQueueManager: pushing transaction <0x9c0d240> into queue <2> (default)
?Debug : Mar 06 15:26:18 TransactionHandlerImpl: push: transaction ptr <0x09c0d240> (size 1, Events [ 114 ])
?Debug : Mar 06 15:26:18 TransactionHandlerImpl: incoming transaction ptr <0x09c0d240>, outgoing transaction ptr <0x09bf6c98>
?Debug : Mar 06 15:26:18 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:18 PluginManagerImpl: Got DynaShapePlugin plugin for event EventShapingCheckTimeranges/114
?Debug : Mar 06 15:26:18 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:18 TransactionQueueManager: pushing transaction <0x9bf6c98> into queue <1> (default)
?Debug : Mar 06 15:26:18 TransactionHandlerImpl: push: empty transaction ptr <0x09bf6c98> dropped
?Debug : Mar 06 15:26:18 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:18 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:18 TransactionHandlerImpl: incoming transaction ptr <0x09c0d240> done
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:24 DBCtx: <162996952> SQL query: UPDATE accounts SET int_status='0' WHERE id='2'
?Debug : Mar 06 15:26:24 BusLogic: BLM(38) pushed (comment: )
?Debug : Mar 06 15:26:24 UTM5 DBA: hw block for account 2
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call 0x2003 (rpcf_change_intstat_for_user) finished...
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:24 BusLogic: try to execute 38
?Debug : Mar 06 15:26:24 BusLogic: hw_block_handler with code 38
?Debug : Mar 06 15:26:24 BusLogic: hw_block_handler start bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9c0d240> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: transaction ptr <0x09c0d240> (size 1, Events [ 17 ])
?Debug : Mar 06 15:26:24 BusLogic: hw_block_handler end bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:24 BusLogic: finished unknown
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c0d240>, outgoing transaction ptr <0x09bf6c98>
?Debug : Mar 06 15:26:24 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got RfwPlugin plugin for event EventSwitchInet/17
?Debug : Mar 06 15:26:24 RfwPlugin: generating inet switch rules for account <2> state <0>
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got FwRulesPlugin plugin for event EventGetFWRules/8
?Debug : Mar 06 15:26:24 FwRulesPlugin: get_fwrules: got <2> rules
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got UserPlugin plugin for event EventGetUser/7
?Debug : Mar 06 15:26:24 DBCtx: <163113472> SQL query: BEGIN
?Debug : Mar 06 15:26:24 DBCtx: DB transaction begin
?Debug : Mar 06 15:26:24 DBCtx: <163113472> SQL SELECT query: SELECT login, password, basic_account, 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, email, house_id, flat_number, entrance,floor, district, building, passport, personal_manager, connect_date, is_send_invoice,advance_payment,remote_switch_id,port_number FROM users WHERE id='2' AND is_deleted=0
?Debug : Mar 06 15:26:24 DBCtx: <163113472> SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='2'
?Debug : Mar 06 15:26:24 DBCtx: <163113472> SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='2'
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:24 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:24 RfwPlugin: final command: [clear access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:24 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:24 RfwPlugin: final command: [clear access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:24 DBCtx: <163113472> SQL query: COMMIT
?Debug : Mar 06 15:26:24 DBCtx: DB transaction commit
?Debug : Mar 06 15:26:24 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9bf6c98> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: empty transaction ptr <0x09bf6c98> dropped
?Debug : Mar 06 15:26:24 DummyTransactionQueue: commit: 2 transactions
?Debug : Mar 06 15:26:24 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9c5c018> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: transaction ptr <0x09c5c018> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:24 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9c5c3b8> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: transaction ptr <0x09c5c3b8> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:24 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c0d240> done
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c5c018>, outgoing transaction ptr <0x09c0d240>
?Debug : Mar 06 15:26:24 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:24 FW@192.168.115.223: Sending [clear access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:24 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9c0d240> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: empty transaction ptr <0x09c0d240> dropped
?Debug : Mar 06 15:26:24 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:24 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c5c018> done
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3b8>, outgoing transaction ptr <0x09c5c018>
?Debug : Mar 06 15:26:24 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:24 FW@192.168.115.223: Sending [clear access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:24 AffectorsPlugin: firewall <fw@centos> not connected, rule <clear access-template 106 test2 any host 192.168.93.99> not executed
?Debug : Mar 06 15:26:24 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9c5c018> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: empty transaction ptr <0x09c5c018> dropped
?Debug : Mar 06 15:26:24 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:24 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3b8> done
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:24 RPCServer@0.0.0.0: rpcf_get_users_list: from: 0, to:2, cnt: 2
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call 0x2001 (rpcf_get_users_list) finished...
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:26 DBCtx: <162996952> SQL query: UPDATE accounts SET int_status='1' WHERE id='2'
?Debug : Mar 06 15:26:26 BusLogic: BLM(39) pushed (comment: )
?Debug : Mar 06 15:26:26 UTM5 DBA: hw unblock for account 2
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call 0x2003 (rpcf_change_intstat_for_user) finished...
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:26 BusLogic: try to execute 39
?Debug : Mar 06 15:26:26 BusLogic: hw_block_handler with code 39
?Debug : Mar 06 15:26:26 BusLogic: hw_block_handler start bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c101c8> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: transaction ptr <0x09c101c8> (size 1, Events [ 17 ])
?Debug : Mar 06 15:26:26 BusLogic: hw_block_handler end bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:26 BusLogic: finished unknown
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c101c8>, outgoing transaction ptr <0x09c1a160>
?Debug : Mar 06 15:26:26 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got RfwPlugin plugin for event EventSwitchInet/17
?Debug : Mar 06 15:26:26 RfwPlugin: generating inet switch rules for account <2> state <1>
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got FwRulesPlugin plugin for event EventGetFWRules/8
?Debug : Mar 06 15:26:26 FwRulesPlugin: get_fwrules: got <2> rules
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got UserPlugin plugin for event EventGetUser/7
?Debug : Mar 06 15:26:26 DBCtx: <163087912> SQL query: BEGIN
?Debug : Mar 06 15:26:26 DBCtx: DB transaction begin
?Debug : Mar 06 15:26:26 DBCtx: <163087912> SQL SELECT query: SELECT login, password, basic_account, 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, email, house_id, flat_number, entrance,floor, district, building, passport, personal_manager, connect_date, is_send_invoice,advance_payment,remote_switch_id,port_number FROM users WHERE id='2' AND is_deleted=0
?Debug : Mar 06 15:26:26 DBCtx: <163087912> SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='2'
?Debug : Mar 06 15:26:26 DBCtx: <163087912> SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='2'
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:26 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:26 RfwPlugin: final command: [access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:26 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:26 RfwPlugin: final command: [access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:26 DBCtx: <163087912> SQL query: COMMIT
?Debug : Mar 06 15:26:26 DBCtx: DB transaction commit
?Debug : Mar 06 15:26:26 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c1a160> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: empty transaction ptr <0x09c1a160> dropped
?Debug : Mar 06 15:26:26 DummyTransactionQueue: commit: 2 transactions
?Debug : Mar 06 15:26:26 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c5c070> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: transaction ptr <0x09c5c070> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:26 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c5c3d8> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: transaction ptr <0x09c5c3d8> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:26 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c101c8> done
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c5c070>, outgoing transaction ptr <0x09c101c8>
?Debug : Mar 06 15:26:26 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:26 FW@192.168.115.223: Sending [access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:26 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c101c8> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: empty transaction ptr <0x09c101c8> dropped
?Debug : Mar 06 15:26:26 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:26 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c5c070> done
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3d8>, outgoing transaction ptr <0x09c5c070>
?Debug : Mar 06 15:26:26 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:26 FW@192.168.115.223: Sending [access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:26 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c5c070> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: empty transaction ptr <0x09c5c070> dropped
?Debug : Mar 06 15:26:26 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:26 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3d8> done
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:26 RPCServer@0.0.0.0: rpcf_get_users_list: from: 0, to:2, cnt: 2
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call 0x2001 (rpcf_get_users_list) finished...
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:28 DBCtx: <162996952> SQL query: UPDATE accounts SET int_status='0' WHERE id='2'
?Debug : Mar 06 15:26:28 BusLogic: BLM(38) pushed (comment: )
?Debug : Mar 06 15:26:28 UTM5 DBA: hw block for account 2
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call 0x2003 (rpcf_change_intstat_for_user) finished...
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:28 BusLogic: try to execute 38
?Debug : Mar 06 15:26:28 BusLogic: hw_block_handler with code 38
?Debug : Mar 06 15:26:28 BusLogic: hw_block_handler start bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c101c8> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: transaction ptr <0x09c101c8> (size 1, Events [ 17 ])
?Debug : Mar 06 15:26:28 BusLogic: hw_block_handler end bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:28 BusLogic: finished unknown
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c101c8>, outgoing transaction ptr <0x09c1a160>
?Debug : Mar 06 15:26:28 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got RfwPlugin plugin for event EventSwitchInet/17
?Debug : Mar 06 15:26:28 RfwPlugin: generating inet switch rules for account <2> state <0>
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got FwRulesPlugin plugin for event EventGetFWRules/8
?Debug : Mar 06 15:26:28 FwRulesPlugin: get_fwrules: got <2> rules
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got UserPlugin plugin for event EventGetUser/7
?Debug : Mar 06 15:26:28 DBCtx: <163165384> SQL query: BEGIN
?Debug : Mar 06 15:26:28 DBCtx: DB transaction begin
?Debug : Mar 06 15:26:28 DBCtx: <163165384> SQL SELECT query: SELECT login, password, basic_account, 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, email, house_id, flat_number, entrance,floor, district, building, passport, personal_manager, connect_date, is_send_invoice,advance_payment,remote_switch_id,port_number FROM users WHERE id='2' AND is_deleted=0
?Debug : Mar 06 15:26:28 DBCtx: <163165384> SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='2'
?Debug : Mar 06 15:26:28 DBCtx: <163165384> SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='2'
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:28 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:28 RfwPlugin: final command: [clear access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:28 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:28 RfwPlugin: final command: [clear access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:28 DBCtx: <163165384> SQL query: COMMIT
?Debug : Mar 06 15:26:28 DBCtx: DB transaction commit
?Debug : Mar 06 15:26:28 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c1a160> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: empty transaction ptr <0x09c1a160> dropped
?Debug : Mar 06 15:26:28 DummyTransactionQueue: commit: 2 transactions
?Debug : Mar 06 15:26:28 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c5d678> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: transaction ptr <0x09c5d678> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:28 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c0dac8> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: transaction ptr <0x09c0dac8> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:28 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c101c8> done
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c5d678>, outgoing transaction ptr <0x09c101c8>
?Debug : Mar 06 15:26:28 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:28 FW@192.168.115.223: Sending [clear access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:28 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c101c8> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: empty transaction ptr <0x09c101c8> dropped
?Debug : Mar 06 15:26:28 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:28 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c5d678> done
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c0dac8>, outgoing transaction ptr <0x09c5d678>
?Debug : Mar 06 15:26:28 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:28 FW@192.168.115.223: Sending [clear access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:28 AffectorsPlugin: firewall <fw@centos> not connected, rule <clear access-template 106 test2 any host 192.168.93.99> not executed
?Debug : Mar 06 15:26:28 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c5d678> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: empty transaction ptr <0x09c5d678> dropped
?Debug : Mar 06 15:26:28 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:28 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c0dac8> done
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:28 RPCServer@0.0.0.0: rpcf_get_users_list: from: 0, to:2, cnt: 2
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call 0x2001 (rpcf_get_users_list) finished...
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:32 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:37 DBCtx: <162996952> SQL query: UPDATE accounts SET int_status='1' WHERE id='2'
?Debug : Mar 06 15:26:37 BusLogic: BLM(39) pushed (comment: )
?Debug : Mar 06 15:26:37 UTM5 DBA: hw unblock for account 2
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call 0x2003 (rpcf_change_intstat_for_user) finished...
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:37 BusLogic: try to execute 39
?Debug : Mar 06 15:26:37 BusLogic: hw_block_handler with code 39
?Debug : Mar 06 15:26:37 BusLogic: hw_block_handler start bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9c0d258> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: transaction ptr <0x09c0d258> (size 1, Events [ 17 ])
?Debug : Mar 06 15:26:37 BusLogic: hw_block_handler end bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:37 BusLogic: finished unknown
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c0d258>, outgoing transaction ptr <0x09bf6c98>
?Debug : Mar 06 15:26:37 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got RfwPlugin plugin for event EventSwitchInet/17
?Debug : Mar 06 15:26:37 RfwPlugin: generating inet switch rules for account <2> state <1>
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got FwRulesPlugin plugin for event EventGetFWRules/8
?Debug : Mar 06 15:26:37 FwRulesPlugin: get_fwrules: got <2> rules
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got UserPlugin plugin for event EventGetUser/7
?Debug : Mar 06 15:26:37 DBCtx: <163139384> SQL query: BEGIN
?Debug : Mar 06 15:26:37 DBCtx: DB transaction begin
?Debug : Mar 06 15:26:37 DBCtx: <163139384> SQL SELECT query: SELECT login, password, basic_account, 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, email, house_id, flat_number, entrance,floor, district, building, passport, personal_manager, connect_date, is_send_invoice,advance_payment,remote_switch_id,port_number FROM users WHERE id='2' AND is_deleted=0
?Debug : Mar 06 15:26:37 DBCtx: <163139384> SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='2'
?Debug : Mar 06 15:26:37 DBCtx: <163139384> SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='2'
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:37 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:37 RfwPlugin: final command: [access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:37 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:37 RfwPlugin: final command: [access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:37 DBCtx: <163139384> SQL query: COMMIT
?Debug : Mar 06 15:26:37 DBCtx: DB transaction commit
?Debug : Mar 06 15:26:37 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9bf6c98> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: empty transaction ptr <0x09bf6c98> dropped
?Debug : Mar 06 15:26:37 DummyTransactionQueue: commit: 2 transactions
?Debug : Mar 06 15:26:37 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9c5c018> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: transaction ptr <0x09c5c018> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:37 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9c5c3a8> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: transaction ptr <0x09c5c3a8> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:37 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c0d258> done
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c5c018>, outgoing transaction ptr <0x09c0d258>
?Debug : Mar 06 15:26:37 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:37 FW@192.168.115.223: Sending [access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:37 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9c0d258> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: empty transaction ptr <0x09c0d258> dropped
?Debug : Mar 06 15:26:37 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:37 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c5c018> done
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3a8>, outgoing transaction ptr <0x09c5c018>
?Debug : Mar 06 15:26:37 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:37 FW@192.168.115.223: Sending [access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:37 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9c5c018> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: empty transaction ptr <0x09c5c018> dropped
?Debug : Mar 06 15:26:37 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:37 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3a8> done
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:37 RPCServer@0.0.0.0: rpcf_get_users_list: from: 0, to:2, cnt: 2
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call 0x2001 (rpcf_get_users_list) finished...
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:58 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:58 RPCConn[SSL]<init@192.168.14.110>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:26:58 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:26:58 RPCConn[SSL]<init@192.168.14.110>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Mar 06 15:26:58 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:27:02 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:27:32 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:27:56 BusClassif: aggregation interval reached for slink <1> ip <0> tclass <0>
?Debug : Mar 06 15:27:56 UTM5 DBA: DBAccess instance created
?Debug : Mar 06 15:27:56 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:27:56 DBCtx: <163113472> SQL query: BEGIN
?Debug : Mar 06 15:27:56 DBCtx: DB transaction begin
?Debug : Mar 06 15:27:56 DBCtx: <163113472> SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='1' AND tclass_id='0'
?Debug : Mar 06 15:27:56 DBCtx: <163113472> SQL query: UPDATE downloaded SET qnt='6469854', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='1' AND tclass_id='0'
?Debug : Mar 06 15:27:56 DTAgg: update dtagg_iptraffic for slink_id 1
?Debug : Mar 06 15:27:56 UTM5 DBA: Charge:0.000000 p.u. for link:1 account 1
?Debug : Mar 06 15:27:56 DBCtx: <163113472> SQL query: UPDATE accounts SET balance='0' WHERE id = '1'
?Debug : Mar 06 15:27:56 DBCtx: <163113472> 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('1','0','0','0','0','2','3','1','1425644876','3','2')
?Debug : Mar 06 15:27:56 UTM5 DBA: Checking for rehash: flags 3, balance 0.000 (old 0.000), credit 0.000
?Debug : Mar 06 15:27:56 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: f6d5ae98
?Debug : Mar 06 15:27:56 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Mar 06 15:27:56 DBCtx: <163113472> 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('199','1','0','0','2','1','1425644876','1425643200','1425589200','1425157200','0','0','0','256167','2')
?Debug : Mar 06 15:27:56 BusLogic: try to execute 37
?Debug : Mar 06 15:27:56 BusLogic: hw_block_handler with code 37
?Debug : Mar 06 15:27:56 DBCtx: <163113472> SQL query: COMMIT
?Debug : Mar 06 15:27:56 DBCtx: DB transaction commit
?Debug : Mar 06 15:27:56 DBA:Ctx: Pushing back free context (system=1)
-Stats : Mar 06 15:27:56 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Mar 06 15:27:56 BusLogic: finished unknown
?Debug : Mar 06 15:27:58 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:27:58 RPCConn[SSL]<init@192.168.14.110>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:27:58 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:27:58 RPCConn[SSL]<init@192.168.14.110>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Mar 06 15:27:58 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:28:02 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:28:32 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:28:58 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:28:58 RPCConn[SSL]<init@192.168.14.110>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:28:58 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:28:58 RPCConn[SSL]<init@192.168.14.110>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Mar 06 15:28:58 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:29:02 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:29:32 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:29:58 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:29:58 RPCConn[SSL]<init@192.168.14.110>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:29:58 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:29:58 RPCConn[SSL]<init@192.168.14.110>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Mar 06 15:29:58 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:30:02 FW@192.168.115.223: ping reply received

gagarin
Сообщения: 16
Зарегистрирован: Пт мар 06, 2015 15:10

Re: UTM5_rfw rsh cisco

Сообщение gagarin »

gagarin писал(а): Cisco debug:

Mar 6 12:25:22.516: RCMD: [514 <- 192.168.115.15:1023] recv 1022\0
Mar 6 12:25:22.716: RCMD: [514 <- 192.168.115.15:1023] recv netup\0netup\0clear access-template 105 test1 host 192.168.93.99 any\0
Mar 6 12:25:22.716: RCMD: [514 -> 192.168.115.15:1023] send <OK>
Mar 6 12:25:22.816: RCMD: [514 <- 192.168.115.15:1021] recv 1020\0
Mar 6 12:25:23.016: RCMD: [514 <- 192.168.115.15:1021] recv netup\0netup\0clear access-template 106 test2 any host 192.168.93.99\0
Mar 6 12:25:23.016: RCMD: [514 -> 192.168.115.15:1021] send <OK>
telecom#
Mar 6 12:25:31.620: RCMD: [514 <- 192.168.115.15:1023] recv 1022\0
Mar 6 12:25:31.820: RCMD: [514 <- 192.168.115.15:1023] recv netup\0netup\0access-template 105 test1 host 192.168.93.99 any\0
Mar 6 12:25:31.820: RCMD: [514 -> 192.168.115.15:1023] send <OK>
Mar 6 12:25:31.920: RCMD: [514 <- 192.168.115.15:1021] recv 1020\0
Mar 6 12:25:32.120: RCMD: [514 <- 192.168.115.15:1021] recv netup\0netup\0access-template 106 test2 any host 192.168.93.99\0
Mar 6 12:25:32.120: RCMD: [514 -> 192.168.115.15:1021] send <OK>

Аксес листы:

telecom#sh access-lists
Standard IP access list 1
10 permit 192.168.93.0, wildcard bits 0.0.0.255 (52781 matches)
20 permit 192.168.115.0, wildcard bits 0.0.0.255
Standard IP access list 10
30 permit 192.168.115.15 (54 matches)
20 permit 192.168.93.20 (20 matches)
10 permit 192.168.93.1 log (10 matches)
Extended IP access list 105
10 Dynamic TEST1 permit ip any any
20 permit ip host 192.168.115.15 any
30 permit ip host 192.168.93.20 any (105743 matches)
Extended IP access list 106
10 Dynamic TEST2 permit ip any any
permit ip any host 192.168.93.25
permit ip any host 192.168.93.21
20 permit ip any host 192.168.115.15
30 permit ip any host 192.168.93.20 (32856 matches)
У меня проблема в том оказалась, что акссес листы названы капсом, а правила в фаерволе нет.

f.hokimov@mail.ru
Сообщения: 10
Зарегистрирован: Вт авг 25, 2015 09:08

Re: UTM5_rfw rsh cisco

Сообщение f.hokimov@mail.ru »

gagarin писал(а):Уважаемые коллеги!
Подскажите, если кто сталкивался.
Пытаюсь включать/выключать тестовому пользователю интернет, дебаг cisco пишет, что все ок, но правила в это время не появляются, если писать руками из терминала, где установлен UTM - все ok.

rfw5.cfg

rfw_name=192.168.115.223
core_host=127.0.0.1
core_port=12758
rfw_login=init
rfw_password=init
firewall_type=cisco
rfw_ssl_type=none
firewall_path=/etc/rc.d/init.d/utm5_rfw.sh
dont_fork=yes
cisco_ip=192.168.115.223
log_level=3
log_file_main=/netup/utm5/log/rfw.log
log_file_debug=/netup/utm5/log/rfw.log
log_file_critical=/netup/utm5/log/rfw.log

Cisco debug:

Mar 6 12:25:22.516: RCMD: [514 <- 192.168.115.15:1023] recv 1022\0
Mar 6 12:25:22.716: RCMD: [514 <- 192.168.115.15:1023] recv netup\0netup\0clear access-template 105 test1 host 192.168.93.99 any\0
Mar 6 12:25:22.716: RCMD: [514 -> 192.168.115.15:1023] send <OK>
Mar 6 12:25:22.816: RCMD: [514 <- 192.168.115.15:1021] recv 1020\0
Mar 6 12:25:23.016: RCMD: [514 <- 192.168.115.15:1021] recv netup\0netup\0clear access-template 106 test2 any host 192.168.93.99\0
Mar 6 12:25:23.016: RCMD: [514 -> 192.168.115.15:1021] send <OK>
telecom#
Mar 6 12:25:31.620: RCMD: [514 <- 192.168.115.15:1023] recv 1022\0
Mar 6 12:25:31.820: RCMD: [514 <- 192.168.115.15:1023] recv netup\0netup\0access-template 105 test1 host 192.168.93.99 any\0
Mar 6 12:25:31.820: RCMD: [514 -> 192.168.115.15:1023] send <OK>
Mar 6 12:25:31.920: RCMD: [514 <- 192.168.115.15:1021] recv 1020\0
Mar 6 12:25:32.120: RCMD: [514 <- 192.168.115.15:1021] recv netup\0netup\0access-template 106 test2 any host 192.168.93.99\0
Mar 6 12:25:32.120: RCMD: [514 -> 192.168.115.15:1021] send <OK>

Аксес листы:

telecom#sh access-lists
Standard IP access list 1
10 permit 192.168.93.0, wildcard bits 0.0.0.255 (52781 matches)
20 permit 192.168.115.0, wildcard bits 0.0.0.255
Standard IP access list 10
30 permit 192.168.115.15 (54 matches)
20 permit 192.168.93.20 (20 matches)
10 permit 192.168.93.1 log (10 matches)
Extended IP access list 105
10 Dynamic TEST1 permit ip any any
20 permit ip host 192.168.115.15 any
30 permit ip host 192.168.93.20 any (105743 matches)
Extended IP access list 106
10 Dynamic TEST2 permit ip any any
permit ip any host 192.168.93.25
permit ip any host 192.168.93.21
20 permit ip any host 192.168.115.15
30 permit ip any host 192.168.93.20 (32856 matches)

rfw.log

?Debug : Mar 06 15:25:32 StreamFirewall: Got ping from core. Sending reply...
?Debug : Mar 06 15:26:02 StreamFirewall: Got ping from core. Sending reply...
?Debug : Mar 06 15:26:24 StreamFirewall: Got 'exec' command...
?Debug : Mar 06 15:26:24 FWCntl: Send rule<clear access-template 105 test1 host 192.168.93.99 any> to remote cisco <192.168.115.223>
?Debug : Mar 06 15:26:24 FWCntl: Call RSH: host 192.168.115.223, port 514, login netup, pass , cmd clear access-template 105 test1 host 192.168.93.99 any
Notice: Mar 06 15:26:24 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:24 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:24 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:24 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
?Debug : Mar 06 15:26:24 StreamFirewall: Got 'exec' command...
?Debug : Mar 06 15:26:24 FWCntl: Send rule<clear access-template 106 test2 any host 192.168.93.99> to remote cisco <192.168.115.223>
?Debug : Mar 06 15:26:24 FWCntl: Call RSH: host 192.168.115.223, port 514, login netup, pass , cmd clear access-template 106 test2 any host 192.168.93.99
Notice: Mar 06 15:26:25 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:25 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:25 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:25 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
?Debug : Mar 06 15:26:26 StreamFirewall: Got 'exec' command...
?Debug : Mar 06 15:26:26 FWCntl: Send rule<access-template 105 test1 host 192.168.93.99 any> to remote cisco <192.168.115.223>
?Debug : Mar 06 15:26:26 FWCntl: Call RSH: host 192.168.115.223, port 514, login netup, pass , cmd access-template 105 test1 host 192.168.93.99 any
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
?Debug : Mar 06 15:26:27 StreamFirewall: Got 'exec' command...
?Debug : Mar 06 15:26:27 FWCntl: Send rule<access-template 106 test2 any host 192.168.93.99> to remote cisco <192.168.115.223>
?Debug : Mar 06 15:26:27 FWCntl: Call RSH: host 192.168.115.223, port 514, login netup, pass , cmd access-template 106 test2 any host 192.168.93.99
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(rfd) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>
Notice: Mar 06 15:26:27 FWCntl: Can't shutdown(sock) while recv data from rsh soscket ... Error:<Bad file descriptor>

Debug.log

?Debug : Mar 06 15:26:18 TransactionQueueManager: pushing transaction <0x9c0d240> into queue <2> (default)
?Debug : Mar 06 15:26:18 TransactionHandlerImpl: push: transaction ptr <0x09c0d240> (size 1, Events [ 114 ])
?Debug : Mar 06 15:26:18 TransactionHandlerImpl: incoming transaction ptr <0x09c0d240>, outgoing transaction ptr <0x09bf6c98>
?Debug : Mar 06 15:26:18 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:18 PluginManagerImpl: Got DynaShapePlugin plugin for event EventShapingCheckTimeranges/114
?Debug : Mar 06 15:26:18 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:18 TransactionQueueManager: pushing transaction <0x9bf6c98> into queue <1> (default)
?Debug : Mar 06 15:26:18 TransactionHandlerImpl: push: empty transaction ptr <0x09bf6c98> dropped
?Debug : Mar 06 15:26:18 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:18 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:18 TransactionHandlerImpl: incoming transaction ptr <0x09c0d240> done
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:24 DBCtx: <162996952> SQL query: UPDATE accounts SET int_status='0' WHERE id='2'
?Debug : Mar 06 15:26:24 BusLogic: BLM(38) pushed (comment: )
?Debug : Mar 06 15:26:24 UTM5 DBA: hw block for account 2
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call 0x2003 (rpcf_change_intstat_for_user) finished...
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:24 BusLogic: try to execute 38
?Debug : Mar 06 15:26:24 BusLogic: hw_block_handler with code 38
?Debug : Mar 06 15:26:24 BusLogic: hw_block_handler start bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9c0d240> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: transaction ptr <0x09c0d240> (size 1, Events [ 17 ])
?Debug : Mar 06 15:26:24 BusLogic: hw_block_handler end bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:24 BusLogic: finished unknown
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c0d240>, outgoing transaction ptr <0x09bf6c98>
?Debug : Mar 06 15:26:24 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got RfwPlugin plugin for event EventSwitchInet/17
?Debug : Mar 06 15:26:24 RfwPlugin: generating inet switch rules for account <2> state <0>
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got FwRulesPlugin plugin for event EventGetFWRules/8
?Debug : Mar 06 15:26:24 FwRulesPlugin: get_fwrules: got <2> rules
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got UserPlugin plugin for event EventGetUser/7
?Debug : Mar 06 15:26:24 DBCtx: <163113472> SQL query: BEGIN
?Debug : Mar 06 15:26:24 DBCtx: DB transaction begin
?Debug : Mar 06 15:26:24 DBCtx: <163113472> SQL SELECT query: SELECT login, password, basic_account, 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, email, house_id, flat_number, entrance,floor, district, building, passport, personal_manager, connect_date, is_send_invoice,advance_payment,remote_switch_id,port_number FROM users WHERE id='2' AND is_deleted=0
?Debug : Mar 06 15:26:24 DBCtx: <163113472> SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='2'
?Debug : Mar 06 15:26:24 DBCtx: <163113472> SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='2'
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:24 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:24 RfwPlugin: final command: [clear access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:24 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:24 RfwPlugin: final command: [clear access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:24 DBCtx: <163113472> SQL query: COMMIT
?Debug : Mar 06 15:26:24 DBCtx: DB transaction commit
?Debug : Mar 06 15:26:24 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9bf6c98> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: empty transaction ptr <0x09bf6c98> dropped
?Debug : Mar 06 15:26:24 DummyTransactionQueue: commit: 2 transactions
?Debug : Mar 06 15:26:24 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9c5c018> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: transaction ptr <0x09c5c018> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:24 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9c5c3b8> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: transaction ptr <0x09c5c3b8> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:24 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c0d240> done
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c5c018>, outgoing transaction ptr <0x09c0d240>
?Debug : Mar 06 15:26:24 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:24 FW@192.168.115.223: Sending [clear access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:24 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9c0d240> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: empty transaction ptr <0x09c0d240> dropped
?Debug : Mar 06 15:26:24 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:24 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c5c018> done
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3b8>, outgoing transaction ptr <0x09c5c018>
?Debug : Mar 06 15:26:24 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:24 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:24 FW@192.168.115.223: Sending [clear access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:24 AffectorsPlugin: firewall <fw@centos> not connected, rule <clear access-template 106 test2 any host 192.168.93.99> not executed
?Debug : Mar 06 15:26:24 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:24 TransactionQueueManager: pushing transaction <0x9c5c018> into queue <0>
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: push: empty transaction ptr <0x09c5c018> dropped
?Debug : Mar 06 15:26:24 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:24 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:24 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3b8> done
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:24 RPCServer@0.0.0.0: rpcf_get_users_list: from: 0, to:2, cnt: 2
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Call 0x2001 (rpcf_get_users_list) finished...
?Debug : Mar 06 15:26:24 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:26 DBCtx: <162996952> SQL query: UPDATE accounts SET int_status='1' WHERE id='2'
?Debug : Mar 06 15:26:26 BusLogic: BLM(39) pushed (comment: )
?Debug : Mar 06 15:26:26 UTM5 DBA: hw unblock for account 2
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call 0x2003 (rpcf_change_intstat_for_user) finished...
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:26 BusLogic: try to execute 39
?Debug : Mar 06 15:26:26 BusLogic: hw_block_handler with code 39
?Debug : Mar 06 15:26:26 BusLogic: hw_block_handler start bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c101c8> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: transaction ptr <0x09c101c8> (size 1, Events [ 17 ])
?Debug : Mar 06 15:26:26 BusLogic: hw_block_handler end bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:26 BusLogic: finished unknown
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c101c8>, outgoing transaction ptr <0x09c1a160>
?Debug : Mar 06 15:26:26 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got RfwPlugin plugin for event EventSwitchInet/17
?Debug : Mar 06 15:26:26 RfwPlugin: generating inet switch rules for account <2> state <1>
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got FwRulesPlugin plugin for event EventGetFWRules/8
?Debug : Mar 06 15:26:26 FwRulesPlugin: get_fwrules: got <2> rules
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got UserPlugin plugin for event EventGetUser/7
?Debug : Mar 06 15:26:26 DBCtx: <163087912> SQL query: BEGIN
?Debug : Mar 06 15:26:26 DBCtx: DB transaction begin
?Debug : Mar 06 15:26:26 DBCtx: <163087912> SQL SELECT query: SELECT login, password, basic_account, 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, email, house_id, flat_number, entrance,floor, district, building, passport, personal_manager, connect_date, is_send_invoice,advance_payment,remote_switch_id,port_number FROM users WHERE id='2' AND is_deleted=0
?Debug : Mar 06 15:26:26 DBCtx: <163087912> SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='2'
?Debug : Mar 06 15:26:26 DBCtx: <163087912> SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='2'
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:26 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:26 RfwPlugin: final command: [access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:26 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:26 RfwPlugin: final command: [access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:26 DBCtx: <163087912> SQL query: COMMIT
?Debug : Mar 06 15:26:26 DBCtx: DB transaction commit
?Debug : Mar 06 15:26:26 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c1a160> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: empty transaction ptr <0x09c1a160> dropped
?Debug : Mar 06 15:26:26 DummyTransactionQueue: commit: 2 transactions
?Debug : Mar 06 15:26:26 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c5c070> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: transaction ptr <0x09c5c070> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:26 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c5c3d8> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: transaction ptr <0x09c5c3d8> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:26 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c101c8> done
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c5c070>, outgoing transaction ptr <0x09c101c8>
?Debug : Mar 06 15:26:26 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:26 FW@192.168.115.223: Sending [access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:26 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c101c8> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: empty transaction ptr <0x09c101c8> dropped
?Debug : Mar 06 15:26:26 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:26 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c5c070> done
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3d8>, outgoing transaction ptr <0x09c5c070>
?Debug : Mar 06 15:26:26 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:26 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:26 FW@192.168.115.223: Sending [access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:26 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:26 TransactionQueueManager: pushing transaction <0x9c5c070> into queue <0>
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: push: empty transaction ptr <0x09c5c070> dropped
?Debug : Mar 06 15:26:26 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:26 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:26 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3d8> done
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:26 RPCServer@0.0.0.0: rpcf_get_users_list: from: 0, to:2, cnt: 2
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Call 0x2001 (rpcf_get_users_list) finished...
?Debug : Mar 06 15:26:26 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:28 DBCtx: <162996952> SQL query: UPDATE accounts SET int_status='0' WHERE id='2'
?Debug : Mar 06 15:26:28 BusLogic: BLM(38) pushed (comment: )
?Debug : Mar 06 15:26:28 UTM5 DBA: hw block for account 2
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call 0x2003 (rpcf_change_intstat_for_user) finished...
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:28 BusLogic: try to execute 38
?Debug : Mar 06 15:26:28 BusLogic: hw_block_handler with code 38
?Debug : Mar 06 15:26:28 BusLogic: hw_block_handler start bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c101c8> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: transaction ptr <0x09c101c8> (size 1, Events [ 17 ])
?Debug : Mar 06 15:26:28 BusLogic: hw_block_handler end bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:28 BusLogic: finished unknown
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c101c8>, outgoing transaction ptr <0x09c1a160>
?Debug : Mar 06 15:26:28 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got RfwPlugin plugin for event EventSwitchInet/17
?Debug : Mar 06 15:26:28 RfwPlugin: generating inet switch rules for account <2> state <0>
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got FwRulesPlugin plugin for event EventGetFWRules/8
?Debug : Mar 06 15:26:28 FwRulesPlugin: get_fwrules: got <2> rules
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got UserPlugin plugin for event EventGetUser/7
?Debug : Mar 06 15:26:28 DBCtx: <163165384> SQL query: BEGIN
?Debug : Mar 06 15:26:28 DBCtx: DB transaction begin
?Debug : Mar 06 15:26:28 DBCtx: <163165384> SQL SELECT query: SELECT login, password, basic_account, 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, email, house_id, flat_number, entrance,floor, district, building, passport, personal_manager, connect_date, is_send_invoice,advance_payment,remote_switch_id,port_number FROM users WHERE id='2' AND is_deleted=0
?Debug : Mar 06 15:26:28 DBCtx: <163165384> SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='2'
?Debug : Mar 06 15:26:28 DBCtx: <163165384> SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='2'
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:28 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:28 RfwPlugin: final command: [clear access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:28 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:28 RfwPlugin: final command: [clear access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:28 DBCtx: <163165384> SQL query: COMMIT
?Debug : Mar 06 15:26:28 DBCtx: DB transaction commit
?Debug : Mar 06 15:26:28 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c1a160> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: empty transaction ptr <0x09c1a160> dropped
?Debug : Mar 06 15:26:28 DummyTransactionQueue: commit: 2 transactions
?Debug : Mar 06 15:26:28 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c5d678> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: transaction ptr <0x09c5d678> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:28 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c0dac8> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: transaction ptr <0x09c0dac8> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:28 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c101c8> done
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c5d678>, outgoing transaction ptr <0x09c101c8>
?Debug : Mar 06 15:26:28 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:28 FW@192.168.115.223: Sending [clear access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:28 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c101c8> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: empty transaction ptr <0x09c101c8> dropped
?Debug : Mar 06 15:26:28 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:28 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c5d678> done
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c0dac8>, outgoing transaction ptr <0x09c5d678>
?Debug : Mar 06 15:26:28 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:28 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:28 FW@192.168.115.223: Sending [clear access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:28 AffectorsPlugin: firewall <fw@centos> not connected, rule <clear access-template 106 test2 any host 192.168.93.99> not executed
?Debug : Mar 06 15:26:28 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:28 TransactionQueueManager: pushing transaction <0x9c5d678> into queue <0>
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: push: empty transaction ptr <0x09c5d678> dropped
?Debug : Mar 06 15:26:28 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:28 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:28 TransactionHandlerImpl: incoming transaction ptr <0x09c0dac8> done
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:28 RPCServer@0.0.0.0: rpcf_get_users_list: from: 0, to:2, cnt: 2
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Call 0x2001 (rpcf_get_users_list) finished...
?Debug : Mar 06 15:26:28 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:32 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2003 (rpcf_change_intstat_for_user)
?Debug : Mar 06 15:26:37 DBCtx: <162996952> SQL query: UPDATE accounts SET int_status='1' WHERE id='2'
?Debug : Mar 06 15:26:37 BusLogic: BLM(39) pushed (comment: )
?Debug : Mar 06 15:26:37 UTM5 DBA: hw unblock for account 2
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call 0x2003 (rpcf_change_intstat_for_user) finished...
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:37 BusLogic: try to execute 39
?Debug : Mar 06 15:26:37 BusLogic: hw_block_handler with code 39
?Debug : Mar 06 15:26:37 BusLogic: hw_block_handler start bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9c0d258> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: transaction ptr <0x09c0d258> (size 1, Events [ 17 ])
?Debug : Mar 06 15:26:37 BusLogic: hw_block_handler end bla_user_hw_unblock|bla_user_hw_block
?Debug : Mar 06 15:26:37 BusLogic: finished unknown
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c0d258>, outgoing transaction ptr <0x09bf6c98>
?Debug : Mar 06 15:26:37 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got RfwPlugin plugin for event EventSwitchInet/17
?Debug : Mar 06 15:26:37 RfwPlugin: generating inet switch rules for account <2> state <1>
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got FwRulesPlugin plugin for event EventGetFWRules/8
?Debug : Mar 06 15:26:37 FwRulesPlugin: get_fwrules: got <2> rules
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got UserPlugin plugin for event EventGetUser/7
?Debug : Mar 06 15:26:37 DBCtx: <163139384> SQL query: BEGIN
?Debug : Mar 06 15:26:37 DBCtx: DB transaction begin
?Debug : Mar 06 15:26:37 DBCtx: <163139384> SQL SELECT query: SELECT login, password, basic_account, 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, email, house_id, flat_number, entrance,floor, district, building, passport, personal_manager, connect_date, is_send_invoice,advance_payment,remote_switch_id,port_number FROM users WHERE id='2' AND is_deleted=0
?Debug : Mar 06 15:26:37 DBCtx: <163139384> SQL SELECT query: SELECT group_id FROM users_groups_link WHERE user_id='2'
?Debug : Mar 06 15:26:37 DBCtx: <163139384> SQL SELECT query: SELECT paramid, value FROM user_additional_params WHERE userid='2'
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:37 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:37 RfwPlugin: final command: [access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got IPgrpPlugin plugin for event EventGetIPGroup/22
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got FwRulesPlugin plugin for event EventSubstFWRule/16
?Debug : Mar 06 15:26:37 FwRulesPlugin: subst_fwrule: replaced <UIP> to <192.168.93.99>
Info : Mar 06 15:26:37 RfwPlugin: final command: [access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:37 DBCtx: <163139384> SQL query: COMMIT
?Debug : Mar 06 15:26:37 DBCtx: DB transaction commit
?Debug : Mar 06 15:26:37 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9bf6c98> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: empty transaction ptr <0x09bf6c98> dropped
?Debug : Mar 06 15:26:37 DummyTransactionQueue: commit: 2 transactions
?Debug : Mar 06 15:26:37 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9c5c018> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: transaction ptr <0x09c5c018> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:37 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9c5c3a8> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: transaction ptr <0x09c5c3a8> (size 1, Events [ 4 ])
?Debug : Mar 06 15:26:37 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c0d258> done
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c5c018>, outgoing transaction ptr <0x09c0d258>
?Debug : Mar 06 15:26:37 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:37 FW@192.168.115.223: Sending [access-template 105 test1 host 192.168.93.99 any]
?Debug : Mar 06 15:26:37 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9c0d258> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: empty transaction ptr <0x09c0d258> dropped
?Debug : Mar 06 15:26:37 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:37 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c5c018> done
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3a8>, outgoing transaction ptr <0x09c5c018>
?Debug : Mar 06 15:26:37 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:26:37 PluginManagerImpl: Got AffectorsPlugin plugin for event EventExecFWRule/4
?Debug : Mar 06 15:26:37 FW@192.168.115.223: Sending [access-template 106 test2 any host 192.168.93.99]
?Debug : Mar 06 15:26:37 TransactionFilter: transaction sent to the internal queue
?Debug : Mar 06 15:26:37 TransactionQueueManager: pushing transaction <0x9c5c018> into queue <0>
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: push: empty transaction ptr <0x09c5c018> dropped
?Debug : Mar 06 15:26:37 DummyTransactionQueue: commit: 0 transactions
?Debug : Mar 06 15:26:37 DBA:Ctx: Pushing back free context (system=1)
?Debug : Mar 06 15:26:37 TransactionHandlerImpl: incoming transaction ptr <0x09c5c3a8> done
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2011 (rpcf_get_users_count)
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call 0x2011 (rpcf_get_users_count) finished...
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x2001 (rpcf_get_users_list)
?Debug : Mar 06 15:26:37 RPCServer@0.0.0.0: rpcf_get_users_list: from: 0, to:2, cnt: 2
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Call 0x2001 (rpcf_get_users_list) finished...
?Debug : Mar 06 15:26:37 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:26:58 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:26:58 RPCConn[SSL]<init@192.168.14.110>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:26:58 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:26:58 RPCConn[SSL]<init@192.168.14.110>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Mar 06 15:26:58 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:27:02 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:27:32 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:27:56 BusClassif: aggregation interval reached for slink <1> ip <0> tclass <0>
?Debug : Mar 06 15:27:56 UTM5 DBA: DBAccess instance created
?Debug : Mar 06 15:27:56 DBA:Ctx: Looking for free context (system=1)
?Debug : Mar 06 15:27:56 DBCtx: <163113472> SQL query: BEGIN
?Debug : Mar 06 15:27:56 DBCtx: DB transaction begin
?Debug : Mar 06 15:27:56 DBCtx: <163113472> SQL SELECT query: SELECT discounted,qnt,downed_as_prepaid FROM downloaded WHERE is_deleted=0 AND downloaded_id='1' AND tclass_id='0'
?Debug : Mar 06 15:27:56 DBCtx: <163113472> SQL query: UPDATE downloaded SET qnt='6469854', discounted='0', downed_as_prepaid='0' WHERE downloaded_id='1' AND tclass_id='0'
?Debug : Mar 06 15:27:56 DTAgg: update dtagg_iptraffic for slink_id 1
?Debug : Mar 06 15:27:56 UTM5 DBA: Charge:0.000000 p.u. for link:1 account 1
?Debug : Mar 06 15:27:56 DBCtx: <163113472> SQL query: UPDATE accounts SET balance='0' WHERE id = '1'
?Debug : Mar 06 15:27:56 DBCtx: <163113472> 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('1','0','0','0','0','2','3','1','1425644876','3','2')
?Debug : Mar 06 15:27:56 UTM5 DBA: Checking for rehash: flags 3, balance 0.000 (old 0.000), credit 0.000
?Debug : Mar 06 15:27:56 DBAGiga: Rehash: Target: 10; Action: 1; Ptr: f6d5ae98
?Debug : Mar 06 15:27:56 BusLogic: BLM(37) pushed (comment: ruh block)
?Debug : Mar 06 15:27:56 DBCtx: <163113472> 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('199','1','0','0','2','1','1425644876','1425643200','1425589200','1425157200','0','0','0','256167','2')
?Debug : Mar 06 15:27:56 BusLogic: try to execute 37
?Debug : Mar 06 15:27:56 BusLogic: hw_block_handler with code 37
?Debug : Mar 06 15:27:56 DBCtx: <163113472> SQL query: COMMIT
?Debug : Mar 06 15:27:56 DBCtx: DB transaction commit
?Debug : Mar 06 15:27:56 DBA:Ctx: Pushing back free context (system=1)
-Stats : Mar 06 15:27:56 UTM5 DBA: Stats: Uptime: 00:00:00. Events: 0; Errors: 0
?Debug : Mar 06 15:27:56 BusLogic: finished unknown
?Debug : Mar 06 15:27:58 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:27:58 RPCConn[SSL]<init@192.168.14.110>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:27:58 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:27:58 RPCConn[SSL]<init@192.168.14.110>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Mar 06 15:27:58 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:28:02 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:28:32 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:28:58 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:28:58 RPCConn[SSL]<init@192.168.14.110>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:28:58 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:28:58 RPCConn[SSL]<init@192.168.14.110>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Mar 06 15:28:58 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:29:02 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:29:32 FW@192.168.115.223: ping reply received
?Debug : Mar 06 15:29:58 RPCConn[SSL]<init@192.168.14.110>: URFA ping received, sending reply
?Debug : Mar 06 15:29:58 RPCConn[SSL]<init@192.168.14.110>: Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:29:58 RPCConn[SSL]<init@192.168.14.110>: Real Call: 0x11112 (rpcf_get_core_time)
?Debug : Mar 06 15:29:58 RPCConn[SSL]<init@192.168.14.110>: Call 0x11112 (rpcf_get_core_time) finished...
?Debug : Mar 06 15:29:58 RPCConn[SSL]<init@192.168.14.110>: Stream cleared
?Debug : Mar 06 15:30:02 FW@192.168.115.223: ping reply received

Уважаемый! Вы решили свою проблему? Подскажите пожалуйста если да в чем была проблема?

Ответить