Discarding duplicate request due to unfinished request in 3.0.2

[sergey-gt-ekb]

I have run acct test with radclient, and I have some response stucks. Its happen when radclient reuses particular request id. In debug mod server write to log "Discarding duplicate request due to unfinished request" !!! But request was finished and server must resend response for duplicate request.

Log: cat ~/fr.log2_1_50 Ready to process requests. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=162, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (0) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (0) preacct { (0) [preprocess] = ok (0) acct_counters64.preacct acct_counters64.preacct { (0) update request { (0) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (0) --> 0 (0) Acct-Input-Octets64 = 0 (0) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (0) --> 0 (0) Acct-Output-Octets64 = 0 (0) } # update request = noop (0) } # acct_counters64.preacct acct_counters64.preacct = noop (0) update request { (0) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (0) --> 1398250954 (0) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (0) } # update request = noop (0) acct_unique acct_unique { (0) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (0) EXPAND %{string:Class} (0) --> (0) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (0) else else { (0) update request { (0) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (0) --> f5f5d59c2e7cc6c7f286d9f011502c28 (0) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (0) } # update request = noop (0) } # else else = noop (0) } # acct_unique acct_unique = noop (0) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (0) suffix : No such realm "NULL" (0) [suffix] = noop (0) } # preacct = ok (0) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (0) accounting { (0) [krus_python] = ok (0) if (fail) (0) if (fail) -> FALSE (0) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (0) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (0) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (0) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (0) detail.krus : --> id=162;datetime=2014-04-23 17:02:34;timestamp=1398250954 (0) [detail.krus] = ok (0) attr_filter.accounting_response : EXPAND %{User-Name} (0) attr_filter.accounting_response : --> voip.172.27.96.11 (0) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (0) [attr_filter.accounting_response] = updated (0) } # accounting = updated Sending Accounting-Response of id 162 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (0) Finished request 0. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=10, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (1) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (1) preacct { (1) [preprocess] = ok (1) acct_counters64.preacct acct_counters64.preacct { (1) update request { (1) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (1) --> 0 (1) Acct-Input-Octets64 = 0 (1) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (1) --> 0 (1) Acct-Output-Octets64 = 0 (1) } # update request = noop (1) } # acct_counters64.preacct acct_counters64.preacct = noop (1) update request { (1) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (1) --> 1398250954 (1) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (1) } # update request = noop (1) acct_unique acct_unique { (1) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (1) EXPAND %{string:Class} (1) --> (1) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (1) else else { (1) update request { (1) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (1) --> f5f5d59c2e7cc6c7f286d9f011502c28 (1) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (1) } # update request = noop (1) } # else else = noop (1) } # acct_unique acct_unique = noop (1) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (1) suffix : No such realm "NULL" (1) [suffix] = noop (1) } # preacct = ok (1) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (1) accounting { (1) [krus_python] = ok (1) if (fail) (1) if (fail) -> FALSE (1) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (1) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (1) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (1) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (1) detail.krus : --> id=10;datetime=2014-04-23 17:02:34;timestamp=1398250954 (1) [detail.krus] = ok (1) attr_filter.accounting_response : EXPAND %{User-Name} (1) attr_filter.accounting_response : --> voip.172.27.96.11 (1) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (1) [attr_filter.accounting_response] = updated (1) } # accounting = updated Sending Accounting-Response of id 10 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (1) Finished request 1. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=222, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (2) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (2) preacct { (2) [preprocess] = ok (2) acct_counters64.preacct acct_counters64.preacct { (2) update request { (2) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (2) --> 0 (2) Acct-Input-Octets64 = 0 (2) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (2) --> 0 (2) Acct-Output-Octets64 = 0 (2) } # update request = noop (2) } # acct_counters64.preacct acct_counters64.preacct = noop (2) update request { (2) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (2) --> 1398250954 (2) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (2) } # update request = noop (2) acct_unique acct_unique { (2) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (2) EXPAND %{string:Class} (2) --> (2) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (2) else else { (2) update request { (2) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (2) --> f5f5d59c2e7cc6c7f286d9f011502c28 (2) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (2) } # update request = noop (2) } # else else = noop (2) } # acct_unique acct_unique = noop (2) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (2) suffix : No such realm "NULL" (2) [suffix] = noop (2) } # preacct = ok (2) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (2) accounting { (2) [krus_python] = ok (2) if (fail) (2) if (fail) -> FALSE (2) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (2) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (2) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (2) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (2) detail.krus : --> id=222;datetime=2014-04-23 17:02:34;timestamp=1398250954 (2) [detail.krus] = ok (2) attr_filter.accounting_response : EXPAND %{User-Name} (2) attr_filter.accounting_response : --> voip.172.27.96.11 (2) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (2) [attr_filter.accounting_response] = updated (2) } # accounting = updated Sending Accounting-Response of id 222 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (2) Finished request 2. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=239, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (3) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (3) preacct { (3) [preprocess] = ok (3) acct_counters64.preacct acct_counters64.preacct { (3) update request { (3) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (3) --> 0 (3) Acct-Input-Octets64 = 0 (3) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (3) --> 0 (3) Acct-Output-Octets64 = 0 (3) } # update request = noop (3) } # acct_counters64.preacct acct_counters64.preacct = noop (3) update request { (3) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (3) --> 1398250954 (3) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (3) } # update request = noop (3) acct_unique acct_unique { (3) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (3) EXPAND %{string:Class} (3) --> (3) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (3) else else { (3) update request { (3) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (3) --> f5f5d59c2e7cc6c7f286d9f011502c28 (3) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (3) } # update request = noop (3) } # else else = noop (3) } # acct_unique acct_unique = noop (3) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (3) suffix : No such realm "NULL" (3) [suffix] = noop (3) } # preacct = ok (3) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (3) accounting { (3) [krus_python] = ok (3) if (fail) (3) if (fail) -> FALSE (3) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (3) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (3) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (3) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (3) detail.krus : --> id=239;datetime=2014-04-23 17:02:34;timestamp=1398250954 (3) [detail.krus] = ok (3) attr_filter.accounting_response : EXPAND %{User-Name} (3) attr_filter.accounting_response : --> voip.172.27.96.11 (3) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (3) [attr_filter.accounting_response] = updated (3) } # accounting = updated Sending Accounting-Response of id 239 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (3) Finished request 3. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=31, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (4) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (4) preacct { (4) [preprocess] = ok (4) acct_counters64.preacct acct_counters64.preacct { (4) update request { (4) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (4) --> 0 (4) Acct-Input-Octets64 = 0 (4) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (4) --> 0 (4) Acct-Output-Octets64 = 0 (4) } # update request = noop (4) } # acct_counters64.preacct acct_counters64.preacct = noop (4) update request { (4) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (4) --> 1398250954 (4) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (4) } # update request = noop (4) acct_unique acct_unique { (4) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (4) EXPAND %{string:Class} (4) --> (4) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (4) else else { (4) update request { (4) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (4) --> f5f5d59c2e7cc6c7f286d9f011502c28 (4) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (4) } # update request = noop (4) } # else else = noop (4) } # acct_unique acct_unique = noop (4) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (4) suffix : No such realm "NULL" (4) [suffix] = noop (4) } # preacct = ok (4) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (4) accounting { (4) [krus_python] = ok (4) if (fail) (4) if (fail) -> FALSE (4) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (4) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (4) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (4) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (4) detail.krus : --> id=31;datetime=2014-04-23 17:02:34;timestamp=1398250954 (4) [detail.krus] = ok (4) attr_filter.accounting_response : EXPAND %{User-Name} (4) attr_filter.accounting_response : --> voip.172.27.96.11 (4) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (4) [attr_filter.accounting_response] = updated (4) } # accounting = updated Sending Accounting-Response of id 31 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (4) Finished request 4. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=207, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (5) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (5) preacct { (5) [preprocess] = ok (5) acct_counters64.preacct acct_counters64.preacct { (5) update request { (5) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (5) --> 0 (5) Acct-Input-Octets64 = 0 (5) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (5) --> 0 (5) Acct-Output-Octets64 = 0 (5) } # update request = noop (5) } # acct_counters64.preacct acct_counters64.preacct = noop (5) update request { (5) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (5) --> 1398250954 (5) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (5) } # update request = noop (5) acct_unique acct_unique { (5) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (5) EXPAND %{string:Class} (5) --> (5) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (5) else else { (5) update request { (5) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (5) --> f5f5d59c2e7cc6c7f286d9f011502c28 (5) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (5) } # update request = noop (5) } # else else = noop (5) } # acct_unique acct_unique = noop (5) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (5) suffix : No such realm "NULL" (5) [suffix] = noop (5) } # preacct = ok (5) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (5) accounting { (5) [krus_python] = ok (5) if (fail) (5) if (fail) -> FALSE (5) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (5) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (5) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (5) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (5) detail.krus : --> id=207;datetime=2014-04-23 17:02:34;timestamp=1398250954 (5) [detail.krus] = ok (5) attr_filter.accounting_response : EXPAND %{User-Name} (5) attr_filter.accounting_response : --> voip.172.27.96.11 (5) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (5) [attr_filter.accounting_response] = updated (5) } # accounting = updated Sending Accounting-Response of id 207 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (5) Finished request 5. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=85, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (6) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (6) preacct { (6) [preprocess] = ok (6) acct_counters64.preacct acct_counters64.preacct { (6) update request { (6) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (6) --> 0 (6) Acct-Input-Octets64 = 0 (6) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (6) --> 0 (6) Acct-Output-Octets64 = 0 (6) } # update request = noop (6) } # acct_counters64.preacct acct_counters64.preacct = noop (6) update request { (6) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (6) --> 1398250954 (6) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (6) } # update request = noop (6) acct_unique acct_unique { (6) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (6) EXPAND %{string:Class} (6) --> (6) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (6) else else { (6) update request { (6) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (6) --> f5f5d59c2e7cc6c7f286d9f011502c28 (6) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (6) } # update request = noop (6) } # else else = noop (6) } # acct_unique acct_unique = noop (6) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (6) suffix : No such realm "NULL" (6) [suffix] = noop (6) } # preacct = ok (6) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (6) accounting { (6) [krus_python] = ok (6) if (fail) (6) if (fail) -> FALSE (6) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (6) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (6) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (6) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (6) detail.krus : --> id=85;datetime=2014-04-23 17:02:34;timestamp=1398250954 (6) [detail.krus] = ok (6) attr_filter.accounting_response : EXPAND %{User-Name} (6) attr_filter.accounting_response : --> voip.172.27.96.11 (6) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (6) [attr_filter.accounting_response] = updated (6) } # accounting = updated Sending Accounting-Response of id 85 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (6) Finished request 6. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=14, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (7) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (7) preacct { (7) [preprocess] = ok (7) acct_counters64.preacct acct_counters64.preacct { (7) update request { (7) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (7) --> 0 (7) Acct-Input-Octets64 = 0 (7) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (7) --> 0 (7) Acct-Output-Octets64 = 0 (7) } # update request = noop (7) } # acct_counters64.preacct acct_counters64.preacct = noop (7) update request { (7) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (7) --> 1398250954 (7) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (7) } # update request = noop (7) acct_unique acct_unique { (7) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (7) EXPAND %{string:Class} (7) --> (7) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (7) else else { (7) update request { (7) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (7) --> f5f5d59c2e7cc6c7f286d9f011502c28 (7) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (7) } # update request = noop (7) } # else else = noop (7) } # acct_unique acct_unique = noop (7) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (7) suffix : No such realm "NULL" (7) [suffix] = noop (7) } # preacct = ok (7) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (7) accounting { (7) [krus_python] = ok (7) if (fail) (7) if (fail) -> FALSE (7) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (7) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (7) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (7) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (7) detail.krus : --> id=14;datetime=2014-04-23 17:02:34;timestamp=1398250954 (7) [detail.krus] = ok (7) attr_filter.accounting_response : EXPAND %{User-Name} (7) attr_filter.accounting_response : --> voip.172.27.96.11 (7) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (7) [attr_filter.accounting_response] = updated (7) } # accounting = updated Sending Accounting-Response of id 14 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (7) Finished request 7. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=173, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (8) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (8) preacct { (8) [preprocess] = ok (8) acct_counters64.preacct acct_counters64.preacct { (8) update request { (8) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (8) --> 0 (8) Acct-Input-Octets64 = 0 (8) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (8) --> 0 (8) Acct-Output-Octets64 = 0 (8) } # update request = noop (8) } # acct_counters64.preacct acct_counters64.preacct = noop (8) update request { (8) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (8) --> 1398250954 (8) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (8) } # update request = noop (8) acct_unique acct_unique { (8) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (8) EXPAND %{string:Class} (8) --> (8) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (8) else else { (8) update request { (8) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (8) --> f5f5d59c2e7cc6c7f286d9f011502c28 (8) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (8) } # update request = noop (8) } # else else = noop (8) } # acct_unique acct_unique = noop (8) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (8) suffix : No such realm "NULL" (8) [suffix] = noop (8) } # preacct = ok (8) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (8) accounting { (8) [krus_python] = ok (8) if (fail) (8) if (fail) -> FALSE (8) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (8) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (8) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (8) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (8) detail.krus : --> id=173;datetime=2014-04-23 17:02:34;timestamp=1398250954 (8) [detail.krus] = ok (8) attr_filter.accounting_response : EXPAND %{User-Name} (8) attr_filter.accounting_response : --> voip.172.27.96.11 (8) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (8) [attr_filter.accounting_response] = updated (8) } # accounting = updated Sending Accounting-Response of id 173 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (8) Finished request 8. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=136, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (9) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (9) preacct { (9) [preprocess] = ok (9) acct_counters64.preacct acct_counters64.preacct { (9) update request { (9) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (9) --> 0 (9) Acct-Input-Octets64 = 0 (9) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (9) --> 0 (9) Acct-Output-Octets64 = 0 (9) } # update request = noop (9) } # acct_counters64.preacct acct_counters64.preacct = noop (9) update request { (9) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (9) --> 1398250954 (9) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (9) } # update request = noop (9) acct_unique acct_unique { (9) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (9) EXPAND %{string:Class} (9) --> (9) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (9) else else { (9) update request { (9) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (9) --> f5f5d59c2e7cc6c7f286d9f011502c28 (9) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (9) } # update request = noop (9) } # else else = noop (9) } # acct_unique acct_unique = noop (9) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (9) suffix : No such realm "NULL" (9) [suffix] = noop (9) } # preacct = ok (9) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (9) accounting { (9) [krus_python] = ok (9) if (fail) (9) if (fail) -> FALSE (9) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (9) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (9) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (9) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (9) detail.krus : --> id=136;datetime=2014-04-23 17:02:34;timestamp=1398250954 (9) [detail.krus] = ok (9) attr_filter.accounting_response : EXPAND %{User-Name} (9) attr_filter.accounting_response : --> voip.172.27.96.11 (9) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (9) [attr_filter.accounting_response] = updated (9) } # accounting = updated Sending Accounting-Response of id 136 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (9) Finished request 9. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=95, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (10) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (10) preacct { (10) [preprocess] = ok (10) acct_counters64.preacct acct_counters64.preacct { (10) update request { (10) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (10) --> 0 (10) Acct-Input-Octets64 = 0 (10) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (10) --> 0 (10) Acct-Output-Octets64 = 0 (10) } # update request = noop (10) } # acct_counters64.preacct acct_counters64.preacct = noop (10) update request { (10) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (10) --> 1398250954 (10) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (10) } # update request = noop (10) acct_unique acct_unique { (10) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (10) EXPAND %{string:Class} (10) --> (10) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (10) else else { (10) update request { (10) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (10) --> f5f5d59c2e7cc6c7f286d9f011502c28 (10) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (10) } # update request = noop (10) } # else else = noop (10) } # acct_unique acct_unique = noop (10) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (10) suffix : No such realm "NULL" (10) [suffix] = noop (10) } # preacct = ok (10) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (10) accounting { (10) [krus_python] = ok (10) if (fail) (10) if (fail) -> FALSE (10) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (10) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (10) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (10) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (10) detail.krus : --> id=95;datetime=2014-04-23 17:02:34;timestamp=1398250954 (10) [detail.krus] = ok (10) attr_filter.accounting_response : EXPAND %{User-Name} (10) attr_filter.accounting_response : --> voip.172.27.96.11 (10) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (10) [attr_filter.accounting_response] = updated (10) } # accounting = updated Sending Accounting-Response of id 95 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (10) Finished request 10. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=109, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (11) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (11) preacct { (11) [preprocess] = ok (11) acct_counters64.preacct acct_counters64.preacct { (11) update request { (11) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (11) --> 0 (11) Acct-Input-Octets64 = 0 (11) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (11) --> 0 (11) Acct-Output-Octets64 = 0 (11) } # update request = noop (11) } # acct_counters64.preacct acct_counters64.preacct = noop (11) update request { (11) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (11) --> 1398250954 (11) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (11) } # update request = noop (11) acct_unique acct_unique { (11) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (11) EXPAND %{string:Class} (11) --> (11) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (11) else else { (11) update request { (11) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (11) --> f5f5d59c2e7cc6c7f286d9f011502c28 (11) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (11) } # update request = noop (11) } # else else = noop (11) } # acct_unique acct_unique = noop (11) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (11) suffix : No such realm "NULL" (11) [suffix] = noop (11) } # preacct = ok (11) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (11) accounting { (11) [krus_python] = ok (11) if (fail) (11) if (fail) -> FALSE (11) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (11) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (11) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (11) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (11) detail.krus : --> id=109;datetime=2014-04-23 17:02:34;timestamp=1398250954 (11) [detail.krus] = ok (11) attr_filter.accounting_response : EXPAND %{User-Name} (11) attr_filter.accounting_response : --> voip.172.27.96.11 (11) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (11) [attr_filter.accounting_response] = updated (11) } # accounting = updated Sending Accounting-Response of id 109 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (11) Finished request 11. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=78, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (12) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (12) preacct { (12) [preprocess] = ok (12) acct_counters64.preacct acct_counters64.preacct { (12) update request { (12) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (12) --> 0 (12) Acct-Input-Octets64 = 0 (12) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (12) --> 0 (12) Acct-Output-Octets64 = 0 (12) } # update request = noop (12) } # acct_counters64.preacct acct_counters64.preacct = noop (12) update request { (12) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (12) --> 1398250954 (12) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (12) } # update request = noop (12) acct_unique acct_unique { (12) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (12) EXPAND %{string:Class} (12) --> (12) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (12) else else { (12) update request { (12) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (12) --> f5f5d59c2e7cc6c7f286d9f011502c28 (12) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (12) } # update request = noop (12) } # else else = noop (12) } # acct_unique acct_unique = noop (12) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (12) suffix : No such realm "NULL" (12) [suffix] = noop (12) } # preacct = ok (12) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (12) accounting { (12) [krus_python] = ok (12) if (fail) (12) if (fail) -> FALSE (12) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (12) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (12) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (12) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (12) detail.krus : --> id=78;datetime=2014-04-23 17:02:34;timestamp=1398250954 (12) [detail.krus] = ok (12) attr_filter.accounting_response : EXPAND %{User-Name} (12) attr_filter.accounting_response : --> voip.172.27.96.11 (12) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (12) [attr_filter.accounting_response] = updated (12) } # accounting = updated Sending Accounting-Response of id 78 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (12) Finished request 12. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=22, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (13) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (13) preacct { (13) [preprocess] = ok (13) acct_counters64.preacct acct_counters64.preacct { (13) update request { (13) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (13) --> 0 (13) Acct-Input-Octets64 = 0 (13) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (13) --> 0 (13) Acct-Output-Octets64 = 0 (13) } # update request = noop (13) } # acct_counters64.preacct acct_counters64.preacct = noop (13) update request { (13) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (13) --> 1398250954 (13) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (13) } # update request = noop (13) acct_unique acct_unique { (13) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (13) EXPAND %{string:Class} (13) --> (13) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (13) else else { (13) update request { (13) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (13) --> f5f5d59c2e7cc6c7f286d9f011502c28 (13) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (13) } # update request = noop (13) } # else else = noop (13) } # acct_unique acct_unique = noop (13) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (13) suffix : No such realm "NULL" (13) [suffix] = noop (13) } # preacct = ok (13) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (13) accounting { (13) [krus_python] = ok (13) if (fail) (13) if (fail) -> FALSE (13) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (13) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (13) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (13) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (13) detail.krus : --> id=22;datetime=2014-04-23 17:02:34;timestamp=1398250954 (13) [detail.krus] = ok (13) attr_filter.accounting_response : EXPAND %{User-Name} (13) attr_filter.accounting_response : --> voip.172.27.96.11 (13) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (13) [attr_filter.accounting_response] = updated (13) } # accounting = updated Sending Accounting-Response of id 22 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (13) Finished request 13. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=243, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (14) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (14) preacct { (14) [preprocess] = ok (14) acct_counters64.preacct acct_counters64.preacct { (14) update request { (14) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (14) --> 0 (14) Acct-Input-Octets64 = 0 (14) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (14) --> 0 (14) Acct-Output-Octets64 = 0 (14) } # update request = noop (14) } # acct_counters64.preacct acct_counters64.preacct = noop (14) update request { (14) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (14) --> 1398250954 (14) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (14) } # update request = noop (14) acct_unique acct_unique { (14) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (14) EXPAND %{string:Class} (14) --> (14) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (14) else else { (14) update request { (14) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (14) --> f5f5d59c2e7cc6c7f286d9f011502c28 (14) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (14) } # update request = noop (14) } # else else = noop (14) } # acct_unique acct_unique = noop (14) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (14) suffix : No such realm "NULL" (14) [suffix] = noop (14) } # preacct = ok (14) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (14) accounting { (14) [krus_python] = ok (14) if (fail) (14) if (fail) -> FALSE (14) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (14) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (14) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (14) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (14) detail.krus : --> id=243;datetime=2014-04-23 17:02:34;timestamp=1398250954 (14) [detail.krus] = ok (14) attr_filter.accounting_response : EXPAND %{User-Name} (14) attr_filter.accounting_response : --> voip.172.27.96.11 (14) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (14) [attr_filter.accounting_response] = updated (14) } # accounting = updated Sending Accounting-Response of id 243 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (14) Finished request 14. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=119, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (15) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (15) preacct { (15) [preprocess] = ok (15) acct_counters64.preacct acct_counters64.preacct { (15) update request { (15) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (15) --> 0 (15) Acct-Input-Octets64 = 0 (15) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (15) --> 0 (15) Acct-Output-Octets64 = 0 (15) } # update request = noop (15) } # acct_counters64.preacct acct_counters64.preacct = noop (15) update request { (15) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (15) --> 1398250954 (15) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (15) } # update request = noop (15) acct_unique acct_unique { (15) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (15) EXPAND %{string:Class} (15) --> (15) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (15) else else { (15) update request { (15) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (15) --> f5f5d59c2e7cc6c7f286d9f011502c28 (15) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (15) } # update request = noop (15) } # else else = noop (15) } # acct_unique acct_unique = noop (15) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (15) suffix : No such realm "NULL" (15) [suffix] = noop (15) } # preacct = ok (15) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (15) accounting { (15) [krus_python] = ok (15) if (fail) (15) if (fail) -> FALSE (15) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (15) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (15) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (15) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (15) detail.krus : --> id=119;datetime=2014-04-23 17:02:34;timestamp=1398250954 (15) [detail.krus] = ok (15) attr_filter.accounting_response : EXPAND %{User-Name} (15) attr_filter.accounting_response : --> voip.172.27.96.11 (15) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (15) [attr_filter.accounting_response] = updated (15) } # accounting = updated Sending Accounting-Response of id 119 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (15) Finished request 15. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=196, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (16) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (16) preacct { (16) [preprocess] = ok (16) acct_counters64.preacct acct_counters64.preacct { (16) update request { (16) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (16) --> 0 (16) Acct-Input-Octets64 = 0 (16) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (16) --> 0 (16) Acct-Output-Octets64 = 0 (16) } # update request = noop (16) } # acct_counters64.preacct acct_counters64.preacct = noop (16) update request { (16) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (16) --> 1398250954 (16) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (16) } # update request = noop (16) acct_unique acct_unique { (16) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (16) EXPAND %{string:Class} (16) --> (16) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (16) else else { (16) update request { (16) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (16) --> f5f5d59c2e7cc6c7f286d9f011502c28 (16) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (16) } # update request = noop (16) } # else else = noop (16) } # acct_unique acct_unique = noop (16) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (16) suffix : No such realm "NULL" (16) [suffix] = noop (16) } # preacct = ok (16) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (16) accounting { (16) [krus_python] = ok (16) if (fail) (16) if (fail) -> FALSE (16) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (16) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (16) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (16) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (16) detail.krus : --> id=196;datetime=2014-04-23 17:02:34;timestamp=1398250954 (16) [detail.krus] = ok (16) attr_filter.accounting_response : EXPAND %{User-Name} (16) attr_filter.accounting_response : --> voip.172.27.96.11 (16) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (16) [attr_filter.accounting_response] = updated (16) } # accounting = updated Sending Accounting-Response of id 196 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (16) Finished request 16. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=137, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (17) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (17) preacct { (17) [preprocess] = ok (17) acct_counters64.preacct acct_counters64.preacct { (17) update request { (17) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (17) --> 0 (17) Acct-Input-Octets64 = 0 (17) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (17) --> 0 (17) Acct-Output-Octets64 = 0 (17) } # update request = noop (17) } # acct_counters64.preacct acct_counters64.preacct = noop (17) update request { (17) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (17) --> 1398250954 (17) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (17) } # update request = noop (17) acct_unique acct_unique { (17) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (17) EXPAND %{string:Class} (17) --> (17) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (17) else else { (17) update request { (17) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (17) --> f5f5d59c2e7cc6c7f286d9f011502c28 (17) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (17) } # update request = noop (17) } # else else = noop (17) } # acct_unique acct_unique = noop (17) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (17) suffix : No such realm "NULL" (17) [suffix] = noop (17) } # preacct = ok (17) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (17) accounting { (17) [krus_python] = ok (17) if (fail) (17) if (fail) -> FALSE (17) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (17) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (17) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (17) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (17) detail.krus : --> id=137;datetime=2014-04-23 17:02:34;timestamp=1398250954 (17) [detail.krus] = ok (17) attr_filter.accounting_response : EXPAND %{User-Name} (17) attr_filter.accounting_response : --> voip.172.27.96.11 (17) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (17) [attr_filter.accounting_response] = updated (17) } # accounting = updated Sending Accounting-Response of id 137 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (17) Finished request 17. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=231, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (18) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (18) preacct { (18) [preprocess] = ok (18) acct_counters64.preacct acct_counters64.preacct { (18) update request { (18) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (18) --> 0 (18) Acct-Input-Octets64 = 0 (18) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (18) --> 0 (18) Acct-Output-Octets64 = 0 (18) } # update request = noop (18) } # acct_counters64.preacct acct_counters64.preacct = noop (18) update request { (18) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (18) --> 1398250954 (18) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (18) } # update request = noop (18) acct_unique acct_unique { (18) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (18) EXPAND %{string:Class} (18) --> (18) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (18) else else { (18) update request { (18) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (18) --> f5f5d59c2e7cc6c7f286d9f011502c28 (18) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (18) } # update request = noop (18) } # else else = noop (18) } # acct_unique acct_unique = noop (18) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (18) suffix : No such realm "NULL" (18) [suffix] = noop (18) } # preacct = ok (18) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (18) accounting { (18) [krus_python] = ok (18) if (fail) (18) if (fail) -> FALSE (18) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (18) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (18) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (18) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (18) detail.krus : --> id=231;datetime=2014-04-23 17:02:34;timestamp=1398250954 (18) [detail.krus] = ok (18) attr_filter.accounting_response : EXPAND %{User-Name} (18) attr_filter.accounting_response : --> voip.172.27.96.11 (18) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (18) [attr_filter.accounting_response] = updated (18) } # accounting = updated Sending Accounting-Response of id 231 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (18) Finished request 18. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=201, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (19) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (19) preacct { (19) [preprocess] = ok (19) acct_counters64.preacct acct_counters64.preacct { (19) update request { (19) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (19) --> 0 (19) Acct-Input-Octets64 = 0 (19) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (19) --> 0 (19) Acct-Output-Octets64 = 0 (19) } # update request = noop (19) } # acct_counters64.preacct acct_counters64.preacct = noop (19) update request { (19) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (19) --> 1398250954 (19) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (19) } # update request = noop (19) acct_unique acct_unique { (19) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (19) EXPAND %{string:Class} (19) --> (19) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (19) else else { (19) update request { (19) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (19) --> f5f5d59c2e7cc6c7f286d9f011502c28 (19) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (19) } # update request = noop (19) } # else else = noop (19) } # acct_unique acct_unique = noop (19) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (19) suffix : No such realm "NULL" (19) [suffix] = noop (19) } # preacct = ok (19) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (19) accounting { (19) [krus_python] = ok (19) if (fail) (19) if (fail) -> FALSE (19) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (19) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (19) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (19) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (19) detail.krus : --> id=201;datetime=2014-04-23 17:02:34;timestamp=1398250954 (19) [detail.krus] = ok (19) attr_filter.accounting_response : EXPAND %{User-Name} (19) attr_filter.accounting_response : --> voip.172.27.96.11 (19) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (19) [attr_filter.accounting_response] = updated (19) } # accounting = updated Sending Accounting-Response of id 201 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (19) Finished request 19. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=255, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (20) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (20) preacct { (20) [preprocess] = ok (20) acct_counters64.preacct acct_counters64.preacct { (20) update request { (20) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (20) --> 0 (20) Acct-Input-Octets64 = 0 (20) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (20) --> 0 (20) Acct-Output-Octets64 = 0 (20) } # update request = noop (20) } # acct_counters64.preacct acct_counters64.preacct = noop (20) update request { (20) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (20) --> 1398250954 (20) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (20) } # update request = noop (20) acct_unique acct_unique { (20) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (20) EXPAND %{string:Class} (20) --> (20) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (20) else else { (20) update request { (20) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (20) --> f5f5d59c2e7cc6c7f286d9f011502c28 (20) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (20) } # update request = noop (20) } # else else = noop (20) } # acct_unique acct_unique = noop (20) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (20) suffix : No such realm "NULL" (20) [suffix] = noop (20) } # preacct = ok (20) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (20) accounting { (20) [krus_python] = ok (20) if (fail) (20) if (fail) -> FALSE (20) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (20) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (20) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (20) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (20) detail.krus : --> id=255;datetime=2014-04-23 17:02:34;timestamp=1398250954 (20) [detail.krus] = ok (20) attr_filter.accounting_response : EXPAND %{User-Name} (20) attr_filter.accounting_response : --> voip.172.27.96.11 (20) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (20) [attr_filter.accounting_response] = updated (20) } # accounting = updated Sending Accounting-Response of id 255 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (20) Finished request 20. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=252, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (21) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (21) preacct { (21) [preprocess] = ok (21) acct_counters64.preacct acct_counters64.preacct { (21) update request { (21) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (21) --> 0 (21) Acct-Input-Octets64 = 0 (21) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (21) --> 0 (21) Acct-Output-Octets64 = 0 (21) } # update request = noop (21) } # acct_counters64.preacct acct_counters64.preacct = noop (21) update request { (21) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (21) --> 1398250954 (21) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (21) } # update request = noop (21) acct_unique acct_unique { (21) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (21) EXPAND %{string:Class} (21) --> (21) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (21) else else { (21) update request { (21) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (21) --> f5f5d59c2e7cc6c7f286d9f011502c28 (21) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (21) } # update request = noop (21) } # else else = noop (21) } # acct_unique acct_unique = noop (21) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (21) suffix : No such realm "NULL" (21) [suffix] = noop (21) } # preacct = ok (21) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (21) accounting { (21) [krus_python] = ok (21) if (fail) (21) if (fail) -> FALSE (21) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (21) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (21) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (21) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (21) detail.krus : --> id=252;datetime=2014-04-23 17:02:34;timestamp=1398250954 (21) [detail.krus] = ok (21) attr_filter.accounting_response : EXPAND %{User-Name} (21) attr_filter.accounting_response : --> voip.172.27.96.11 (21) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (21) [attr_filter.accounting_response] = updated (21) } # accounting = updated Sending Accounting-Response of id 252 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (21) Finished request 21. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=197, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (22) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (22) preacct { (22) [preprocess] = ok (22) acct_counters64.preacct acct_counters64.preacct { (22) update request { (22) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (22) --> 0 (22) Acct-Input-Octets64 = 0 (22) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (22) --> 0 (22) Acct-Output-Octets64 = 0 (22) } # update request = noop (22) } # acct_counters64.preacct acct_counters64.preacct = noop (22) update request { (22) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (22) --> 1398250954 (22) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (22) } # update request = noop (22) acct_unique acct_unique { (22) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (22) EXPAND %{string:Class} (22) --> (22) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (22) else else { (22) update request { (22) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (22) --> f5f5d59c2e7cc6c7f286d9f011502c28 (22) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (22) } # update request = noop (22) } # else else = noop (22) } # acct_unique acct_unique = noop (22) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (22) suffix : No such realm "NULL" (22) [suffix] = noop (22) } # preacct = ok (22) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (22) accounting { (22) [krus_python] = ok (22) if (fail) (22) if (fail) -> FALSE (22) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (22) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (22) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (22) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (22) detail.krus : --> id=197;datetime=2014-04-23 17:02:34;timestamp=1398250954 (22) [detail.krus] = ok (22) attr_filter.accounting_response : EXPAND %{User-Name} (22) attr_filter.accounting_response : --> voip.172.27.96.11 (22) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (22) [attr_filter.accounting_response] = updated (22) } # accounting = updated Sending Accounting-Response of id 197 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (22) Finished request 22. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=69, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (23) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (23) preacct { (23) [preprocess] = ok (23) acct_counters64.preacct acct_counters64.preacct { (23) update request { (23) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (23) --> 0 (23) Acct-Input-Octets64 = 0 (23) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (23) --> 0 (23) Acct-Output-Octets64 = 0 (23) } # update request = noop (23) } # acct_counters64.preacct acct_counters64.preacct = noop (23) update request { (23) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (23) --> 1398250954 (23) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (23) } # update request = noop (23) acct_unique acct_unique { (23) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (23) EXPAND %{string:Class} (23) --> (23) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (23) else else { (23) update request { (23) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (23) --> f5f5d59c2e7cc6c7f286d9f011502c28 (23) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (23) } # update request = noop (23) } # else else = noop (23) } # acct_unique acct_unique = noop (23) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (23) suffix : No such realm "NULL" (23) [suffix] = noop (23) } # preacct = ok (23) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (23) accounting { (23) [krus_python] = ok (23) if (fail) (23) if (fail) -> FALSE (23) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (23) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (23) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (23) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (23) detail.krus : --> id=69;datetime=2014-04-23 17:02:34;timestamp=1398250954 (23) [detail.krus] = ok (23) attr_filter.accounting_response : EXPAND %{User-Name} (23) attr_filter.accounting_response : --> voip.172.27.96.11 (23) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (23) [attr_filter.accounting_response] = updated (23) } # accounting = updated Sending Accounting-Response of id 69 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (23) Finished request 23. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=226, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (24) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (24) preacct { (24) [preprocess] = ok (24) acct_counters64.preacct acct_counters64.preacct { (24) update request { (24) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (24) --> 0 (24) Acct-Input-Octets64 = 0 (24) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (24) --> 0 (24) Acct-Output-Octets64 = 0 (24) } # update request = noop (24) } # acct_counters64.preacct acct_counters64.preacct = noop (24) update request { (24) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (24) --> 1398250954 (24) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (24) } # update request = noop (24) acct_unique acct_unique { (24) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (24) EXPAND %{string:Class} (24) --> (24) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (24) else else { (24) update request { (24) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (24) --> f5f5d59c2e7cc6c7f286d9f011502c28 (24) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (24) } # update request = noop (24) } # else else = noop (24) } # acct_unique acct_unique = noop (24) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (24) suffix : No such realm "NULL" (24) [suffix] = noop (24) } # preacct = ok (24) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (24) accounting { (24) [krus_python] = ok (24) if (fail) (24) if (fail) -> FALSE (24) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (24) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (24) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (24) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (24) detail.krus : --> id=226;datetime=2014-04-23 17:02:34;timestamp=1398250954 (24) [detail.krus] = ok (24) attr_filter.accounting_response : EXPAND %{User-Name} (24) attr_filter.accounting_response : --> voip.172.27.96.11 (24) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (24) [attr_filter.accounting_response] = updated (24) } # accounting = updated Sending Accounting-Response of id 226 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (24) Finished request 24. (0) Cleaning up request packet ID 162 with timestamp +2 rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=106, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (25) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (25) preacct { (25) [preprocess] = ok (25) acct_counters64.preacct acct_counters64.preacct { (25) update request { (25) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (25) --> 0 (25) Acct-Input-Octets64 = 0 (25) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (25) --> 0 (25) Acct-Output-Octets64 = 0 (25) } # update request = noop (25) } # acct_counters64.preacct acct_counters64.preacct = noop (25) update request { (25) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (25) --> 1398250954 (25) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (25) } # update request = noop (25) acct_unique acct_unique { (25) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (25) EXPAND %{string:Class} (25) --> (25) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (25) else else { (25) update request { (25) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (25) --> f5f5d59c2e7cc6c7f286d9f011502c28 (25) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (25) } # update request = noop (25) } # else else = noop (25) } # acct_unique acct_unique = noop (25) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (25) suffix : No such realm "NULL" (25) [suffix] = noop (25) } # preacct = ok (25) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (25) accounting { (25) [krus_python] = ok (25) if (fail) (25) if (fail) -> FALSE (25) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (25) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (25) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (25) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (25) detail.krus : --> id=106;datetime=2014-04-23 17:02:34;timestamp=1398250954 (25) [detail.krus] = ok (25) attr_filter.accounting_response : EXPAND %{User-Name} (25) attr_filter.accounting_response : --> voip.172.27.96.11 (25) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (25) [attr_filter.accounting_response] = updated (25) } # accounting = updated Sending Accounting-Response of id 106 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (25) Finished request 25. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=56, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (26) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (26) preacct { (26) [preprocess] = ok (26) acct_counters64.preacct acct_counters64.preacct { (26) update request { (26) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (26) --> 0 (26) Acct-Input-Octets64 = 0 (26) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (26) --> 0 (26) Acct-Output-Octets64 = 0 (26) } # update request = noop (26) } # acct_counters64.preacct acct_counters64.preacct = noop (26) update request { (26) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (26) --> 1398250954 (26) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (26) } # update request = noop (26) acct_unique acct_unique { (26) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (26) EXPAND %{string:Class} (26) --> (26) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (26) else else { (26) update request { (26) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (26) --> f5f5d59c2e7cc6c7f286d9f011502c28 (26) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (26) } # update request = noop (26) } # else else = noop (26) } # acct_unique acct_unique = noop (26) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (26) suffix : No such realm "NULL" (26) [suffix] = noop (26) } # preacct = ok (26) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (26) accounting { (26) [krus_python] = ok (26) if (fail) (26) if (fail) -> FALSE (26) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (26) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (26) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (26) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (26) detail.krus : --> id=56;datetime=2014-04-23 17:02:34;timestamp=1398250954 (26) [detail.krus] = ok (26) attr_filter.accounting_response : EXPAND %{User-Name} (26) attr_filter.accounting_response : --> voip.172.27.96.11 (26) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (26) [attr_filter.accounting_response] = updated (26) } # accounting = updated Sending Accounting-Response of id 56 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (26) Finished request 26. (1) Cleaning up request packet ID 10 with timestamp +2 rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=97, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (27) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (27) preacct { (27) [preprocess] = ok (27) acct_counters64.preacct acct_counters64.preacct { (27) update request { (27) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (27) --> 0 (27) Acct-Input-Octets64 = 0 (27) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (27) --> 0 (27) Acct-Output-Octets64 = 0 (27) } # update request = noop (27) } # acct_counters64.preacct acct_counters64.preacct = noop (27) update request { (27) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (27) --> 1398250954 (27) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:34 YEKT" (27) } # update request = noop (27) acct_unique acct_unique { (27) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (27) EXPAND %{string:Class} (27) --> (27) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (27) else else { (27) update request { (27) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (27) --> f5f5d59c2e7cc6c7f286d9f011502c28 (27) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (27) } # update request = noop (27) } # else else = noop (27) } # acct_unique acct_unique = noop (27) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (27) suffix : No such realm "NULL" (27) [suffix] = noop (27) } # preacct = ok (27) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (27) accounting { (27) [krus_python] = ok (27) if (fail) (27) if (fail) -> FALSE (27) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (27) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (27) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (27) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (27) detail.krus : --> id=97;datetime=2014-04-23 17:02:34;timestamp=1398250954 (27) [detail.krus] = ok (27) attr_filter.accounting_response : EXPAND %{User-Name} (27) attr_filter.accounting_response : --> voip.172.27.96.11 (27) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (27) [attr_filter.accounting_response] = updated (27) } # accounting = updated Sending Accounting-Response of id 97 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (27) Finished request 27. (2) Cleaning up request packet ID 222 with timestamp +2 rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=243, length=709 (14) Discarding duplicate request from client localhost port 50716 - ID: 243 due to unfinished request (3) Cleaning up request packet ID 239 with timestamp +2 (4) Cleaning up request packet ID 31 with timestamp +2 (5) Cleaning up request packet ID 207 with timestamp +2 (6) Cleaning up request packet ID 85 with timestamp +2 (7) Cleaning up request packet ID 14 with timestamp +2 (8) Cleaning up request packet ID 173 with timestamp +2 (9) Cleaning up request packet ID 136 with timestamp +2 (10) Cleaning up request packet ID 95 with timestamp +2 (11) Cleaning up request packet ID 109 with timestamp +2 (12) Cleaning up request packet ID 78 with timestamp +2 (13) Cleaning up request packet ID 22 with timestamp +2 (14) Cleaning up request packet ID 243 with timestamp +2 (15) Cleaning up request packet ID 119 with timestamp +2 (16) Cleaning up request packet ID 196 with timestamp +2 (17) Cleaning up request packet ID 137 with timestamp +2 (18) Cleaning up request packet ID 231 with timestamp +2 (19) Cleaning up request packet ID 201 with timestamp +2 (20) Cleaning up request packet ID 255 with timestamp +2 (21) Cleaning up request packet ID 252 with timestamp +2 (22) Cleaning up request packet ID 197 with timestamp +2 (23) Cleaning up request packet ID 69 with timestamp +2 (24) Cleaning up request packet ID 226 with timestamp +2 (25) Cleaning up request packet ID 106 with timestamp +2 (26) Cleaning up request packet ID 56 with timestamp +2 (27) Cleaning up request packet ID 97 with timestamp +2 Ready to process requests. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=243, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (28) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (28) preacct { (28) [preprocess] = ok (28) acct_counters64.preacct acct_counters64.preacct { (28) update request { (28) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (28) --> 0 (28) Acct-Input-Octets64 = 0 (28) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (28) --> 0 (28) Acct-Output-Octets64 = 0 (28) } # update request = noop (28) } # acct_counters64.preacct acct_counters64.preacct = noop (28) update request { (28) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (28) --> 1398250959 (28) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:39 YEKT" (28) } # update request = noop (28) acct_unique acct_unique { (28) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (28) EXPAND %{string:Class} (28) --> (28) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (28) else else { (28) update request { (28) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (28) --> f5f5d59c2e7cc6c7f286d9f011502c28 (28) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (28) } # update request = noop (28) } # else else = noop (28) } # acct_unique acct_unique = noop (28) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (28) suffix : No such realm "NULL" (28) [suffix] = noop (28) } # preacct = ok (28) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (28) accounting { (28) [krus_python] = ok (28) if (fail) (28) if (fail) -> FALSE (28) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (28) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (28) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (28) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (28) detail.krus : --> id=243;datetime=2014-04-23 17:02:39;timestamp=1398250959 (28) [detail.krus] = ok (28) attr_filter.accounting_response : EXPAND %{User-Name} (28) attr_filter.accounting_response : --> voip.172.27.96.11 (28) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (28) [attr_filter.accounting_response] = updated (28) } # accounting = updated Sending Accounting-Response of id 243 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (28) Finished request 28. Waking up in 0.3 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=147, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (29) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (29) preacct { (29) [preprocess] = ok (29) acct_counters64.preacct acct_counters64.preacct { (29) update request { (29) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (29) --> 0 (29) Acct-Input-Octets64 = 0 (29) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (29) --> 0 (29) Acct-Output-Octets64 = 0 (29) } # update request = noop (29) } # acct_counters64.preacct acct_counters64.preacct = noop (29) update request { (29) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (29) --> 1398250959 (29) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:39 YEKT" (29) } # update request = noop (29) acct_unique acct_unique { (29) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (29) EXPAND %{string:Class} (29) --> (29) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (29) else else { (29) update request { (29) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (29) --> f5f5d59c2e7cc6c7f286d9f011502c28 (29) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (29) } # update request = noop (29) } # else else = noop (29) } # acct_unique acct_unique = noop (29) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (29) suffix : No such realm "NULL" (29) [suffix] = noop (29) } # preacct = ok (29) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (29) accounting { (29) [krus_python] = ok (29) if (fail) (29) if (fail) -> FALSE (29) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (29) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (29) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (29) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (29) detail.krus : --> id=147;datetime=2014-04-23 17:02:39;timestamp=1398250959 (29) [detail.krus] = ok (29) attr_filter.accounting_response : EXPAND %{User-Name} (29) attr_filter.accounting_response : --> voip.172.27.96.11 (29) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (29) [attr_filter.accounting_response] = updated (29) } # accounting = updated Sending Accounting-Response of id 147 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (29) Finished request 29. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=85, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (30) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (30) preacct { (30) [preprocess] = ok (30) acct_counters64.preacct acct_counters64.preacct { (30) update request { (30) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (30) --> 0 (30) Acct-Input-Octets64 = 0 (30) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (30) --> 0 (30) Acct-Output-Octets64 = 0 (30) } # update request = noop (30) } # acct_counters64.preacct acct_counters64.preacct = noop (30) update request { (30) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (30) --> 1398250960 (30) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (30) } # update request = noop (30) acct_unique acct_unique { (30) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (30) EXPAND %{string:Class} (30) --> (30) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (30) else else { (30) update request { (30) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (30) --> f5f5d59c2e7cc6c7f286d9f011502c28 (30) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (30) } # update request = noop (30) } # else else = noop (30) } # acct_unique acct_unique = noop (30) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (30) suffix : No such realm "NULL" (30) [suffix] = noop (30) } # preacct = ok (30) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (30) accounting { (30) [krus_python] = ok (30) if (fail) (30) if (fail) -> FALSE (30) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (30) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (30) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (30) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (30) detail.krus : --> id=85;datetime=2014-04-23 17:02:40;timestamp=1398250960 (30) [detail.krus] = ok (30) attr_filter.accounting_response : EXPAND %{User-Name} (30) attr_filter.accounting_response : --> voip.172.27.96.11 (30) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (30) [attr_filter.accounting_response] = updated (30) } # accounting = updated Sending Accounting-Response of id 85 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (30) Finished request 30. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=252, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (31) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (31) preacct { (31) [preprocess] = ok (31) acct_counters64.preacct acct_counters64.preacct { (31) update request { (31) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (31) --> 0 (31) Acct-Input-Octets64 = 0 (31) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (31) --> 0 (31) Acct-Output-Octets64 = 0 (31) } # update request = noop (31) } # acct_counters64.preacct acct_counters64.preacct = noop (31) update request { (31) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (31) --> 1398250960 (31) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (31) } # update request = noop (31) acct_unique acct_unique { (31) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (31) EXPAND %{string:Class} (31) --> (31) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (31) else else { (31) update request { (31) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (31) --> f5f5d59c2e7cc6c7f286d9f011502c28 (31) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (31) } # update request = noop (31) } # else else = noop (31) } # acct_unique acct_unique = noop (31) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (31) suffix : No such realm "NULL" (31) [suffix] = noop (31) } # preacct = ok (31) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (31) accounting { (31) [krus_python] = ok (31) if (fail) (31) if (fail) -> FALSE (31) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (31) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (31) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (31) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (31) detail.krus : --> id=252;datetime=2014-04-23 17:02:40;timestamp=1398250960 (31) [detail.krus] = ok (31) attr_filter.accounting_response : EXPAND %{User-Name} (31) attr_filter.accounting_response : --> voip.172.27.96.11 (31) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (31) [attr_filter.accounting_response] = updated (31) } # accounting = updated Sending Accounting-Response of id 252 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (31) Finished request 31. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=217, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (32) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (32) preacct { (32) [preprocess] = ok (32) acct_counters64.preacct acct_counters64.preacct { (32) update request { (32) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (32) --> 0 (32) Acct-Input-Octets64 = 0 (32) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (32) --> 0 (32) Acct-Output-Octets64 = 0 (32) } # update request = noop (32) } # acct_counters64.preacct acct_counters64.preacct = noop (32) update request { (32) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (32) --> 1398250960 (32) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (32) } # update request = noop (32) acct_unique acct_unique { (32) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (32) EXPAND %{string:Class} (32) --> (32) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (32) else else { (32) update request { (32) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (32) --> f5f5d59c2e7cc6c7f286d9f011502c28 (32) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (32) } # update request = noop (32) } # else else = noop (32) } # acct_unique acct_unique = noop (32) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (32) suffix : No such realm "NULL" (32) [suffix] = noop (32) } # preacct = ok (32) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (32) accounting { (32) [krus_python] = ok (32) if (fail) (32) if (fail) -> FALSE (32) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (32) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (32) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (32) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (32) detail.krus : --> id=217;datetime=2014-04-23 17:02:40;timestamp=1398250960 (32) [detail.krus] = ok (32) attr_filter.accounting_response : EXPAND %{User-Name} (32) attr_filter.accounting_response : --> voip.172.27.96.11 (32) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (32) [attr_filter.accounting_response] = updated (32) } # accounting = updated Sending Accounting-Response of id 217 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (32) Finished request 32. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=205, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (33) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (33) preacct { (33) [preprocess] = ok (33) acct_counters64.preacct acct_counters64.preacct { (33) update request { (33) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (33) --> 0 (33) Acct-Input-Octets64 = 0 (33) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (33) --> 0 (33) Acct-Output-Octets64 = 0 (33) } # update request = noop (33) } # acct_counters64.preacct acct_counters64.preacct = noop (33) update request { (33) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (33) --> 1398250960 (33) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (33) } # update request = noop (33) acct_unique acct_unique { (33) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (33) EXPAND %{string:Class} (33) --> (33) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (33) else else { (33) update request { (33) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (33) --> f5f5d59c2e7cc6c7f286d9f011502c28 (33) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (33) } # update request = noop (33) } # else else = noop (33) } # acct_unique acct_unique = noop (33) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (33) suffix : No such realm "NULL" (33) [suffix] = noop (33) } # preacct = ok (33) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (33) accounting { (33) [krus_python] = ok (33) if (fail) (33) if (fail) -> FALSE (33) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (33) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (33) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (33) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (33) detail.krus : --> id=205;datetime=2014-04-23 17:02:40;timestamp=1398250960 (33) [detail.krus] = ok (33) attr_filter.accounting_response : EXPAND %{User-Name} (33) attr_filter.accounting_response : --> voip.172.27.96.11 (33) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (33) [attr_filter.accounting_response] = updated (33) } # accounting = updated Sending Accounting-Response of id 205 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (33) Finished request 33. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=207, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (34) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (34) preacct { (34) [preprocess] = ok (34) acct_counters64.preacct acct_counters64.preacct { (34) update request { (34) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (34) --> 0 (34) Acct-Input-Octets64 = 0 (34) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (34) --> 0 (34) Acct-Output-Octets64 = 0 (34) } # update request = noop (34) } # acct_counters64.preacct acct_counters64.preacct = noop (34) update request { (34) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (34) --> 1398250960 (34) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (34) } # update request = noop (34) acct_unique acct_unique { (34) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (34) EXPAND %{string:Class} (34) --> (34) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (34) else else { (34) update request { (34) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (34) --> f5f5d59c2e7cc6c7f286d9f011502c28 (34) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (34) } # update request = noop (34) } # else else = noop (34) } # acct_unique acct_unique = noop (34) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (34) suffix : No such realm "NULL" (34) [suffix] = noop (34) } # preacct = ok (34) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (34) accounting { (34) [krus_python] = ok (34) if (fail) (34) if (fail) -> FALSE (34) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (34) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (34) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (34) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (34) detail.krus : --> id=207;datetime=2014-04-23 17:02:40;timestamp=1398250960 (34) [detail.krus] = ok (34) attr_filter.accounting_response : EXPAND %{User-Name} (34) attr_filter.accounting_response : --> voip.172.27.96.11 (34) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (34) [attr_filter.accounting_response] = updated (34) } # accounting = updated Sending Accounting-Response of id 207 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (34) Finished request 34. Waking up in 0.2 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=127, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (35) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (35) preacct { (35) [preprocess] = ok (35) acct_counters64.preacct acct_counters64.preacct { (35) update request { (35) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (35) --> 0 (35) Acct-Input-Octets64 = 0 (35) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (35) --> 0 (35) Acct-Output-Octets64 = 0 (35) } # update request = noop (35) } # acct_counters64.preacct acct_counters64.preacct = noop (35) update request { (35) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (35) --> 1398250960 (35) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (35) } # update request = noop (35) acct_unique acct_unique { (35) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (35) EXPAND %{string:Class} (35) --> (35) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (35) else else { (35) update request { (35) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (35) --> f5f5d59c2e7cc6c7f286d9f011502c28 (35) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (35) } # update request = noop (35) } # else else = noop (35) } # acct_unique acct_unique = noop (35) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (35) suffix : No such realm "NULL" (35) [suffix] = noop (35) } # preacct = ok (35) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (35) accounting { (35) [krus_python] = ok (35) if (fail) (35) if (fail) -> FALSE (35) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (35) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (35) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (35) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (35) detail.krus : --> id=127;datetime=2014-04-23 17:02:40;timestamp=1398250960 (35) [detail.krus] = ok (35) attr_filter.accounting_response : EXPAND %{User-Name} (35) attr_filter.accounting_response : --> voip.172.27.96.11 (35) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (35) [attr_filter.accounting_response] = updated (35) } # accounting = updated Sending Accounting-Response of id 127 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (35) Finished request 35. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=116, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (36) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (36) preacct { (36) [preprocess] = ok (36) acct_counters64.preacct acct_counters64.preacct { (36) update request { (36) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (36) --> 0 (36) Acct-Input-Octets64 = 0 (36) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (36) --> 0 (36) Acct-Output-Octets64 = 0 (36) } # update request = noop (36) } # acct_counters64.preacct acct_counters64.preacct = noop (36) update request { (36) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (36) --> 1398250960 (36) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (36) } # update request = noop (36) acct_unique acct_unique { (36) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (36) EXPAND %{string:Class} (36) --> (36) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (36) else else { (36) update request { (36) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (36) --> f5f5d59c2e7cc6c7f286d9f011502c28 (36) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (36) } # update request = noop (36) } # else else = noop (36) } # acct_unique acct_unique = noop (36) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (36) suffix : No such realm "NULL" (36) [suffix] = noop (36) } # preacct = ok (36) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (36) accounting { (36) [krus_python] = ok (36) if (fail) (36) if (fail) -> FALSE (36) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (36) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (36) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (36) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (36) detail.krus : --> id=116;datetime=2014-04-23 17:02:40;timestamp=1398250960 (36) [detail.krus] = ok (36) attr_filter.accounting_response : EXPAND %{User-Name} (36) attr_filter.accounting_response : --> voip.172.27.96.11 (36) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (36) [attr_filter.accounting_response] = updated (36) } # accounting = updated Sending Accounting-Response of id 116 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (36) Finished request 36. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=253, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (37) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (37) preacct { (37) [preprocess] = ok (37) acct_counters64.preacct acct_counters64.preacct { (37) update request { (37) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (37) --> 0 (37) Acct-Input-Octets64 = 0 (37) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (37) --> 0 (37) Acct-Output-Octets64 = 0 (37) } # update request = noop (37) } # acct_counters64.preacct acct_counters64.preacct = noop (37) update request { (37) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (37) --> 1398250960 (37) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (37) } # update request = noop (37) acct_unique acct_unique { (37) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (37) EXPAND %{string:Class} (37) --> (37) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (37) else else { (37) update request { (37) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (37) --> f5f5d59c2e7cc6c7f286d9f011502c28 (37) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (37) } # update request = noop (37) } # else else = noop (37) } # acct_unique acct_unique = noop (37) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (37) suffix : No such realm "NULL" (37) [suffix] = noop (37) } # preacct = ok (37) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (37) accounting { (37) [krus_python] = ok (37) if (fail) (37) if (fail) -> FALSE (37) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (37) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (37) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (37) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (37) detail.krus : --> id=253;datetime=2014-04-23 17:02:40;timestamp=1398250960 (37) [detail.krus] = ok (37) attr_filter.accounting_response : EXPAND %{User-Name} (37) attr_filter.accounting_response : --> voip.172.27.96.11 (37) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (37) [attr_filter.accounting_response] = updated (37) } # accounting = updated Sending Accounting-Response of id 253 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (37) Finished request 37. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=236, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (38) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (38) preacct { (38) [preprocess] = ok (38) acct_counters64.preacct acct_counters64.preacct { (38) update request { (38) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (38) --> 0 (38) Acct-Input-Octets64 = 0 (38) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (38) --> 0 (38) Acct-Output-Octets64 = 0 (38) } # update request = noop (38) } # acct_counters64.preacct acct_counters64.preacct = noop (38) update request { (38) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (38) --> 1398250960 (38) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (38) } # update request = noop (38) acct_unique acct_unique { (38) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (38) EXPAND %{string:Class} (38) --> (38) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (38) else else { (38) update request { (38) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (38) --> f5f5d59c2e7cc6c7f286d9f011502c28 (38) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (38) } # update request = noop (38) } # else else = noop (38) } # acct_unique acct_unique = noop (38) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (38) suffix : No such realm "NULL" (38) [suffix] = noop (38) } # preacct = ok (38) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (38) accounting { (38) [krus_python] = ok (38) if (fail) (38) if (fail) -> FALSE (38) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (38) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (38) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (38) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (38) detail.krus : --> id=236;datetime=2014-04-23 17:02:40;timestamp=1398250960 (38) [detail.krus] = ok (38) attr_filter.accounting_response : EXPAND %{User-Name} (38) attr_filter.accounting_response : --> voip.172.27.96.11 (38) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (38) [attr_filter.accounting_response] = updated (38) } # accounting = updated Sending Accounting-Response of id 236 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (38) Finished request 38. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=63, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (39) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (39) preacct { (39) [preprocess] = ok (39) acct_counters64.preacct acct_counters64.preacct { (39) update request { (39) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (39) --> 0 (39) Acct-Input-Octets64 = 0 (39) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (39) --> 0 (39) Acct-Output-Octets64 = 0 (39) } # update request = noop (39) } # acct_counters64.preacct acct_counters64.preacct = noop (39) update request { (39) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (39) --> 1398250960 (39) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (39) } # update request = noop (39) acct_unique acct_unique { (39) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (39) EXPAND %{string:Class} (39) --> (39) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (39) else else { (39) update request { (39) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (39) --> f5f5d59c2e7cc6c7f286d9f011502c28 (39) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (39) } # update request = noop (39) } # else else = noop (39) } # acct_unique acct_unique = noop (39) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (39) suffix : No such realm "NULL" (39) [suffix] = noop (39) } # preacct = ok (39) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (39) accounting { (39) [krus_python] = ok (39) if (fail) (39) if (fail) -> FALSE (39) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (39) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (39) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (39) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (39) detail.krus : --> id=63;datetime=2014-04-23 17:02:40;timestamp=1398250960 (39) [detail.krus] = ok (39) attr_filter.accounting_response : EXPAND %{User-Name} (39) attr_filter.accounting_response : --> voip.172.27.96.11 (39) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (39) [attr_filter.accounting_response] = updated (39) } # accounting = updated Sending Accounting-Response of id 63 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (39) Finished request 39. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=154, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (40) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (40) preacct { (40) [preprocess] = ok (40) acct_counters64.preacct acct_counters64.preacct { (40) update request { (40) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (40) --> 0 (40) Acct-Input-Octets64 = 0 (40) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (40) --> 0 (40) Acct-Output-Octets64 = 0 (40) } # update request = noop (40) } # acct_counters64.preacct acct_counters64.preacct = noop (40) update request { (40) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (40) --> 1398250960 (40) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (40) } # update request = noop (40) acct_unique acct_unique { (40) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (40) EXPAND %{string:Class} (40) --> (40) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (40) else else { (40) update request { (40) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (40) --> f5f5d59c2e7cc6c7f286d9f011502c28 (40) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (40) } # update request = noop (40) } # else else = noop (40) } # acct_unique acct_unique = noop (40) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (40) suffix : No such realm "NULL" (40) [suffix] = noop (40) } # preacct = ok (40) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (40) accounting { (40) [krus_python] = ok (40) if (fail) (40) if (fail) -> FALSE (40) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (40) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (40) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (40) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (40) detail.krus : --> id=154;datetime=2014-04-23 17:02:40;timestamp=1398250960 (40) [detail.krus] = ok (40) attr_filter.accounting_response : EXPAND %{User-Name} (40) attr_filter.accounting_response : --> voip.172.27.96.11 (40) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (40) [attr_filter.accounting_response] = updated (40) } # accounting = updated Sending Accounting-Response of id 154 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (40) Finished request 40. Waking up in 0.1 seconds. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=15, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (41) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (41) preacct { (41) [preprocess] = ok (41) acct_counters64.preacct acct_counters64.preacct { (41) update request { (41) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (41) --> 0 (41) Acct-Input-Octets64 = 0 (41) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (41) --> 0 (41) Acct-Output-Octets64 = 0 (41) } # update request = noop (41) } # acct_counters64.preacct acct_counters64.preacct = noop (41) update request { (41) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (41) --> 1398250960 (41) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (41) } # update request = noop (41) acct_unique acct_unique { (41) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (41) EXPAND %{string:Class} (41) --> (41) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (41) else else { (41) update request { (41) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (41) --> f5f5d59c2e7cc6c7f286d9f011502c28 (41) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (41) } # update request = noop (41) } # else else = noop (41) } # acct_unique acct_unique = noop (41) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (41) suffix : No such realm "NULL" (41) [suffix] = noop (41) } # preacct = ok (41) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (41) accounting { (41) [krus_python] = ok (41) if (fail) (41) if (fail) -> FALSE (41) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (41) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (41) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (41) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (41) detail.krus : --> id=15;datetime=2014-04-23 17:02:40;timestamp=1398250960 (41) [detail.krus] = ok (41) attr_filter.accounting_response : EXPAND %{User-Name} (41) attr_filter.accounting_response : --> voip.172.27.96.11 (41) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (41) [attr_filter.accounting_response] = updated (41) } # accounting = updated Sending Accounting-Response of id 15 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (41) Finished request 41. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=13, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (42) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (42) preacct { (42) [preprocess] = ok (42) acct_counters64.preacct acct_counters64.preacct { (42) update request { (42) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (42) --> 0 (42) Acct-Input-Octets64 = 0 (42) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (42) --> 0 (42) Acct-Output-Octets64 = 0 (42) } # update request = noop (42) } # acct_counters64.preacct acct_counters64.preacct = noop (42) update request { (42) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (42) --> 1398250960 (42) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (42) } # update request = noop (42) acct_unique acct_unique { (42) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (42) EXPAND %{string:Class} (42) --> (42) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (42) else else { (42) update request { (42) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (42) --> f5f5d59c2e7cc6c7f286d9f011502c28 (42) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (42) } # update request = noop (42) } # else else = noop (42) } # acct_unique acct_unique = noop (42) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (42) suffix : No such realm "NULL" (42) [suffix] = noop (42) } # preacct = ok (42) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (42) accounting { (42) [krus_python] = ok (42) if (fail) (42) if (fail) -> FALSE (42) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (42) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (42) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (42) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (42) detail.krus : --> id=13;datetime=2014-04-23 17:02:40;timestamp=1398250960 (42) [detail.krus] = ok (42) attr_filter.accounting_response : EXPAND %{User-Name} (42) attr_filter.accounting_response : --> voip.172.27.96.11 (42) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (42) [attr_filter.accounting_response] = updated (42) } # accounting = updated Sending Accounting-Response of id 13 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (42) Finished request 42. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=50, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (43) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (43) preacct { (43) [preprocess] = ok (43) acct_counters64.preacct acct_counters64.preacct { (43) update request { (43) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (43) --> 0 (43) Acct-Input-Octets64 = 0 (43) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (43) --> 0 (43) Acct-Output-Octets64 = 0 (43) } # update request = noop (43) } # acct_counters64.preacct acct_counters64.preacct = noop (43) update request { (43) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (43) --> 1398250960 (43) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (43) } # update request = noop (43) acct_unique acct_unique { (43) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (43) EXPAND %{string:Class} (43) --> (43) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (43) else else { (43) update request { (43) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (43) --> f5f5d59c2e7cc6c7f286d9f011502c28 (43) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (43) } # update request = noop (43) } # else else = noop (43) } # acct_unique acct_unique = noop (43) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (43) suffix : No such realm "NULL" (43) [suffix] = noop (43) } # preacct = ok (43) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (43) accounting { (43) [krus_python] = ok (43) if (fail) (43) if (fail) -> FALSE (43) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (43) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (43) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (43) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (43) detail.krus : --> id=50;datetime=2014-04-23 17:02:40;timestamp=1398250960 (43) [detail.krus] = ok (43) attr_filter.accounting_response : EXPAND %{User-Name} (43) attr_filter.accounting_response : --> voip.172.27.96.11 (43) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (43) [attr_filter.accounting_response] = updated (43) } # accounting = updated Sending Accounting-Response of id 50 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (43) Finished request 43. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=17, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (44) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (44) preacct { (44) [preprocess] = ok (44) acct_counters64.preacct acct_counters64.preacct { (44) update request { (44) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (44) --> 0 (44) Acct-Input-Octets64 = 0 (44) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (44) --> 0 (44) Acct-Output-Octets64 = 0 (44) } # update request = noop (44) } # acct_counters64.preacct acct_counters64.preacct = noop (44) update request { (44) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (44) --> 1398250960 (44) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (44) } # update request = noop (44) acct_unique acct_unique { (44) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (44) EXPAND %{string:Class} (44) --> (44) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (44) else else { (44) update request { (44) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (44) --> f5f5d59c2e7cc6c7f286d9f011502c28 (44) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (44) } # update request = noop (44) } # else else = noop (44) } # acct_unique acct_unique = noop (44) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (44) suffix : No such realm "NULL" (44) [suffix] = noop (44) } # preacct = ok (44) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (44) accounting { (44) [krus_python] = ok (44) if (fail) (44) if (fail) -> FALSE (44) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (44) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (44) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (44) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (44) detail.krus : --> id=17;datetime=2014-04-23 17:02:40;timestamp=1398250960 (44) [detail.krus] = ok (44) attr_filter.accounting_response : EXPAND %{User-Name} (44) attr_filter.accounting_response : --> voip.172.27.96.11 (44) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (44) [attr_filter.accounting_response] = updated (44) } # accounting = updated Sending Accounting-Response of id 17 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (44) Finished request 44. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=212, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (45) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (45) preacct { (45) [preprocess] = ok (45) acct_counters64.preacct acct_counters64.preacct { (45) update request { (45) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (45) --> 0 (45) Acct-Input-Octets64 = 0 (45) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (45) --> 0 (45) Acct-Output-Octets64 = 0 (45) } # update request = noop (45) } # acct_counters64.preacct acct_counters64.preacct = noop (45) update request { (45) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (45) --> 1398250960 (45) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (45) } # update request = noop (45) acct_unique acct_unique { (45) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (45) EXPAND %{string:Class} (45) --> (45) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (45) else else { (45) update request { (45) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (45) --> f5f5d59c2e7cc6c7f286d9f011502c28 (45) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (45) } # update request = noop (45) } # else else = noop (45) } # acct_unique acct_unique = noop (45) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (45) suffix : No such realm "NULL" (45) [suffix] = noop (45) } # preacct = ok (45) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (45) accounting { (45) [krus_python] = ok (45) if (fail) (45) if (fail) -> FALSE (45) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (45) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (45) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (45) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (45) detail.krus : --> id=212;datetime=2014-04-23 17:02:40;timestamp=1398250960 (45) [detail.krus] = ok (45) attr_filter.accounting_response : EXPAND %{User-Name} (45) attr_filter.accounting_response : --> voip.172.27.96.11 (45) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (45) [attr_filter.accounting_response] = updated (45) } # accounting = updated Sending Accounting-Response of id 212 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (45) Finished request 45. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=227, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (46) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (46) preacct { (46) [preprocess] = ok (46) acct_counters64.preacct acct_counters64.preacct { (46) update request { (46) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (46) --> 0 (46) Acct-Input-Octets64 = 0 (46) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (46) --> 0 (46) Acct-Output-Octets64 = 0 (46) } # update request = noop (46) } # acct_counters64.preacct acct_counters64.preacct = noop (46) update request { (46) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (46) --> 1398250960 (46) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (46) } # update request = noop (46) acct_unique acct_unique { (46) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (46) EXPAND %{string:Class} (46) --> (46) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (46) else else { (46) update request { (46) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (46) --> f5f5d59c2e7cc6c7f286d9f011502c28 (46) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (46) } # update request = noop (46) } # else else = noop (46) } # acct_unique acct_unique = noop (46) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (46) suffix : No such realm "NULL" (46) [suffix] = noop (46) } # preacct = ok (46) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (46) accounting { (46) [krus_python] = ok (46) if (fail) (46) if (fail) -> FALSE (46) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (46) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (46) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (46) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (46) detail.krus : --> id=227;datetime=2014-04-23 17:02:40;timestamp=1398250960 (46) [detail.krus] = ok (46) attr_filter.accounting_response : EXPAND %{User-Name} (46) attr_filter.accounting_response : --> voip.172.27.96.11 (46) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (46) [attr_filter.accounting_response] = updated (46) } # accounting = updated Sending Accounting-Response of id 227 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (46) Finished request 46. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=94, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (47) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (47) preacct { (47) [preprocess] = ok (47) acct_counters64.preacct acct_counters64.preacct { (47) update request { (47) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (47) --> 0 (47) Acct-Input-Octets64 = 0 (47) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (47) --> 0 (47) Acct-Output-Octets64 = 0 (47) } # update request = noop (47) } # acct_counters64.preacct acct_counters64.preacct = noop (47) update request { (47) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (47) --> 1398250960 (47) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (47) } # update request = noop (47) acct_unique acct_unique { (47) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (47) EXPAND %{string:Class} (47) --> (47) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (47) else else { (47) update request { (47) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (47) --> f5f5d59c2e7cc6c7f286d9f011502c28 (47) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (47) } # update request = noop (47) } # else else = noop (47) } # acct_unique acct_unique = noop (47) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (47) suffix : No such realm "NULL" (47) [suffix] = noop (47) } # preacct = ok (47) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (47) accounting { (47) [krus_python] = ok (47) if (fail) (47) if (fail) -> FALSE (47) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (47) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (47) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (47) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (47) detail.krus : --> id=94;datetime=2014-04-23 17:02:40;timestamp=1398250960 (47) [detail.krus] = ok (47) attr_filter.accounting_response : EXPAND %{User-Name} (47) attr_filter.accounting_response : --> voip.172.27.96.11 (47) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (47) [attr_filter.accounting_response] = updated (47) } # accounting = updated Sending Accounting-Response of id 94 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (47) Finished request 47. (28) Cleaning up request packet ID 243 with timestamp +7 rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=245, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (48) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (48) preacct { (48) [preprocess] = ok (48) acct_counters64.preacct acct_counters64.preacct { (48) update request { (48) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (48) --> 0 (48) Acct-Input-Octets64 = 0 (48) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (48) --> 0 (48) Acct-Output-Octets64 = 0 (48) } # update request = noop (48) } # acct_counters64.preacct acct_counters64.preacct = noop (48) update request { (48) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (48) --> 1398250960 (48) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (48) } # update request = noop (48) acct_unique acct_unique { (48) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (48) EXPAND %{string:Class} (48) --> (48) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (48) else else { (48) update request { (48) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (48) --> f5f5d59c2e7cc6c7f286d9f011502c28 (48) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (48) } # update request = noop (48) } # else else = noop (48) } # acct_unique acct_unique = noop (48) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (48) suffix : No such realm "NULL" (48) [suffix] = noop (48) } # preacct = ok (48) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (48) accounting { (48) [krus_python] = ok (48) if (fail) (48) if (fail) -> FALSE (48) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (48) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (48) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (48) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (48) detail.krus : --> id=245;datetime=2014-04-23 17:02:40;timestamp=1398250960 (48) [detail.krus] = ok (48) attr_filter.accounting_response : EXPAND %{User-Name} (48) attr_filter.accounting_response : --> voip.172.27.96.11 (48) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (48) [attr_filter.accounting_response] = updated (48) } # accounting = updated Sending Accounting-Response of id 245 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (48) Finished request 48. rad_recv: Accounting-Request packet from host 127.0.0.1 port 50716, id=171, length=709 Acct-Status-Type = Start NAS-IP-Address = 172.24.96.5 NAS-Identifier = 'l1gk_ekb_2' NAS-Port-Type = Virtual Service-Type = Login-User Acct-Session-Id = '5332326300006432' User-Name = 'voip.172.27.96.11' Framed-IP-Address = 172.27.96.11 Calling-Station-Id = '94073433789692' Called-Station-Id = '20079634461269' h323-conf-id = 'BBD64353 2688427B 8FD80002 A407D676' h323-gw-id = 'l1gk_ekb_2' h323-call-origin = 'proxy' h323-call-type = 'VoIP' h323-setup-time = '2014-04-08_12:00:06' h323-remote-address = '172.24.96.4' Cisco-AVPair = 'h323-ivr-out=h323-call-id:BBD64353 CC055CE5 8FD90002 A407D676' Acct-Delay-Time = 0 Cisco-AVPair = 'h323pddtime=4' Cisco-AVPair = 'h323ringtime=43' Cisco-AVPair = 'h323routeattempts=0' Cisco-AVPair = 'h323_rtp_proxy=0' Cisco-AVPair = 'RTP_source_IP=0.0.0.0' Cisco-AVPair = 'RTP_destination_IP=0.0.0.0' Cisco-AVPair = 'RTCP_source_packet_count=0' Cisco-AVPair = 'RTCP_source_packet_lost=0' Cisco-AVPair = 'RTCP_source_jitter=0|0|0' Cisco-AVPair = 'RTCP_destination_packet_count=0' Cisco-AVPair = 'RTCP_destination_packet_lost=0' Cisco-AVPair = 'RTCP_destination_jitter=0|0|0' (49) # Executing section preacct from file /opt/fr.krus/conf/sites-enabled/krus (49) preacct { (49) [preprocess] = ok (49) acct_counters64.preacct acct_counters64.preacct { (49) update request { (49) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}} (49) --> 0 (49) Acct-Input-Octets64 = 0 (49) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}} (49) --> 0 (49) Acct-Output-Octets64 = 0 (49) } # update request = noop (49) } # acct_counters64.preacct acct_counters64.preacct = noop (49) update request { (49) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} - %{%{Acct-Delay-Time}:-0}} (49) --> 1398250960 (49) FreeRADIUS-Acct-Session-Start-Time = "Apr 23 2014 17:02:40 YEKT" (49) } # update request = noop (49) acct_unique acct_unique { (49) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (49) EXPAND %{string:Class} (49) --> (49) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (49) else else { (49) update request { (49) EXPAND %{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}} (49) --> f5f5d59c2e7cc6c7f286d9f011502c28 (49) Acct-Unique-Session-Id := "f5f5d59c2e7cc6c7f286d9f011502c28" (49) } # update request = noop (49) } # else else = noop (49) } # acct_unique acct_unique = noop (49) suffix : No '@' in User-Name = "voip.172.27.96.11", looking up realm NULL (49) suffix : No such realm "NULL" (49) [suffix] = noop (49) } # preacct = ok (49) # Executing section accounting from file /opt/fr.krus/conf/sites-enabled/krus (49) accounting { (49) [krus_python] = ok (49) if (fail) (49) if (fail) -> FALSE (49) detail.krus : EXPAND /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog (49) detail.krus : --> /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (49) detail.krus : /opt/fr.krus/acct/%Y%m-%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/%Y%m%d.radlog expands to /opt/fr.krus/acct/201404-127.0.0.1/20140423.radlog (49) detail.krus : EXPAND id=%I;datetime=%S;timestamp=%l (49) detail.krus : --> id=171;datetime=2014-04-23 17:02:40;timestamp=1398250960 (49) [detail.krus] = ok (49) attr_filter.accounting_response : EXPAND %{User-Name} (49) attr_filter.accounting_response : --> voip.172.27.96.11 (49) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (49) [attr_filter.accounting_response] = updated (49) } # accounting = updated Sending Accounting-Response of id 171 from 127.0.0.1 port 1813 to 127.0.0.1 port 50716 (49) Finished request 49. (29) Cleaning up request packet ID 147 with timestamp +7 ...

[alandekok]

Please try the v3.0.x branch. We've pushed a number of fixes in the last few weeks. This issue should be fixed, too.