IPoE+L2+dhcp+opt82 (dhcp_local_relay)

IPoE related questions
baronzzz
Posts: 22
Joined: 22 Sep 2019, 12:01

Re: IPoE+L2+dhcp+opt82 (dhcp_local_relay)

Post by baronzzz » 02 Oct 2019, 16:46

Глянул в debug LBinet:
Спойлер
02.10.2019 21:39:51.100920 [0x0000b2ecc700] DEBUG recv_udp_sock:91: IP_PKTINFO control data found
02.10.2019 21:39:51.100931 [0x0000b2ecc700] DEBUG iface_by_index:108: lookup interface by index 5
02.10.2019 21:39:51.100946 [0x0000b2ecc700] DEBUG dhcp_option_print:233: DHCP Op: 53/0x35, type: 2, len: 01, value: u8 01 / 0x01
02.10.2019 21:39:51.100961 [0x0000b2ecc700] DEBUG dhcp_option_print:233: DHCP Op: 61/0x3D, type: 5, len: 07, value: HEX: 01 18 A9 05 CB C3 0A ASCII '.......' HEX:01 18 a9 05 cb c3 0a proto unas
02.10.2019 21:39:51.100967 [0x0000b2ecc700] DEBUG dhcp_option_print:233: DHCP Op: 12/0x0C, type: 1, len: 13, value: 'Administrator'
02.10.2019 21:39:51.100973 [0x0000b2ecc700] DEBUG dhcp_option_print:233: DHCP Op: 60/0x3C, type: 1, len: 08, value: 'MSFT 5.0'
02.10.2019 21:39:51.100983 [0x0000b2ecc700] DEBUG dhcp_option_print:233: DHCP Op: 55/0x37, type: 5, len: 12, value: HEX: 01 0F 03 06 2C 2E 2F 1F 21 79 F9 2B ReqOp: 1 15 3 6 44 46 47 31 33 121 -7
02.10.2019 21:39:51.100997 [0x0000b2ecc700] DEBUG dhcp_option_print:233: DHCP Op: 82/0x52, type: 5, len: 18, value: HEX: 01 06 00 04 00 6F 00 03 02 08 00 06 34 08 04 64 49 84 ASCII '.....o......
02.10.2019 21:39:51.101007 [0x0000b2ecc700] DEBUG Dump DHCP packet: op=1, htype=1, hlen=6, hops=0x00, xid=0x654516c5, secs=3, flags=0x0000, ciaddr=0.0.0.0, yiaddr=0.0.0.0, siaddr=0.0.0.0, giaddr
02.10.2019 21:39:51.101021 [0x0000b2ecc700] DEBUG dhcp_op82_parse:466: Op82 Circuit ID 006F0003:VLAN 111, Unit 0, Port 3 (l=4), Remote ID 340804644984 (l=6)
02.10.2019 21:39:51.101028 [0x0000b2ecc700] DEBUG dhcp_allocate_ip:4692: lookup up client by Op.82: 0x7f7ca0002440
02.10.2019 21:39:51.101032 [0x0000b2ecc700] DEBUG pool_ip_entry_match_op82:153: branched by Op.82 RemoteID 340804644984
02.10.2019 21:39:51.101035 [0x0000b2ecc700] DEBUG pool_ip_entry_match_op82:179: RemoteID = 340804644984, record not FOUND
02.10.2019 21:39:51.101038 [0x0000b2ecc700] DEBUG dhcp_allocate_ip:4703: client MAC 18:a9:05:cb:c3:0a not permitted by Op.82: 0x7f7ca0002440
02.10.2019 21:39:51.101041 [0x0000b2ecc700] DEBUG dhcp_device_list_lookup_op82:4497: Op.82 lookup device RemoteID 340804644984
02.10.2019 21:39:51.101045 [0x0000b2ecc700] DEBUG dhcp_device_list_lookup_op82:4519: RemoteID = 340804644984, record FOUND: IP=192.168.200.202 device_id=01 name="sw-d3200-200.202"
02.10.2019 21:39:51.101050 [0x0000b2ecc700] DEBUG dhcp_allocate_ip:4714: Op.82 check passed: device entry=(nil) id=1
02.10.2019 21:39:51.101053 [0x0000b2ecc700] DEBUG dhcp_allocate_ip:4718: lookup equipment for MAC 18:a9:05:cb:c3:0a
02.10.2019 21:39:51.101056 [0x0000b2ecc700] DEBUG dhcp_allocate_ip:4738: equipment not found
02.10.2019 21:39:51.101058 [0x0000b2ecc700] DEBUG dhcp_allocate_ip:4808: lookup for dynamic guest IP, device_id = 1
02.10.2019 21:39:51.101062 [0x0000b2ecc700] DEBUG dhcp_pool_lookup_dynamic_ip:411: lookup dynamic guest IP: MAC=18:a9:05:cb:c3:0a: device_id=1 vg_id=0 guest=Y
02.10.2019 21:39:51.101067 [0x0000b2ecc700] DEBUG dhcp_pool_lookup_dynamic_ip:511: lookup dynamic IP by MAC: 18:a9:05:cb:c3:0a: result (nil)
02.10.2019 21:39:51.101070 [0x0000b2ecc700] DEBUG dhcp_allocate_ip:4815: no guest IP could be assigned for MAC 18:a9:05:cb:c3:0a
02.10.2019 21:39:51.101075 [0x0000b2ecc700] DEBUG dhcp_msg_dispatch:108: DHCPDISCOVER from unknown client HW MAC 18:a9:05:cb:c3:0a
02.10.2019 21:39:51.101079 [0x0000b2ecc700] DEBUG dhcp_main:298: dhcp_msg_dispatch(0x7f7ca00009f0) failed
02.10.2019 21:39:51.101085 [0x0000b2ecc700] DEBUG dhcp_main:290: waiting for req

baronzzz
Posts: 22
Joined: 22 Sep 2019, 12:01

Re: IPoE+L2+dhcp+opt82 (dhcp_local_relay)

Post by baronzzz » 03 Oct 2019, 16:10

Дело сдвинулось, изменил атрибуты opt82 на
attr-dhcp-opt82-remote-id=Redback-Agent-Remote-Id
attr-dhcp-opt82-circuit-id=Redback-Agent-Circuit-Id
прописал в словаре и
ИТОГ:



cat lbarcd_mikrotik.log
Спойлер
03.10.2019 21:00:07.025523 VERBOSE  LWP7890 [src/radius_base.cpp:56] ============== Authorization packet #16 received from 192.168.200.200, size: 174 ==============
03.10.2019 21:00:07.025728 VERBOSE  LWP7890 [src/radius_record.cpp:90] Access-Request (1), id: 0x1, length: 174
03.10.2019 21:00:07.025750 VERBOSE  LWP7890 [src/radius_record.cpp:108] Authenticator: 400ffe78d0f24051c223af7fb714f6c7
03.10.2019 21:00:07.025762 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 21:00:07.025772 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 21:00:07.025780 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 21:00:07.025789 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "543"
03.10.2019 21:00:07.025796 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 21:00:07.025803 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 21:00:07.025810 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 21:00:07.025817 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 21:00:07.025826 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 21:00:07.025839 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 21:00:07.025848 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac49f5bf"
03.10.2019 21:00:07.025864 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Password", value: "ae30be2209aff974d6d36da9b13fe3934db05901e70be38986b18090e26bd3f2"
03.10.2019 21:00:07.025876 VERBOSE  LWP7890 [src/radius_record.cpp:186] User-Password = "18:a9:05:cb:c3:0a"
03.10.2019 21:00:07.025887 VERBOSE  LWP7890 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 21:00:07.025967 VERBOSE  LWP7890 [src/radius_packet.cpp:652] Trying to authorize user by Opt82 params: "340804644984", 3
03.10.2019 21:00:07.026638 INFO     LWP7890 [src/radius_packet.cpp:896] Auth by 'opt82' ok: [1], Session-Id 774dcff2ac49f5bf
03.10.2019 21:00:07.028280 VERBOSE  LWP7890 [src/radius_packet.cpp:1163] ANI '18:a9:05:cb:c3:0a' (User '18:a9:05:cb:c3:0a') is clean
03.10.2019 21:00:07.028570 VERBOSE  LWP7890 [src/radius_packet.cpp:1074] User: '1234', bill by traffic, unlimited session timeout (86400)
03.10.2019 21:00:07.030742 WARNING  LWP7890 [src/radius.cpp:2062] ANI '18:a9:05:cb:c3:0a' is bound to 10.11.0.8/255.255.255.255 for user '18:a9:05:cb:c3:0a'
03.10.2019 21:00:07.030766 VERBOSE  LWP7890 [src/radius.cpp:2144] Client IP/Netmask: 10.11.0.8/255.255.255.255, ANI: "18:a9:05:cb:c3:0a"
03.10.2019 21:00:07.030774 WARNING  LWP7890 [src/radius.cpp:536] Unable to allocate delegated prefix
03.10.2019 21:00:07.030779 WARNING  LWP7890 [src/radius.cpp:538] Unable to allocate framed prefix
03.10.2019 21:00:07.030800 INFO     LWP7890 [src/radius.cpp:609] Access-Accept, <18:a9:05:cb:c3:0a> [1], Session-Id 774dcff2ac49f5bf
03.10.2019 21:00:07.030807 VERBOSE  LWP7890 [src/radius.cpp:612] =============== Output attributes dump: ===============
03.10.2019 21:00:07.030820 VERBOSE  LWP7890 [src/radius.cpp:706] Attribute "Session-Timeout", value: "86400"
03.10.2019 21:00:07.030828 VERBOSE  LWP7890 [src/radius.cpp:711] Attribute "Service-Type", value: "2"
03.10.2019 21:00:07.030836 VERBOSE  LWP7890 [src/radius.cpp:715] Attribute "Framed-Protocol", value: "1"
03.10.2019 21:00:07.030845 VERBOSE  LWP7890 [src/radius.cpp:726] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 21:00:07.030854 VERBOSE  LWP7890 [src/radius.cpp:746] Attribute "Framed-IP-Netmask", value: "255.255.255.255"
03.10.2019 21:00:07.032002 VERBOSE  LWP7890 [src/radius.cpp:756] Attribute "Class", tag: "174", value: "45b930d6-a255-4fae-a696-1e150d467aae/1"
03.10.2019 21:00:07.032058 VERBOSE  LWP7890 [src/radius.cpp:799] Attribute "Acct-Interim-Interval", value: "60"
03.10.2019 21:00:07.032075 VERBOSE  LWP7890 [src/radius.cpp:820] INSERT INTO CACHE NAS_IP_ADDRESS: 192.168.200.200; UUID(session_id): 774dcff2ac49f5bf
03.10.2019 21:00:07.035420 WARNING  LWP7890 [src/radius.cpp:879] Packet received from MAC = '18:a9:05:cb:c3:0a' while another MAC = '18:a9:05:cb:c3:0a' is assigned to vg_id = 1
03.10.2019 21:00:07.035455 VERBOSE  LWP7890 [src/radius_record.cpp:90] Access-Accept (2), id: 0x1, length: 96
03.10.2019 21:00:07.035499 VERBOSE  LWP7890 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Authentication answer sent successfully, time: 9 <=<=<=<=<=<=<=<
03.10.2019 21:00:15.025670 VERBOSE  LWP7890 [src/radius_base.cpp:56] ============== Authorization packet #17 received from 192.168.200.200, size: 174 ==============
03.10.2019 21:00:15.025703 VERBOSE  LWP7890 [src/radius_record.cpp:90] Access-Request (1), id: 0x1, length: 174
03.10.2019 21:00:15.025715 VERBOSE  LWP7890 [src/radius_record.cpp:108] Authenticator: 185d3620ca9eaa71868eb66a511e35d0
03.10.2019 21:00:15.025726 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 21:00:15.025734 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 21:00:15.025742 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 21:00:15.025749 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "544"
03.10.2019 21:00:15.025756 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 21:00:15.025762 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 21:00:15.025768 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 21:00:15.025774 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 21:00:15.025783 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 21:00:15.025793 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 21:00:15.025800 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac49f5c0"
03.10.2019 21:00:15.025812 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Password", value: "d55d0630f64df275880a6b2170c07dd87121e66619dc9072e4ffb6d5753437ae"
03.10.2019 21:00:15.025820 VERBOSE  LWP7890 [src/radius_record.cpp:186] User-Password = "18:a9:05:cb:c3:0a"
03.10.2019 21:00:15.025829 VERBOSE  LWP7890 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 21:00:15.025879 VERBOSE  LWP7890 [src/radius_packet.cpp:652] Trying to authorize user by Opt82 params: "340804644984", 3
03.10.2019 21:00:15.026478 INFO     LWP7890 [src/radius_packet.cpp:896] Auth by 'opt82' ok: [1], Session-Id 774dcff2ac49f5c0
03.10.2019 21:00:15.027790 VERBOSE  LWP7890 [src/radius_packet.cpp:1163] ANI '18:a9:05:cb:c3:0a' (User '18:a9:05:cb:c3:0a') is clean
03.10.2019 21:00:15.028050 VERBOSE  LWP7890 [src/radius_packet.cpp:1074] User: '1234', bill by traffic, unlimited session timeout (86400)
03.10.2019 21:00:15.029125 VERBOSE  LWP7890 [src/radius.cpp:920] Found existing session: 774dcff2ac49f5bf
03.10.2019 21:00:15.029609 VERBOSE  LWP7890 [src/radius.cpp:931] login '18:a9:05:cb:c3:0a' is already connected (1 sessions >= 1 max)
03.10.2019 21:00:15.029651 INFO     LWP7890 [src/radius.cpp:591] Access-Reject, <18:a9:05:cb:c3:0a> [1], Session-Id 774dcff2ac49f5c0, {already connected}
03.10.2019 21:00:15.030225 WARNING  LWP7890 [src/radius.cpp:879] Packet received from MAC = '18:a9:05:cb:c3:0a' while another MAC = '18:a9:05:cb:c3:0a' is assigned to vg_id = 1
03.10.2019 21:00:15.030255 VERBOSE  LWP7890 [src/radius_record.cpp:90] Access-Reject (3), id: 0x1, length: 20
03.10.2019 21:00:15.030297 VERBOSE  LWP7890 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Authentication answer sent successfully, time: 4 <=<=<=<=<=<=<=<
03.10.2019 21:00:30.011880 VERBOSE  LWP7885 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 21:00:32.026212 VERBOSE  LWP7890 [src/radius_base.cpp:56] ============== Authorization packet #18 received from 192.168.200.200, size: 174 ==============
03.10.2019 21:00:32.026246 VERBOSE  LWP7890 [src/radius_record.cpp:90] Access-Request (1), id: 0x1, length: 174
03.10.2019 21:00:32.026260 VERBOSE  LWP7890 [src/radius_record.cpp:108] Authenticator: cce6be2ddad59a2671280d3082e9dd38
03.10.2019 21:00:32.026271 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 21:00:32.026281 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 21:00:32.026289 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 21:00:32.026297 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "545"
03.10.2019 21:00:32.026305 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 21:00:32.026312 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 21:00:32.026319 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 21:00:32.026326 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 21:00:32.026335 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 21:00:32.026346 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 21:00:32.026354 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac49f5c1"
03.10.2019 21:00:32.026366 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Password", value: "12c37a8e52f89c3dcc7c5f16e3243ef169f26de8cfca2b327b586e26374078dc"
03.10.2019 21:00:32.026375 VERBOSE  LWP7890 [src/radius_record.cpp:186] User-Password = "18:a9:05:cb:c3:0a"
03.10.2019 21:00:32.026385 VERBOSE  LWP7890 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 21:00:32.026440 VERBOSE  LWP7890 [src/radius_packet.cpp:652] Trying to authorize user by Opt82 params: "340804644984", 3
03.10.2019 21:00:32.027033 INFO     LWP7890 [src/radius_packet.cpp:896] Auth by 'opt82' ok: [1], Session-Id 774dcff2ac49f5c1
03.10.2019 21:00:32.028409 VERBOSE  LWP7890 [src/radius_packet.cpp:1163] ANI '18:a9:05:cb:c3:0a' (User '18:a9:05:cb:c3:0a') is clean
03.10.2019 21:00:32.028689 VERBOSE  LWP7890 [src/radius_packet.cpp:1074] User: '1234', bill by traffic, unlimited session timeout (86400)
03.10.2019 21:00:32.029853 VERBOSE  LWP7890 [src/radius.cpp:920] Found existing session: 774dcff2ac49f5bf
03.10.2019 21:00:32.030580 VERBOSE  LWP7890 [src/radius.cpp:931] login '18:a9:05:cb:c3:0a' is already connected (1 sessions >= 1 max)
03.10.2019 21:00:32.030624 INFO     LWP7890 [src/radius.cpp:591] Access-Reject, <18:a9:05:cb:c3:0a> [1], Session-Id 774dcff2ac49f5c1, {already connected}
03.10.2019 21:00:32.031188 WARNING  LWP7890 [src/radius.cpp:879] Packet received from MAC = '18:a9:05:cb:c3:0a' while another MAC = '18:a9:05:cb:c3:0a' is assigned to vg_id = 1
03.10.2019 21:00:32.031219 VERBOSE  LWP7890 [src/radius_record.cpp:90] Access-Reject (3), id: 0x1, length: 20
03.10.2019 21:00:32.031262 VERBOSE  LWP7890 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Authentication answer sent successfully, time: 5 <=<=<=<=<=<=<=<
03.10.2019 21:01:04.285104 VERBOSE  LWP7890 [src/radius_base.cpp:56] ============== Authorization packet #19 received from 192.168.200.200, size: 174 ==============
03.10.2019 21:01:04.285195 VERBOSE  LWP7890 [src/radius_record.cpp:90] Access-Request (1), id: 0x1, length: 174
03.10.2019 21:01:04.285212 VERBOSE  LWP7890 [src/radius_record.cpp:108] Authenticator: f631e7cdd06e5eba5fe23b6724d532bf
03.10.2019 21:01:04.285223 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 21:01:04.285232 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 21:01:04.285240 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 21:01:04.285248 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "546"
03.10.2019 21:01:04.285255 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 21:01:04.285262 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 21:01:04.285269 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 21:01:04.285275 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 21:01:04.285284 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 21:01:04.285295 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 21:01:04.285303 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac49f5c2"
03.10.2019 21:01:04.285315 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Password", value: "d8e438fb32710e0be0d1f35359ee1a7eafb7c1c6bb9afc1486e7704f2aeab838"
03.10.2019 21:01:04.285324 VERBOSE  LWP7890 [src/radius_record.cpp:186] User-Password = "18:a9:05:cb:c3:0a"
03.10.2019 21:01:04.285334 VERBOSE  LWP7890 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 21:01:04.285391 VERBOSE  LWP7890 [src/radius_packet.cpp:652] Trying to authorize user by Opt82 params: "340804644984", 3
03.10.2019 21:01:04.285971 INFO     LWP7890 [src/radius_packet.cpp:896] Auth by 'opt82' ok: [1], Session-Id 774dcff2ac49f5c2
03.10.2019 21:01:04.287429 VERBOSE  LWP7890 [src/radius_packet.cpp:1163] ANI '18:a9:05:cb:c3:0a' (User '18:a9:05:cb:c3:0a') is clean
03.10.2019 21:01:04.287697 VERBOSE  LWP7890 [src/radius_packet.cpp:1074] User: '1234', bill by traffic, unlimited session timeout (86400)
03.10.2019 21:01:04.288838 VERBOSE  LWP7890 [src/radius.cpp:920] Found existing session: 774dcff2ac49f5bf
03.10.2019 21:01:04.289330 VERBOSE  LWP7890 [src/radius.cpp:931] login '18:a9:05:cb:c3:0a' is already connected (1 sessions >= 1 max)
03.10.2019 21:01:04.289372 INFO     LWP7890 [src/radius.cpp:591] Access-Reject, <18:a9:05:cb:c3:0a> [1], Session-Id 774dcff2ac49f5c2, {already connected}
03.10.2019 21:01:04.289991 WARNING  LWP7890 [src/radius.cpp:879] Packet received from MAC = '18:a9:05:cb:c3:0a' while another MAC = '18:a9:05:cb:c3:0a' is assigned to vg_id = 1
03.10.2019 21:01:04.290022 VERBOSE  LWP7890 [src/radius_record.cpp:90] Access-Reject (3), id: 0x1, length: 20
03.10.2019 21:01:04.290071 VERBOSE  LWP7890 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Authentication answer sent successfully, time: 4 <=<=<=<=<=<=<=<
03.10.2019 21:01:07.358113 VERBOSE  LWP7890 [src/radius_base.cpp:56] ============== Authorization packet #20 received from 192.168.200.200, size: 174 ==============
03.10.2019 21:01:07.358148 VERBOSE  LWP7890 [src/radius_record.cpp:90] Access-Request (1), id: 0x1, length: 174
03.10.2019 21:01:07.358162 VERBOSE  LWP7890 [src/radius_record.cpp:108] Authenticator: 1adbc6dd368bf45c3a8720cdee48922a
03.10.2019 21:01:07.358173 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 21:01:07.358182 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 21:01:07.358190 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 21:01:07.358207 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "547"
03.10.2019 21:01:07.358214 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 21:01:07.358221 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 21:01:07.358228 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 21:01:07.358235 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 21:01:07.358244 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 21:01:07.358256 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 21:01:07.358264 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac49f5c3"
03.10.2019 21:01:07.358277 VERBOSE  LWP7890 [src/radius_record.cpp:113] Attribute "Password", value: "2d84f1ddd0e437dc90a2703e0d25e2beb031cc557f5b76b2a026c73628fd2d5f"
03.10.2019 21:01:07.358286 VERBOSE  LWP7890 [src/radius_record.cpp:186] User-Password = "18:a9:05:cb:c3:0a"
03.10.2019 21:01:07.358295 VERBOSE  LWP7890 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 21:01:07.358350 VERBOSE  LWP7890 [src/radius_packet.cpp:652] Trying to authorize user by Opt82 params: "340804644984", 3
03.10.2019 21:01:07.358985 INFO     LWP7890 [src/radius_packet.cpp:896] Auth by 'opt82' ok: [1], Session-Id 774dcff2ac49f5c3
03.10.2019 21:01:07.360347 VERBOSE  LWP7890 [src/radius_packet.cpp:1163] ANI '18:a9:05:cb:c3:0a' (User '18:a9:05:cb:c3:0a') is clean
03.10.2019 21:01:07.360633 VERBOSE  LWP7890 [src/radius_packet.cpp:1074] User: '1234', bill by traffic, unlimited session timeout (86400)
03.10.2019 21:01:07.361805 VERBOSE  LWP7890 [src/radius.cpp:920] Found existing session: 774dcff2ac49f5bf
03.10.2019 21:01:07.362293 VERBOSE  LWP7890 [src/radius.cpp:931] login '18:a9:05:cb:c3:0a' is already connected (1 sessions >= 1 max)
03.10.2019 21:01:07.362338 INFO     LWP7890 [src/radius.cpp:591] Access-Reject, <18:a9:05:cb:c3:0a> [1], Session-Id 774dcff2ac49f5c3, {already connected}
03.10.2019 21:01:07.363225 WARNING  LWP7890 [src/radius.cpp:879] Packet received from MAC = '18:a9:05:cb:c3:0a' while another MAC = '18:a9:05:cb:c3:0a' is assigned to vg_id = 1
03.10.2019 21:01:07.363258 VERBOSE  LWP7890 [src/radius_record.cpp:90] Access-Reject (3), id: 0x1, length: 20

cat lbinet.log
Спойлер
03.10.2019 21:00:05.670007 [0x0000f27fc700] DEBUG    dhcp_pool_expire_ip:3722: req to free "(null)" but dhcp_ip_pool uninitialized
03.10.2019 21:00:05.670019 [0x0000f27fc700] DEBUG    dhcp_pool_expire_offer:3807: req to free but dhcp_ip_pool uninitialized
03.10.2019 21:00:07.024518 [0x0000f2ffd700] DEBUG    recv_udp_sock:91: IP_PKTINFO control data found
03.10.2019 21:00:07.024542 [0x0000f2ffd700] DEBUG    iface_by_index:108: lookup interface by index 5
03.10.2019 21:00:07.024566 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 53/0x35, type: 2, len: 01, value: u8 01 / 0x01
03.10.2019 21:00:07.024581 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 61/0x3D, type: 5, len: 07, value: HEX: 01 18 A9 05 CB C3 0A ASCII '.......' HEX:01 18 a9 05 cb c3 0a  proto unassigned
03.10.2019 21:00:07.024587 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 12/0x0C, type: 1, len: 13, value: 'Administrator'
03.10.2019 21:00:07.024593 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 60/0x3C, type: 1, len: 08, value: 'MSFT 5.0'
03.10.2019 21:00:07.024604 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 55/0x37, type: 5, len: 12, value: HEX: 01 0F 03 06 2C 2E 2F 1F 21 79 F9 2B ReqOp: 1 15 3 6 44 46 47 31 33 121 -7 43
03.10.2019 21:00:07.024619 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 82/0x52, type: 5, len: 18, value: HEX: 01 06 00 04 00 6F 00 03 02 08 00 06 34 08 04 64 49 84 ASCII '.....o......4..dI.'
03.10.2019 21:00:07.024630 [0x0000f2ffd700] DEBUG    Dump DHCP packet: op=1, htype=1, hlen=6, hops=0x00, xid=0xb44314ea, secs=4, flags=0x0000, ciaddr=0.0.0.0, yiaddr=0.0.0.0, siaddr=0.0.0.0, giaddr=0.0.0.0, chaddr=18:a9:, sname=, filename=, cookie=0x63825363, len=312, sin_addr=0.0.0.0, sin_port=0, client_sockaddr=(67, 0, 0.0.0.0), dhcp_nopt=6, client_hw_addr=e0:12:, client_dhcp_pkt_len_max=0, dhcp_req_type=NOT SET, dhcp_reply_type=NOT SET
03.10.2019 21:00:07.024645 [0x0000f2ffd700] DEBUG    dhcp_op82_parse:466: Op82 Circuit ID 006F0003:VLAN 111, Unit 0, Port 3 (l=4), Remote ID 340804644984 (l=6)
03.10.2019 21:00:07.024652 [0x0000f2ffd700] ERROR    dhcp_allocate_ip:4680: DHCP IP pool uninitialized lookup!
03.10.2019 21:00:07.024657 [0x0000f2ffd700] DEBUG    dhcp_msg_dispatch:108: DHCPDISCOVER from unknown client HW MAC 18:a9:05:cb:c3:0a
03.10.2019 21:00:07.024661 [0x0000f2ffd700] DEBUG    dhcp_main:298: dhcp_msg_dispatch(0x7f43e40009f0) failed
03.10.2019 21:00:07.024668 [0x0000f2ffd700] DEBUG    dhcp_main:290: waiting for req
03.10.2019 21:00:15.024714 [0x0000f2ffd700] DEBUG    recv_udp_sock:91: IP_PKTINFO control data found
03.10.2019 21:00:15.024726 [0x0000f2ffd700] DEBUG    iface_by_index:108: lookup interface by index 5
03.10.2019 21:00:15.024740 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 53/0x35, type: 2, len: 01, value: u8 01 / 0x01
03.10.2019 21:00:15.024754 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 61/0x3D, type: 5, len: 07, value: HEX: 01 18 A9 05 CB C3 0A ASCII '.......' HEX:01 18 a9 05 cb c3 0a  proto unassigned
03.10.2019 21:00:15.024759 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 12/0x0C, type: 1, len: 13, value: 'Administrator'
03.10.2019 21:00:15.024764 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 60/0x3C, type: 1, len: 08, value: 'MSFT 5.0'
03.10.2019 21:00:15.024774 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 55/0x37, type: 5, len: 12, value: HEX: 01 0F 03 06 2C 2E 2F 1F 21 79 F9 2B ReqOp: 1 15 3 6 44 46 47 31 33 121 -7 43
03.10.2019 21:00:15.024787 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 82/0x52, type: 5, len: 18, value: HEX: 01 06 00 04 00 6F 00 03 02 08 00 06 34 08 04 64 49 84 ASCII '.....o......4..dI.'
03.10.2019 21:00:15.024797 [0x0000f2ffd700] DEBUG    Dump DHCP packet: op=1, htype=1, hlen=6, hops=0x00, xid=0xb44314ea, secs=12, flags=0x0000, ciaddr=0.0.0.0, yiaddr=0.0.0.0, siaddr=0.0.0.0, giaddr=0.0.0.0, chaddr=18:a9:, sname=, filename=, cookie=0x63825363, len=312, sin_addr=0.0.0.0, sin_port=0, client_sockaddr=(67, 0, 0.0.0.0), dhcp_nopt=6, client_hw_addr=e0:12:, client_dhcp_pkt_len_max=0, dhcp_req_type=NOT SET, dhcp_reply_type=NOT SET
03.10.2019 21:00:15.024810 [0x0000f2ffd700] DEBUG    dhcp_op82_parse:466: Op82 Circuit ID 006F0003:VLAN 111, Unit 0, Port 3 (l=4), Remote ID 340804644984 (l=6)
03.10.2019 21:00:15.024817 [0x0000f2ffd700] ERROR    dhcp_allocate_ip:4680: DHCP IP pool uninitialized lookup!
03.10.2019 21:00:15.024821 [0x0000f2ffd700] DEBUG    dhcp_msg_dispatch:108: DHCPDISCOVER from unknown client HW MAC 18:a9:05:cb:c3:0a
03.10.2019 21:00:15.024825 [0x0000f2ffd700] DEBUG    dhcp_main:298: dhcp_msg_dispatch(0x7f43e40009f0) failed
03.10.2019 21:00:15.024832 [0x0000f2ffd700] DEBUG    dhcp_main:290: waiting for req
03.10.2019 21:00:15.670105 [0x0000f27fc700] DEBUG    dhcp_pool_expire_ip:3722: req to free "(null)" but dhcp_ip_pool uninitialized
03.10.2019 21:00:15.670118 [0x0000f27fc700] DEBUG    dhcp_pool_expire_offer:3807: req to free but dhcp_ip_pool uninitialized
03.10.2019 21:00:25.670204 [0x0000f27fc700] DEBUG    dhcp_pool_expire_ip:3722: req to free "(null)" but dhcp_ip_pool uninitialized
03.10.2019 21:00:25.670216 [0x0000f27fc700] DEBUG    dhcp_pool_expire_offer:3807: req to free but dhcp_ip_pool uninitialized
03.10.2019 21:00:32.025196 [0x0000f2ffd700] DEBUG    recv_udp_sock:91: IP_PKTINFO control data found
03.10.2019 21:00:32.025209 [0x0000f2ffd700] DEBUG    iface_by_index:108: lookup interface by index 5
03.10.2019 21:00:32.025223 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 53/0x35, type: 2, len: 01, value: u8 01 / 0x01
03.10.2019 21:00:32.025238 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 61/0x3D, type: 5, len: 07, value: HEX: 01 18 A9 05 CB C3 0A ASCII '.......' HEX:01 18 a9 05 cb c3 0a  proto unassigned
03.10.2019 21:00:32.025244 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 12/0x0C, type: 1, len: 13, value: 'Administrator'
03.10.2019 21:00:32.025249 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 60/0x3C, type: 1, len: 08, value: 'MSFT 5.0'
03.10.2019 21:00:32.025259 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 55/0x37, type: 5, len: 12, value: HEX: 01 0F 03 06 2C 2E 2F 1F 21 79 F9 2B ReqOp: 1 15 3 6 44 46 47 31 33 121 -7 43
03.10.2019 21:00:32.025272 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 82/0x52, type: 5, len: 18, value: HEX: 01 06 00 04 00 6F 00 03 02 08 00 06 34 08 04 64 49 84 ASCII '.....o......4..dI.'
03.10.2019 21:00:32.025284 [0x0000f2ffd700] DEBUG    Dump DHCP packet: op=1, htype=1, hlen=6, hops=0x00, xid=0xb44314ea, secs=29, flags=0x0000, ciaddr=0.0.0.0, yiaddr=0.0.0.0, siaddr=0.0.0.0, giaddr=0.0.0.0, chaddr=18:a9:, sname=, filename=, cookie=0x63825363, len=312, sin_addr=0.0.0.0, sin_port=0, client_sockaddr=(67, 0, 0.0.0.0), dhcp_nopt=6, client_hw_addr=e0:12:, client_dhcp_pkt_len_max=0, dhcp_req_type=NOT SET, dhcp_reply_type=NOT SET
03.10.2019 21:00:32.025297 [0x0000f2ffd700] DEBUG    dhcp_op82_parse:466: Op82 Circuit ID 006F0003:VLAN 111, Unit 0, Port 3 (l=4), Remote ID 340804644984 (l=6)
03.10.2019 21:00:32.025304 [0x0000f2ffd700] ERROR    dhcp_allocate_ip:4680: DHCP IP pool uninitialized lookup!
03.10.2019 21:00:32.025309 [0x0000f2ffd700] DEBUG    dhcp_msg_dispatch:108: DHCPDISCOVER from unknown client HW MAC 18:a9:05:cb:c3:0a
03.10.2019 21:00:32.025313 [0x0000f2ffd700] DEBUG    dhcp_main:298: dhcp_msg_dispatch(0x7f43e40009f0) failed
03.10.2019 21:00:32.025319 [0x0000f2ffd700] DEBUG    dhcp_main:290: waiting for req
03.10.2019 21:00:35.670308 [0x0000f27fc700] DEBUG    dhcp_pool_expire_ip:3722: req to free "(null)" but dhcp_ip_pool uninitialized
03.10.2019 21:00:35.670320 [0x0000f27fc700] DEBUG    dhcp_pool_expire_offer:3807: req to free but dhcp_ip_pool uninitialized
03.10.2019 21:00:45.670414 [0x0000f27fc700] DEBUG    dhcp_pool_expire_ip:3722: req to free "(null)" but dhcp_ip_pool uninitialized
03.10.2019 21:00:45.670426 [0x0000f27fc700] DEBUG    dhcp_pool_expire_offer:3807: req to free but dhcp_ip_pool uninitialized
03.10.2019 21:00:55.670546 [0x0000f27fc700] DEBUG    dhcp_pool_expire_ip:3722: req to free "(null)" but dhcp_ip_pool uninitialized
03.10.2019 21:00:55.670568 [0x0000f27fc700] DEBUG    dhcp_pool_expire_offer:3807: req to free but dhcp_ip_pool uninitialized
03.10.2019 21:01:04.284100 [0x0000f2ffd700] DEBUG    recv_udp_sock:91: IP_PKTINFO control data found
03.10.2019 21:01:04.284112 [0x0000f2ffd700] DEBUG    iface_by_index:108: lookup interface by index 5
03.10.2019 21:01:04.284126 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 53/0x35, type: 2, len: 01, value: u8 01 / 0x01
03.10.2019 21:01:04.284140 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 61/0x3D, type: 5, len: 07, value: HEX: 01 18 A9 05 CB C3 0A ASCII '.......' HEX:01 18 a9 05 cb c3 0a  proto unassigned
03.10.2019 21:01:04.284146 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 12/0x0C, type: 1, len: 13, value: 'Administrator'
03.10.2019 21:01:04.284151 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 60/0x3C, type: 1, len: 08, value: 'MSFT 5.0'
03.10.2019 21:01:04.284162 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 55/0x37, type: 5, len: 12, value: HEX: 01 0F 03 06 2C 2E 2F 1F 21 79 F9 2B ReqOp: 1 15 3 6 44 46 47 31 33 121 -7 43
03.10.2019 21:01:04.284175 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 82/0x52, type: 5, len: 18, value: HEX: 01 06 00 04 00 6F 00 03 02 08 00 06 34 08 04 64 49 84 ASCII '.....o......4..dI.'
03.10.2019 21:01:04.284186 [0x0000f2ffd700] DEBUG    Dump DHCP packet: op=1, htype=1, hlen=6, hops=0x00, xid=0x9fa960eb, secs=0, flags=0x0080, ciaddr=0.0.0.0, yiaddr=0.0.0.0, siaddr=0.0.0.0, giaddr=0.0.0.0, chaddr=18:a9:, sname=, filename=, cookie=0x63825363, len=312, sin_addr=0.0.0.0, sin_port=0, client_sockaddr=(67, 0, 0.0.0.0), dhcp_nopt=6, client_hw_addr=e0:12:, client_dhcp_pkt_len_max=0, dhcp_req_type=NOT SET, dhcp_reply_type=NOT SET
03.10.2019 21:01:04.284200 [0x0000f2ffd700] DEBUG    dhcp_op82_parse:466: Op82 Circuit ID 006F0003:VLAN 111, Unit 0, Port 3 (l=4), Remote ID 340804644984 (l=6)
03.10.2019 21:01:04.284207 [0x0000f2ffd700] ERROR    dhcp_allocate_ip:4680: DHCP IP pool uninitialized lookup!
03.10.2019 21:01:04.284212 [0x0000f2ffd700] DEBUG    dhcp_msg_dispatch:108: DHCPDISCOVER from unknown client HW MAC 18:a9:05:cb:c3:0a
03.10.2019 21:01:04.284216 [0x0000f2ffd700] DEBUG    dhcp_main:298: dhcp_msg_dispatch(0x7f43e40009f0) failed
03.10.2019 21:01:04.284223 [0x0000f2ffd700] DEBUG    dhcp_main:290: waiting for req
03.10.2019 21:01:05.670643 [0x0000f27fc700] DEBUG    dhcp_pool_expire_ip:3722: req to free "(null)" but dhcp_ip_pool uninitialized
03.10.2019 21:01:05.670664 [0x0000f27fc700] DEBUG    dhcp_pool_expire_offer:3807: req to free but dhcp_ip_pool uninitialized
03.10.2019 21:01:07.357124 [0x0000f2ffd700] DEBUG    recv_udp_sock:91: IP_PKTINFO control data found
03.10.2019 21:01:07.357136 [0x0000f2ffd700] DEBUG    iface_by_index:108: lookup interface by index 5
03.10.2019 21:01:07.357150 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 53/0x35, type: 2, len: 01, value: u8 01 / 0x01
03.10.2019 21:01:07.357165 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 61/0x3D, type: 5, len: 07, value: HEX: 01 18 A9 05 CB C3 0A ASCII '.......' HEX:01 18 a9 05 cb c3 0a  proto unassigned
03.10.2019 21:01:07.357171 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 12/0x0C, type: 1, len: 13, value: 'Administrator'
03.10.2019 21:01:07.357176 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 60/0x3C, type: 1, len: 08, value: 'MSFT 5.0'
03.10.2019 21:01:07.357187 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 55/0x37, type: 5, len: 12, value: HEX: 01 0F 03 06 2C 2E 2F 1F 21 79 F9 2B ReqOp: 1 15 3 6 44 46 47 31 33 121 -7 43
03.10.2019 21:01:07.357200 [0x0000f2ffd700] DEBUG    dhcp_option_print:233: DHCP Op: 82/0x52, type: 5, len: 18, value: HEX: 01 06 00 04 00 6F 00 03 02 08 00 06 34 08 04 64 49 84 ASCII '.....o......4..dI.'
03.10.2019 21:01:07.357211 [0x0000f2ffd700] DEBUG    Dump DHCP packet: op=1, htype=1, hlen=6, hops=0x00, xid=0x9fa960eb, secs=3, flags=0x0080, ciaddr=0.0.0.0, yiaddr=0.0.0.0, siaddr=0.0.0.0, giaddr=0.0.0.0, chaddr=18:a9:, sname=, filename=, cookie=0x63825363, len=312, sin_addr=0.0.0.0, sin_port=0, client_sockaddr=(67, 0, 0.0.0.0), dhcp_nopt=6, client_hw_addr=e0:12:, client_dhcp_pkt_len_max=0, dhcp_req_type=NOT SET, dhcp_reply_type=NOT SET
03.10.2019 21:01:07.357225 [0x0000f2ffd700] DEBUG    dhcp_op82_parse:466: Op82 Circuit ID 006F0003:VLAN 111, Unit 0, Port 3 (l=4), Remote ID 340804644984 (l=6)
03.10.2019 21:01:07.357232 [0x0000f2ffd700] ERROR    dhcp_allocate_ip:4680: DHCP IP pool uninitialized lookup!
03.10.2019 21:01:07.357237 [0x0000f2ffd700] DEBUG    dhcp_msg_dispatch:108: DHCPDISCOVER from unknown client HW MAC 18:a9:05:cb:c3:0a
03.10.2019 21:01:07.357241 [0x0000f2ffd700] DEBUG    dhcp_main:298: dhcp_msg_dispatch(0x7f43e40009f0) failed
03.10.2019 21:01:07.357248 [0x0000f2ffd700] DEBUG    dhcp_main:290: waiting for req
03.10.2019 21:01:15.357417 [0x0000f2ffd700] DEBUG    recv_udp_sock:91: IP_PKTINFO control data found


accel-ppp
Спойлер
.[1;32m[2019-10-03 21:01:15]:  info: eth0.111: .[0;39mrecv [DHCPv4 Discover xid=9fa960eb chaddr=18:a9:05:cb:c3:0a <Message-Type Discover> <Client-ID 0118a905cbc30a> <Host-Name Administrator> <Vendo
.[1;32m[2019-10-03 21:01:15]:  info: ipoe0: .[0;39mcreate interface ipoe0 parent eth0.111
.[1;32m[2019-10-03 21:01:15]:  info: ipoe0: .[0;39msend [RADIUS(1) Access-Request id=1 <User-Name "18:a9:05:cb:c3:0a"> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200> <NAS-Port 548> <
.[1;32m[2019-10-03 21:01:15]:  info: ipoe0: .[0;39mrecv [RADIUS(1) Access-Accept id=1 <Session-Timeout 86400> <Service-Type Framed-User> <Framed-Protocol PPP> <Framed-IP-Address 10.11.0.8> <Framed-
.[1;32m[2019-10-03 21:01:15]:  info: ipoe0: .[0;39m18:a9:05:cb:c3:0a: authentication succeeded
.[1;31m[2019-10-03 21:01:15]: error: ipoe0: .[0;39mcan't determine router address
.[1;34m[2019-10-03 21:01:15]: debug: ipoe0: .[0;39mterminate
.[1;32m[2019-10-03 21:01:15]:  info: ipoe0: .[0;39mipoe: session finished
.[1;32m[2019-10-03 21:01:30]:  info: eth0.111: .[0;39mrecv [DHCPv4 Discover xid=9fa960eb chaddr=18:a9:05:cb:c3:0a <Message-Type Discover> <Client-ID 0118a905cbc30a> <Host-Name Administrator> <Vendo
.[1;32m[2019-10-03 21:01:30]:  info: ipoe0: .[0;39mcreate interface ipoe0 parent eth0.111
.[1;32m[2019-10-03 21:01:30]:  info: ipoe0: .[0;39msend [RADIUS(1) Access-Request id=1 <User-Name "18:a9:05:cb:c3:0a"> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200> <NAS-Port 549> <
.[1;32m[2019-10-03 21:01:30]:  info: ipoe0: .[0;39mrecv [RADIUS(1) Access-Reject id=1]
.[1;34m[2019-10-03 21:01:30]: debug: ipoe0: .[0;39mterminate
.[1;32m[2019-10-03 21:01:30]:  info: ipoe0: .[0;39mipoe: session finished
tcpdump
Спойлер
tcpdump -i eth0.111 port 67 or port 68 -nn -vvv
tcpdump: listening on eth0.111, link-type EN10MB (Ethernet), capture size 65535 bytes

21:23:14.989346 IP (tos 0x0, ttl 128, id 2791, offset 0, flags [none], proto UDP (17), length 340)
0.0.0.0.68 > 255.255.255.255.67: [udp sum ok] BOOTP/DHCP, Request from 18:a9:05:cb:c3:0a, length 312, xid 0x230c13a9, secs 1280, Flags [none] (0x0000)
Client-Ethernet-Address 18:a9:05:cb:c3:0a
Vendor-rfc1048 Extensions
Magic Cookie 0x63825363
DHCP-Message Option 53, length 1: Discover
Client-ID Option 61, length 7: ether 18:a9:05:cb:c3:0a
Hostname Option 12, length 13: "Administrator"
Vendor-Class Option 60, length 8: "MSFT 5.0"
Parameter-Request Option 55, length 12:
Subnet-Mask, Domain-Name, Default-Gateway, Domain-Name-Server
Netbios-Name-Server, Netbios-Node, Netbios-Scope, Router-Discovery
Static-Route, Classless-Static-Route, Classless-Static-Route-Microsoft, Vendor-Option
Agent-Information Option 82, length 18:
Circuit-ID SubOption 1, length 6: ^@^D^@o^@^C
Remote-ID SubOption 2, length 8: ^@^F4^H^DdIM-^D
END Option 255, length 0

21:23:22.894645 IP (tos 0x0, ttl 128, id 2866, offset 0, flags [none], proto UDP (17), length 340)
0.0.0.0.68 > 255.255.255.255.67: [udp sum ok] BOOTP/DHCP, Request from 18:a9:05:cb:c3:0a, length 312, xid 0x230c13a9, secs 3328, Flags [none] (0x0000)
Client-Ethernet-Address 18:a9:05:cb:c3:0a
Vendor-rfc1048 Extensions
Magic Cookie 0x63825363
DHCP-Message Option 53, length 1: Discover
Client-ID Option 61, length 7: ether 18:a9:05:cb:c3:0a
Hostname Option 12, length 13: "Administrator"
Vendor-Class Option 60, length 8: "MSFT 5.0"
Parameter-Request Option 55, length 12:
Subnet-Mask, Domain-Name, Default-Gateway, Domain-Name-Server
Netbios-Name-Server, Netbios-Node, Netbios-Scope, Router-Discovery
Static-Route, Classless-Static-Route, Classless-Static-Route-Microsoft, Vendor-Option
Agent-Information Option 82, length 18:
Circuit-ID SubOption 1, length 6: ^@^D^@o^@^C
Remote-ID SubOption 2, length 8: ^@^F4^H^DdIM-^D
END Option 255, length 0
Однако, дело дальше не идёт, клиенту выдаётся, но так и не назначается IP адрес. Биллинг фиксирует успешную авторизацию, однако более ни где нет подтверждения того, что сессия жива. Ни на accel-ppp, ни в биллинге.

Идеи в голову не прилетают, вопрос открыт, копаю дальше.

dimka88
Posts: 711
Joined: 13 Oct 2014, 05:51
Contact:

Re: IPoE+L2+dhcp+opt82 (dhcp_local_relay)

Post by dimka88 » 03 Oct 2019, 18:46

Нужно добавить в accel-ppp.conf gw-ip-address

Code: Select all

[ipoe]
gw-ip-address=10.11.0.1/19
Хотя в первом посте был указан. Второй вариант это отправить DHCP-Router-IP-Address радиусом.
Запись в логе "can't determine router address" говорит, что не смог найти gw-ip-addres, что очень странно если он указан.

baronzzz
Posts: 22
Joined: 22 Sep 2019, 12:01

Re: IPoE+L2+dhcp+opt82 (dhcp_local_relay)

Post by baronzzz » 04 Oct 2019, 01:24

dimka88 wrote:
03 Oct 2019, 18:46
Нужно добавить в accel-ppp.conf gw-ip-address

Code: Select all

[ipoe]
gw-ip-address=10.11.0.1/19
Хотя в первом посте был указан. Второй вариант это отправить DHCP-Router-IP-Address радиусом.
Запись в логе "can't determine router address" говорит, что не смог найти gw-ip-addres, что очень странно если он указан.
Спасибо за ответ.
Вчера вечером добавил некоторые параметры, клиент стал получать ип, однако напоролся на новые проблемы. Сэссия не обновляется, а прерывается достигнув максимального значения max-lease, потом происходит переавторизация.

accel-ppp debug.log
Спойлер
[2019-10-03 22:07:49.111] ipoe: start interface eth0.111 ()
[2019-10-03 22:07:49.121] send [RADIUS(1) Accounting-Request id=1 <Acct-Status-Type Accounting-On> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200>]
[2019-10-03 22:07:49.122] recv [RADIUS(1) Accounting-Response id=1]
[2019-10-03 22:08:24.082] eth0.111: : recv [DHCPv4 Discover xid=76b96bd5 chaddr=18:a9:05:cb:c3:0a <Message-Type Discover> <Client-ID 0118a905cbc30a> <Host-Name Administrator> <Vendor-Class 4d53465420352e30> <Request-List Subnet,Domain-Na
[2019-10-03 22:08:24.083] ipoe0: 774dcff2ac4a057d: create interface ipoe0 parent eth0.111
[2019-10-03 22:08:24.084] ipoe0: 774dcff2ac4a057d: send [RADIUS(1) Access-Request id=1 <User-Name "18:a9:05:cb:c3:0a"> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200> <NAS-Port 573> <NAS-Port-Id "ipoe0"> <NAS-Port-Type Ethe
[2019-10-03 22:08:24.101] ipoe0: 774dcff2ac4a057d: recv [RADIUS(1) Access-Accept id=1 <Session-Timeout 900> <Service-Type Framed-User> <Framed-Protocol PPP> <Framed-IP-Address 10.11.0.8> <Framed-IP-Netmask 255.255.255.255> <Class 0x30323
[2019-10-03 22:08:24.101] ipoe0: 774dcff2ac4a057d: 18:a9:05:cb:c3:0a: authentication succeeded
[2019-10-03 22:08:24.101] ipoe0: 774dcff2ac4a057d: send [DHCPv4 Offer xid=76b96bd5 yiaddr=10.11.0.8 chaddr=18:a9:05:cb:c3:0a <Message-Type Offer> <Server-ID 10.11.0.1> <Lease-Time 300> <T1 150> <Router 10.11.0.1> <Subnet 255.255.255.0> <
[2019-10-03 22:08:24.106] ipoe0: 774dcff2ac4a057d: recv [DHCPv4 Request xid=76b96bd5 chaddr=18:a9:05:cb:c3:0a <Message-Type Request> <Client-ID 0118a905cbc30a> <Request-IP 10.11.0.8> <Server-ID 10.11.0.1> <Host-Name Administrator> <Optio
[2019-10-03 22:08:24.106] ipoe0: 774dcff2ac4a057d: ipoe: activate session
[2019-10-03 22:08:24.107] ipoe0: 774dcff2ac4a057d: send [RADIUS(1) Accounting-Request id=1 <User-Name "18:a9:05:cb:c3:0a"> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200> <NAS-Port 573> <NAS-Port-Id "ipoe0"> <NAS-Port-Type
[2019-10-03 22:08:24.107] ipoe0: 774dcff2ac4a057d: send [DHCPv4 Ack xid=76b96bd5 yiaddr=10.11.0.8 chaddr=18:a9:05:cb:c3:0a <Message-Type Ack> <Server-ID 10.11.0.1> <Lease-Time 300> <T1 150> <Router 10.11.0.1> <Subnet 255.255.255.0> <DNS
[2019-10-03 22:08:24.112] ipoe0: 774dcff2ac4a057d: recv [RADIUS(1) Accounting-Response id=1]
[2019-10-03 22:08:24.113] ipoe0: 774dcff2ac4a057d: ipoe: session started
[2019-10-03 22:08:47.921] cli: telnet: new connection from 127.0.0.1
[2019-10-03 22:11:39.169] cli: disconnect
[2019-10-03 22:13:30.645] ipoe0: 774dcff2ac4a057d: recv [DHCPv4 Discover xid=9b5d4c5b chaddr=18:a9:05:cb:c3:0a <Message-Type Discover> <Client-ID 0118a905cbc30a> <Request-IP 10.11.0.8> <Host-Name Administrator> <Vendor-Class 4d5346542035
[2019-10-03 22:13:30.645] ipoe0: 774dcff2ac4a057d: send [DHCPv4 Offer xid=9b5d4c5b yiaddr=10.11.0.8 chaddr=18:a9:05:cb:c3:0a <Message-Type Offer> <Server-ID 10.11.0.1> <Lease-Time 300> <T1 150> <Router 10.11.0.1> <Subnet 255.255.255.0> <
[2019-10-03 22:13:30.651] ipoe0: 774dcff2ac4a057d: recv [DHCPv4 Request xid=9b5d4c5b chaddr=18:a9:05:cb:c3:0a <Message-Type Request> <Client-ID 0118a905cbc30a> <Request-IP 10.11.0.8> <Server-ID 10.11.0.1> <Host-Name Administrator> <Optio
[2019-10-03 22:13:30.651] ipoe0: 774dcff2ac4a057d: send [DHCPv4 Ack xid=9b5d4c5b yiaddr=10.11.0.8 chaddr=18:a9:05:cb:c3:0a <Message-Type Ack> <Server-ID 10.11.0.1> <Lease-Time 300> <T1 150> <Router 10.11.0.1> <Subnet 255.255.255.0> <DNS
[2019-10-03 22:14:16.055] cli: telnet: new connection from 127.0.0.1
[2019-10-03 22:18:36.880] ipoe0: 774dcff2ac4a057d: recv [DHCPv4 Discover xid=e57f7f0c chaddr=18:a9:05:cb:c3:0a <Message-Type Discover> <Client-ID 0118a905cbc30a> <Request-IP 10.11.0.8> <Host-Name Administrator> <Vendor-Class 4d5346542035
[2019-10-03 22:18:36.880] ipoe0: 774dcff2ac4a057d: send [DHCPv4 Offer xid=e57f7f0c yiaddr=10.11.0.8 chaddr=18:a9:05:cb:c3:0a <Message-Type Offer> <Server-ID 10.11.0.1> <Lease-Time 300> <T1 150> <Router 10.11.0.1> <Subnet 255.255.255.0> <
[2019-10-03 22:18:36.886] ipoe0: 774dcff2ac4a057d: recv [DHCPv4 Request xid=e57f7f0c chaddr=18:a9:05:cb:c3:0a <Message-Type Request> <Client-ID 0118a905cbc30a> <Request-IP 10.11.0.8> <Server-ID 10.11.0.1> <Host-Name Administrator> <Optio
[2019-10-03 22:18:36.886] ipoe0: 774dcff2ac4a057d: send [DHCPv4 Ack xid=e57f7f0c yiaddr=10.11.0.8 chaddr=18:a9:05:cb:c3:0a <Message-Type Ack> <Server-ID 10.11.0.1> <Lease-Time 300> <T1 150> <Router 10.11.0.1> <Subnet 255.255.255.0> <DNS
[2019-10-03 22:23:24.107] ipoe0: 774dcff2ac4a057d: session timeout
[2019-10-03 22:23:24.107] ipoe0: 774dcff2ac4a057d: terminate
[2019-10-03 22:23:24.109] ipoe0: 774dcff2ac4a057d: send [RADIUS(1) Accounting-Request id=6 <User-Name "18:a9:05:cb:c3:0a"> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200> <NAS-Port 573> <NAS-Port-Id "ipoe0"> <NAS-Port-Type
[2019-10-03 22:23:24.110] ipoe0: 774dcff2ac4a057d: ipoe: session finished
[2019-10-03 22:23:24.111] recv [RADIUS(1) Accounting-Response id=6]
[2019-10-03 22:23:32.177] eth0.111: recv [DHCPv4 Request xid=b67a2494 ciaddr=10.11.0.8 chaddr=18:a9:05:cb:c3:0a <Message-Type Request> <Client-ID 0118a905cbc30a> <Host-Name Administrator> <Option-81 00000041646d696e6973747261746f72> <Ven
[2019-10-03 22:23:32.177] send [DHCPv4 Nak xid=b67a2494 chaddr=18:a9:05:cb:c3:0a <Message-Type Nak>]
[2019-10-03 22:23:32.301] eth0.111: : recv [DHCPv4 Discover xid=2c2c7e5f chaddr=18:a9:05:cb:c3:0a <Message-Type Discover> <Client-ID 0118a905cbc30a> <Host-Name Administrator> <Vendor-Class 4d53465420352e30> <Request-List Subnet,Domain-Na
[2019-10-03 22:23:32.302] ipoe0: 774dcff2ac4a057e: create interface ipoe0 parent eth0.111
[2019-10-03 22:23:32.302] ipoe0: 774dcff2ac4a057e: send [RADIUS(1) Access-Request id=1 <User-Name "18:a9:05:cb:c3:0a"> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200> <NAS-Port 574> <NAS-Port-Id "ipoe0"> <NAS-Port-Type Ethe
[2019-10-03 22:23:32.312] ipoe0: 774dcff2ac4a057e: recv [RADIUS(1) Access-Accept id=1 <Session-Timeout 900> <Service-Type Framed-User> <Framed-Protocol PPP> <Framed-IP-Address 10.11.0.8> <Framed-IP-Netmask 255.255.255.255> <Class 0x34366
[2019-10-03 22:23:32.312] ipoe0: 774dcff2ac4a057e: 18:a9:05:cb:c3:0a: authentication succeeded
[2019-10-03 22:23:32.312] ipoe0: 774dcff2ac4a057e: send [DHCPv4 Offer xid=2c2c7e5f yiaddr=10.11.0.8 chaddr=18:a9:05:cb:c3:0a <Message-Type Offer> <Server-ID 10.11.0.1> <Lease-Time 300> <T1 150> <Router 10.11.0.1> <Subnet 255.255.255.0> <
[2019-10-03 22:23:32.320] ipoe0: 774dcff2ac4a057e: recv [DHCPv4 Request xid=2c2c7e5f chaddr=18:a9:05:cb:c3:0a <Message-Type Request> <Client-ID 0118a905cbc30a> <Request-IP 10.11.0.8> <Server-ID 10.11.0.1> <Host-Name Administrator> <Optio
[2019-10-03 22:23:32.320] ipoe0: 774dcff2ac4a057e: ipoe: activate session
[2019-10-03 22:23:32.320] ipoe0: 774dcff2ac4a057e: send [RADIUS(1) Accounting-Request id=1 <User-Name "18:a9:05:cb:c3:0a"> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200> <NAS-Port 574> <NAS-Port-Id "ipoe0"> <NAS-Port-Type
[2019-10-03 22:23:32.321] ipoe0: 774dcff2ac4a057e: send [DHCPv4 Ack xid=2c2c7e5f yiaddr=10.11.0.8 chaddr=18:a9:05:cb:c3:0a <Message-Type Ack> <Server-ID 10.11.0.1> <Lease-Time 300> <T1 150> <Router 10.11.0.1> <Subnet 255.255.255.0> <DNS
[2019-10-03 22:23:32.323] ipoe0: 774dcff2ac4a057e: recv [RADIUS(1) Accounting-Response id=1]
[2019-10-03 22:23:32.323] ipoe0: 774dcff2ac4a057e: ipoe: session started
[2019-10-03 22:23:42.490] cli: disconnect
[2019-10-03 22:24:23.658] cli: telnet: new connection from 127.0.0.1
[2019-10-03 22:24:27.571] ipoe0: 774dcff2ac4a057e: terminate
[2019-10-03 22:24:27.573] ipoe0: 774dcff2ac4a057e: send [RADIUS(1) Accounting-Request id=1 <User-Name "18:a9:05:cb:c3:0a"> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200> <NAS-Port 574> <NAS-Port-Id "ipoe0"> <NAS-Port-Type
[2019-10-03 22:24:27.574] ipoe0: 774dcff2ac4a057e: ipoe: session finished
[2019-10-03 22:24:27.584] terminate, sig = 15
[2019-10-03 22:24:27.584] cli: disconnect
[2019-10-03 22:24:27.586] ipoe: stop interface eth0.111
[2019-10-03 22:24:30.574] timeout 0x7efc600008d8
[2019-10-03 22:24:30.574] send [RADIUS(1) Accounting-Request id=1 <User-Name "18:a9:05:cb:c3:0a"> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200> <NAS-Port 574> <NAS-Port-Id "ipoe0"> <NAS-Port-Type Ethernet> <Calling-Statio
[2019-10-03 22:24:33.574] timeout 0x7efc600008d8
[2019-10-03 22:24:33.574] send [RADIUS(1) Accounting-Request id=1 <User-Name "18:a9:05:cb:c3:0a"> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200> <NAS-Port 574> <NAS-Port-Id "ipoe0"> <NAS-Port-Type Ethernet> <Calling-Statio
[2019-10-03 22:24:36.574] timeout 0x7efc600008d8
[2019-10-03 22:24:36.574] send [RADIUS(1) Accounting-Request id=1 <Acct-Status-Type Accounting-Off> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200>]
[2019-10-03 22:24:39.574] send [RADIUS(1) Accounting-Request id=1 <Acct-Status-Type Accounting-Off> <NAS-Identifier "accel-ppp"> <NAS-IP-Address 192.168.200.200>]

baronzzz
Posts: 22
Joined: 22 Sep 2019, 12:01

Re: IPoE+L2+dhcp+opt82 (dhcp_local_relay)

Post by baronzzz » 04 Oct 2019, 03:01

LBarcd.log
Спойлер
03.10.2019 22:08:24.084295 VERBOSE LWP10300 [src/radius_base.cpp:56] ============== Authorization packet #1 received from 192.168.200.200, size: 174 ==============
03.10.2019 22:08:24.084517 VERBOSE LWP10300 [src/radius_record.cpp:90] Access-Request (1), id: 0x1, length: 174
03.10.2019 22:08:24.084554 VERBOSE LWP10300 [src/radius_record.cpp:108] Authenticator: 7be23c2bfe01c5142e46e31ca2e189be
03.10.2019 22:08:24.084573 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:08:24.084586 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 22:08:24.084595 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 22:08:24.084608 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "573"
03.10.2019 22:08:24.084619 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 22:08:24.084627 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 22:08:24.084635 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:08:24.084642 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 22:08:24.084651 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 22:08:24.084669 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 22:08:24.084679 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac4a057d"
03.10.2019 22:08:24.084693 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Password", value: "248a3c51bc80c06a205033b951cdd3344bf754771639de2edf059b3f2c93efb5"
03.10.2019 22:08:24.084711 VERBOSE LWP10300 [src/radius_record.cpp:186] User-Password = "18:a9:05:cb:c3:0a"
03.10.2019 22:08:24.084723 VERBOSE LWP10300 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 22:08:24.085307 VERBOSE LWP10300 [src/radius_packet.cpp:652] Trying to authorize user by Opt82 params: "340804644984", 3
03.10.2019 22:08:24.086459 INFO LWP10300 [src/radius_packet.cpp:896] Auth by 'opt82' ok: [1], Session-Id 774dcff2ac4a057d
03.10.2019 22:08:24.089863 VERBOSE LWP10300 [src/radius_packet.cpp:1163] ANI '18:a9:05:cb:c3:0a' (User '18:a9:05:cb:c3:0a') is clean
03.10.2019 22:08:24.090363 VERBOSE LWP10300 [src/radius_packet.cpp:1074] User: '1234', bill by traffic, unlimited session timeout (900)
03.10.2019 22:08:24.094785 WARNING LWP10300 [src/radius.cpp:2062] ANI '18:a9:05:cb:c3:0a' is bound to 10.11.0.8/255.255.255.255 for user '18:a9:05:cb:c3:0a'
03.10.2019 22:08:24.095048 VERBOSE LWP10300 [src/radius.cpp:2144] Client IP/Netmask: 10.11.0.8/255.255.255.255, ANI: "18:a9:05:cb:c3:0a"
03.10.2019 22:08:24.095069 WARNING LWP10300 [src/radius.cpp:536] Unable to allocate delegated prefix
03.10.2019 22:08:24.095075 WARNING LWP10300 [src/radius.cpp:538] Unable to allocate framed prefix
03.10.2019 22:08:24.095086 INFO LWP10300 [src/radius.cpp:609] Access-Accept, <18:a9:05:cb:c3:0a> [1], Session-Id 774dcff2ac4a057d
03.10.2019 22:08:24.095091 VERBOSE LWP10300 [src/radius.cpp:612] =============== Output attributes dump: ===============
03.10.2019 22:08:24.095106 VERBOSE LWP10300 [src/radius.cpp:706] Attribute "Session-Timeout", value: "900"
03.10.2019 22:08:24.095114 VERBOSE LWP10300 [src/radius.cpp:711] Attribute "Service-Type", value: "2"
03.10.2019 22:08:24.095121 VERBOSE LWP10300 [src/radius.cpp:715] Attribute "Framed-Protocol", value: "1"
03.10.2019 22:08:24.095131 VERBOSE LWP10300 [src/radius.cpp:726] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 22:08:24.095139 VERBOSE LWP10300 [src/radius.cpp:746] Attribute "Framed-IP-Netmask", value: "255.255.255.255"
03.10.2019 22:08:24.096280 VERBOSE LWP10300 [src/radius.cpp:756] Attribute "Class", tag: "125", value: "026404d4-2481-4f7d-87bc-f40ce75830e3/1"
03.10.2019 22:08:24.096340 VERBOSE LWP10300 [src/radius.cpp:799] Attribute "Acct-Interim-Interval", value: "150"
03.10.2019 22:08:24.096355 VERBOSE LWP10300 [src/radius.cpp:820] INSERT INTO CACHE NAS_IP_ADDRESS: 192.168.200.200; UUID(session_id): 774dcff2ac4a057d
03.10.2019 22:08:24.101185 WARNING LWP10300 [src/radius.cpp:879] Packet received from MAC = '18:a9:05:cb:c3:0a' while another MAC = '18:a9:05:cb:c3:0a' is assigned to vg_id = 1
03.10.2019 22:08:24.101223 VERBOSE LWP10300 [src/radius_record.cpp:90] Access-Accept (2), id: 0x1, length: 96
03.10.2019 22:08:24.101267 VERBOSE LWP10300 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Authentication answer sent successfully, time: 16 <=<=<=<=<=<=<=<
03.10.2019 22:08:24.107614 VERBOSE LWP10301 [src/radius_base.cpp:56] ============== Accounting packet #2 received from 192.168.200.200, size: 240 ==============
03.10.2019 22:08:24.107652 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Request (4), id: 0x1, length: 240
03.10.2019 22:08:24.107668 VERBOSE LWP10301 [src/radius_record.cpp:108] Authenticator: 887b6e5682b631760b2d6cd2092d1226
03.10.2019 22:08:24.107678 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:08:24.107686 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 22:08:24.107694 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 22:08:24.107701 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "573"
03.10.2019 22:08:24.107707 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 22:08:24.107713 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 22:08:24.107720 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:08:24.107727 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 22:08:24.107733 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Class", value: "026404d4-2481-4f7d-87bc-f40ce75830e3/1"
03.10.2019 22:08:24.107741 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 22:08:24.107750 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 22:08:24.107757 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Status-Type", value: "1"
03.10.2019 22:08:24.107770 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Authentic", value: "1"
03.10.2019 22:08:24.107776 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac4a057d"
03.10.2019 22:08:24.107782 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Time", value: "0"
03.10.2019 22:08:24.107788 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Octets", value: "0"
03.10.2019 22:08:24.107794 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Octets", value: "0"
03.10.2019 22:08:24.107799 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Packets", value: "0"
03.10.2019 22:08:24.107805 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Packets", value: "0"
03.10.2019 22:08:24.107811 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Gigawords", value: "0"
03.10.2019 22:08:24.107817 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Gigawords", value: "0"
03.10.2019 22:08:24.107824 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 22:08:24.107834 VERBOSE LWP10301 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 22:08:24.107879 INFO LWP10301 [src/radius.cpp:2624] Acct-Status-Type = START
03.10.2019 22:08:24.107895 INFO LWP10301 [src/radius.cpp:2661] Acct START, Session-Id 774dcff2ac4a057d
03.10.2019 22:08:24.107925 VERBOSE LWP10301 [src/radius.cpp:2680] No record with SessionID = '774dcff2ac4a057d' found in cache
03.10.2019 22:08:24.112128 VERBOSE LWP10301 [src/radius.cpp:2696] Looking for auth session: NAS_IP_ADDRESS: 192.168.200.200; UUID(session_id): 774dcff2ac4a057d;
03.10.2019 22:08:24.112151 VERBOSE LWP10301 [src/radius.cpp:2699] FOUND IN AUTH CACHE!
03.10.2019 22:08:24.112160 INFO LWP10301 [src/radius.cpp:2745] Starting Handler:ScriptStart for 18:a9:05:cb:c3:0a
03.10.2019 22:08:24.112439 VERBOSE LWP10301 [src/radius.cpp:2774] End DRadius::RunAcctRequestInst
03.10.2019 22:08:24.112458 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Response (5), id: 0x1, length: 20
03.10.2019 22:08:24.112500 VERBOSE LWP10301 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Accounting answer sent successfully, time: 4 <=<=<=<=<=<=<=<
03.10.2019 22:08:59.190435 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:08:59.229842 VERBOSE LWP10299 [src/radius.cpp:2939] Start billing sessions
03.10.2019 22:08:59.229871 VERBOSE LWP10299 [src/radius_session.cpp:753] Put data to DB for sessions <774dcff2ac4a057d>
03.10.2019 22:08:59.254918 VERBOSE LWP10297 [src/radius.cpp:1762] Flush is done
03.10.2019 22:09:58.138244 VERBOSE LWP10293 [src/shaper.cpp:59] Calculating shape is finished. Elapsed 4 ms
03.10.2019 22:10:00.260274 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:10:54.113392 VERBOSE LWP10301 [src/radius_base.cpp:56] ============== Accounting packet #3 received from 192.168.200.200, size: 240 ==============
03.10.2019 22:10:54.113505 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Request (4), id: 0x2, length: 240
03.10.2019 22:10:54.113525 VERBOSE LWP10301 [src/radius_record.cpp:108] Authenticator: c045bd9335d9cf53d5d3db2bd9ede4b4
03.10.2019 22:10:54.113566 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:10:54.113576 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 22:10:54.113593 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 22:10:54.113601 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "573"
03.10.2019 22:10:54.113609 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 22:10:54.113616 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 22:10:54.113623 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:10:54.113631 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 22:10:54.113639 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Class", value: "026404d4-2481-4f7d-87bc-f40ce75830e3/1"
03.10.2019 22:10:54.113648 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 22:10:54.113660 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 22:10:54.113667 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Status-Type", value: "3"
03.10.2019 22:10:54.113674 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Authentic", value: "1"
03.10.2019 22:10:54.113682 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac4a057d"
03.10.2019 22:10:54.113689 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Time", value: "150"
03.10.2019 22:10:54.113695 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Octets", value: "68184"
03.10.2019 22:10:54.113702 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Octets", value: "16238"
03.10.2019 22:10:54.113709 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Packets", value: "583"
03.10.2019 22:10:54.113716 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Packets", value: "155"
03.10.2019 22:10:54.113722 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Gigawords", value: "0"
03.10.2019 22:10:54.113729 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Gigawords", value: "0"
03.10.2019 22:10:54.113737 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 22:10:54.113749 VERBOSE LWP10301 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 22:10:54.113814 INFO LWP10301 [src/radius.cpp:2624] Acct-Status-Type = UPDATE
03.10.2019 22:10:54.113827 VERBOSE LWP10301 [src/radius.cpp:2685] Record with SessionID = '774dcff2ac4a057d' found in cache
03.10.2019 22:10:54.113839 VERBOSE LWP10301 [src/radius.cpp:2790] End DRadius::RunAcctRequestInst
03.10.2019 22:10:54.113847 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Response (5), id: 0x2, length: 20
03.10.2019 22:10:54.113889 VERBOSE LWP10301 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Accounting answer sent successfully, time: 0 <=<=<=<=<=<=<=<
03.10.2019 22:11:01.265609 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:11:01.304890 VERBOSE LWP10299 [src/radius.cpp:2939] Start billing sessions
03.10.2019 22:11:01.304913 VERBOSE LWP10299 [src/radius_session.cpp:753] Put data to DB for sessions <774dcff2ac4a057d>
03.10.2019 22:11:01.305522 VERBOSE LWP10299 [src/radius_session.cpp:773] Put data to DB for session <774dcff2ac4a057d>
03.10.2019 22:11:01.307527 VERBOSE LWP10299 [src/radius_session.cpp:881] Vg_id: 1, Source tariff 1, category 0: units included = 0, above price = 0
03.10.2019 22:11:01.307567 VERBOSE LWP10299 [src/radius_session.cpp:916] Billed traffic = 16238 bytes
03.10.2019 22:11:01.309640 INFO LWP10299 [src/charge_vgroup.cpp:181] Charging: vg_id = 1, tar_id = 1, cat_idx = 0, consumed = 0.0154858, climit = 0.0808086, price = unlim, amount = 0
03.10.2019 22:11:01.338173 VERBOSE LWP10297 [src/radius.cpp:1762] Flush is done
03.10.2019 22:11:01.413458 VERBOSE LWP10299 [src/radius_session.cpp:1095] Total charge amount for '18:a9:05:cb:c3:0a'(vg_id = 1): 0
03.10.2019 22:11:58.153365 VERBOSE LWP10293 [src/shaper.cpp:59] Calculating shape is finished. Elapsed 4 ms
03.10.2019 22:12:02.343155 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:13:03.348418 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:13:24.113384 VERBOSE LWP10301 [src/radius_base.cpp:56] ============== Accounting packet #4 received from 192.168.200.200, size: 240 ==============
03.10.2019 22:13:24.113490 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Request (4), id: 0x3, length: 240
03.10.2019 22:13:24.113509 VERBOSE LWP10301 [src/radius_record.cpp:108] Authenticator: 4befad6c502c300e252d836b30eb8671
03.10.2019 22:13:24.113521 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:13:24.113548 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 22:13:24.113559 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 22:13:24.113567 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "573"
03.10.2019 22:13:24.113575 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 22:13:24.113591 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 22:13:24.113598 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:13:24.113605 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 22:13:24.113612 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Class", value: "026404d4-2481-4f7d-87bc-f40ce75830e3/1"
03.10.2019 22:13:24.113630 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 22:13:24.113641 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 22:13:24.113649 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Status-Type", value: "3"
03.10.2019 22:13:24.113656 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Authentic", value: "1"
03.10.2019 22:13:24.113663 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac4a057d"
03.10.2019 22:13:24.113670 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Time", value: "300"
03.10.2019 22:13:24.113677 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Octets", value: "86077"
03.10.2019 22:13:24.113684 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Octets", value: "34741"
03.10.2019 22:13:24.113690 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Packets", value: "766"
03.10.2019 22:13:24.113697 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Packets", value: "301"
03.10.2019 22:13:24.113703 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Gigawords", value: "0"
03.10.2019 22:13:24.113710 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Gigawords", value: "0"
03.10.2019 22:13:24.113718 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 22:13:24.113730 VERBOSE LWP10301 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 22:13:24.113775 INFO LWP10301 [src/radius.cpp:2624] Acct-Status-Type = UPDATE
03.10.2019 22:13:24.113787 VERBOSE LWP10301 [src/radius.cpp:2685] Record with SessionID = '774dcff2ac4a057d' found in cache
03.10.2019 22:13:24.113799 VERBOSE LWP10301 [src/radius.cpp:2790] End DRadius::RunAcctRequestInst
03.10.2019 22:13:24.113808 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Response (5), id: 0x3, length: 20
03.10.2019 22:13:24.113849 VERBOSE LWP10301 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Accounting answer sent successfully, time: 0 <=<=<=<=<=<=<=<
03.10.2019 22:13:58.168430 VERBOSE LWP10293 [src/shaper.cpp:59] Calculating shape is finished. Elapsed 4 ms
03.10.2019 22:14:04.353744 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:14:04.390093 VERBOSE LWP10299 [src/radius.cpp:2939] Start billing sessions
03.10.2019 22:14:04.390117 VERBOSE LWP10299 [src/radius_session.cpp:753] Put data to DB for sessions <774dcff2ac4a057d>
03.10.2019 22:14:04.390127 VERBOSE LWP10299 [src/radius_session.cpp:773] Put data to DB for session <774dcff2ac4a057d>
03.10.2019 22:14:04.391646 VERBOSE LWP10299 [src/radius_session.cpp:881] Vg_id: 1, Source tariff 1, category 0: units included = 0, above price = 0
03.10.2019 22:14:04.391672 VERBOSE LWP10299 [src/radius_session.cpp:916] Billed traffic = 18503 bytes
03.10.2019 22:14:04.393275 INFO LWP10299 [src/charge_vgroup.cpp:181] Charging: vg_id = 1, tar_id = 1, cat_idx = 0, consumed = 0.0176458, climit = 0.0962944, price = unlim, amount = 0
03.10.2019 22:14:04.415098 VERBOSE LWP10297 [src/radius.cpp:1762] Flush is done
03.10.2019 22:14:04.523729 VERBOSE LWP10299 [src/radius_session.cpp:1095] Total charge amount for '18:a9:05:cb:c3:0a'(vg_id = 1): 0
03.10.2019 22:15:05.420418 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:15:54.113391 VERBOSE LWP10301 [src/radius_base.cpp:56] ============== Accounting packet #5 received from 192.168.200.200, size: 240 ==============
03.10.2019 22:15:54.113494 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Request (4), id: 0x4, length: 240
03.10.2019 22:15:54.113511 VERBOSE LWP10301 [src/radius_record.cpp:108] Authenticator: 6a300ff089b739d35c1c92b59f0946e9
03.10.2019 22:15:54.113522 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:15:54.113578 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 22:15:54.113590 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 22:15:54.113599 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "573"
03.10.2019 22:15:54.113606 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 22:15:54.113614 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 22:15:54.113622 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:15:54.113629 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 22:15:54.113637 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Class", value: "026404d4-2481-4f7d-87bc-f40ce75830e3/1"
03.10.2019 22:15:54.113646 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 22:15:54.113658 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 22:15:54.113665 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Status-Type", value: "3"
03.10.2019 22:15:54.113673 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Authentic", value: "1"
03.10.2019 22:15:54.113680 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac4a057d"
03.10.2019 22:15:54.113687 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Time", value: "450"
03.10.2019 22:15:54.113694 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Octets", value: "147712"
03.10.2019 22:15:54.113700 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Octets", value: "49836"
03.10.2019 22:15:54.113716 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Packets", value: "1381"
03.10.2019 22:15:54.113723 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Packets", value: "451"
03.10.2019 22:15:54.113730 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Gigawords", value: "0"
03.10.2019 22:15:54.113737 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Gigawords", value: "0"
03.10.2019 22:15:54.113745 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 22:15:54.113757 VERBOSE LWP10301 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 22:15:54.113801 INFO LWP10301 [src/radius.cpp:2624] Acct-Status-Type = UPDATE
03.10.2019 22:15:54.113813 VERBOSE LWP10301 [src/radius.cpp:2685] Record with SessionID = '774dcff2ac4a057d' found in cache
03.10.2019 22:15:54.113826 VERBOSE LWP10301 [src/radius.cpp:2790] End DRadius::RunAcctRequestInst
03.10.2019 22:15:54.113834 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Response (5), id: 0x4, length: 20
03.10.2019 22:15:54.113872 VERBOSE LWP10301 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Accounting answer sent successfully, time: 0 <=<=<=<=<=<=<=<
03.10.2019 22:15:58.183166 VERBOSE LWP10293 [src/shaper.cpp:59] Calculating shape is finished. Elapsed 4 ms
03.10.2019 22:16:06.425732 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:16:06.456818 VERBOSE LWP10299 [src/radius.cpp:2939] Start billing sessions
03.10.2019 22:16:06.456842 VERBOSE LWP10299 [src/radius_session.cpp:753] Put data to DB for sessions <774dcff2ac4a057d>
03.10.2019 22:16:06.456852 VERBOSE LWP10299 [src/radius_session.cpp:773] Put data to DB for session <774dcff2ac4a057d>
03.10.2019 22:16:06.458286 VERBOSE LWP10299 [src/radius_session.cpp:881] Vg_id: 1, Source tariff 1, category 0: units included = 0, above price = 0
03.10.2019 22:16:06.458311 VERBOSE LWP10299 [src/radius_session.cpp:916] Billed traffic = 15095 bytes
03.10.2019 22:16:06.459831 INFO LWP10299 [src/charge_vgroup.cpp:181] Charging: vg_id = 1, tar_id = 1, cat_idx = 0, consumed = 0.0143957, climit = 0.11394, price = unlim, amount = 0
03.10.2019 22:16:06.481776 VERBOSE LWP10297 [src/radius.cpp:1762] Flush is done
03.10.2019 22:16:06.532031 VERBOSE LWP10299 [src/radius_session.cpp:1095] Total charge amount for '18:a9:05:cb:c3:0a'(vg_id = 1): 0
03.10.2019 22:17:07.486874 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:17:58.198073 VERBOSE LWP10293 [src/shaper.cpp:59] Calculating shape is finished. Elapsed 4 ms
03.10.2019 22:18:08.492089 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:18:24.113349 VERBOSE LWP10301 [src/radius_base.cpp:56] ============== Accounting packet #6 received from 192.168.200.200, size: 240 ==============
03.10.2019 22:18:24.113455 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Request (4), id: 0x5, length: 240
03.10.2019 22:18:24.113472 VERBOSE LWP10301 [src/radius_record.cpp:108] Authenticator: 8471380c716f29381e353e2c5707e4df
03.10.2019 22:18:24.113483 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:18:24.113492 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 22:18:24.113500 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 22:18:24.113507 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "573"
03.10.2019 22:18:24.113514 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 22:18:24.113521 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 22:18:24.113528 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:18:24.113556 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 22:18:24.113563 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Class", value: "026404d4-2481-4f7d-87bc-f40ce75830e3/1"
03.10.2019 22:18:24.113572 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 22:18:24.113583 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 22:18:24.113591 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Status-Type", value: "3"
03.10.2019 22:18:24.113598 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Authentic", value: "1"
03.10.2019 22:18:24.113605 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac4a057d"
03.10.2019 22:18:24.113611 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Time", value: "600"
03.10.2019 22:18:24.113617 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Octets", value: "180801"
03.10.2019 22:18:24.113624 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Octets", value: "64183"
03.10.2019 22:18:24.113630 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Packets", value: "1857"
03.10.2019 22:18:24.113636 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Packets", value: "601"
03.10.2019 22:18:24.113643 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Gigawords", value: "0"
03.10.2019 22:18:24.113649 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Gigawords", value: "0"
03.10.2019 22:18:24.113656 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 22:18:24.113668 VERBOSE LWP10301 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 22:18:24.113711 INFO LWP10301 [src/radius.cpp:2624] Acct-Status-Type = UPDATE
03.10.2019 22:18:24.113723 VERBOSE LWP10301 [src/radius.cpp:2685] Record with SessionID = '774dcff2ac4a057d' found in cache
03.10.2019 22:18:24.113734 VERBOSE LWP10301 [src/radius.cpp:2790] End DRadius::RunAcctRequestInst
03.10.2019 22:18:24.113743 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Response (5), id: 0x5, length: 20
03.10.2019 22:18:24.113781 VERBOSE LWP10301 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Accounting answer sent successfully, time: 0 <=<=<=<=<=<=<=<
03.10.2019 22:19:09.497351 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:19:09.531135 VERBOSE LWP10299 [src/radius.cpp:2939] Start billing sessions
03.10.2019 22:19:09.531160 VERBOSE LWP10299 [src/radius_session.cpp:753] Put data to DB for sessions <774dcff2ac4a057d>
03.10.2019 22:19:09.531169 VERBOSE LWP10299 [src/radius_session.cpp:773] Put data to DB for session <774dcff2ac4a057d>
03.10.2019 22:19:09.532637 VERBOSE LWP10299 [src/radius_session.cpp:881] Vg_id: 1, Source tariff 1, category 0: units included = 0, above price = 0
03.10.2019 22:19:09.532661 VERBOSE LWP10299 [src/radius_session.cpp:916] Billed traffic = 14347 bytes
03.10.2019 22:19:09.534152 INFO LWP10299 [src/charge_vgroup.cpp:181] Charging: vg_id = 1, tar_id = 1, cat_idx = 0, consumed = 0.0136824, climit = 0.128336, price = unlim, amount = 0
03.10.2019 22:19:09.572827 VERBOSE LWP10297 [src/radius.cpp:1762] Flush is done
03.10.2019 22:19:09.681448 VERBOSE LWP10299 [src/radius_session.cpp:1095] Total charge amount for '18:a9:05:cb:c3:0a'(vg_id = 1): 0
03.10.2019 22:19:58.213257 VERBOSE LWP10293 [src/shaper.cpp:59] Calculating shape is finished. Elapsed 4 ms
03.10.2019 22:20:10.578151 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:20:54.113368 VERBOSE LWP10301 [src/radius_base.cpp:56] ============== Accounting packet #7 received from 192.168.200.200, size: 240 ==============
03.10.2019 22:20:54.113469 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Request (4), id: 0x6, length: 240
03.10.2019 22:20:54.113486 VERBOSE LWP10301 [src/radius_record.cpp:108] Authenticator: da9141088979d02e325b73f08ab84c57
03.10.2019 22:20:54.113497 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:20:54.113506 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 22:20:54.113514 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 22:20:54.113522 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "573"
03.10.2019 22:20:54.113528 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 22:20:54.113553 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 22:20:54.113561 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:20:54.113568 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 22:20:54.113576 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Class", value: "026404d4-2481-4f7d-87bc-f40ce75830e3/1"
03.10.2019 22:20:54.113585 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 22:20:54.113596 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 22:20:54.113603 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Status-Type", value: "3"
03.10.2019 22:20:54.113610 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Authentic", value: "1"
03.10.2019 22:20:54.113617 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac4a057d"
03.10.2019 22:20:54.113623 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Time", value: "750"
03.10.2019 22:20:54.113630 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Octets", value: "256295"
03.10.2019 22:20:54.113636 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Octets", value: "80166"
03.10.2019 22:20:54.113642 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Packets", value: "2648"
03.10.2019 22:20:54.113649 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Packets", value: "751"
03.10.2019 22:20:54.113655 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Gigawords", value: "0"
03.10.2019 22:20:54.113661 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Gigawords", value: "0"
03.10.2019 22:20:54.113669 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 22:20:54.113681 VERBOSE LWP10301 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 22:20:54.113723 INFO LWP10301 [src/radius.cpp:2624] Acct-Status-Type = UPDATE
03.10.2019 22:20:54.113735 VERBOSE LWP10301 [src/radius.cpp:2685] Record with SessionID = '774dcff2ac4a057d' found in cache
03.10.2019 22:20:54.113746 VERBOSE LWP10301 [src/radius.cpp:2790] End DRadius::RunAcctRequestInst
03.10.2019 22:20:54.113755 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Response (5), id: 0x6, length: 20
03.10.2019 22:20:54.113793 VERBOSE LWP10301 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Accounting answer sent successfully, time: 0 <=<=<=<=<=<=<=<
03.10.2019 22:21:11.583398 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:21:11.615554 VERBOSE LWP10299 [src/radius.cpp:2939] Start billing sessions
03.10.2019 22:21:11.615576 VERBOSE LWP10299 [src/radius_session.cpp:753] Put data to DB for sessions <774dcff2ac4a057d>
03.10.2019 22:21:11.615585 VERBOSE LWP10299 [src/radius_session.cpp:773] Put data to DB for session <774dcff2ac4a057d>
03.10.2019 22:21:11.617077 VERBOSE LWP10299 [src/radius_session.cpp:881] Vg_id: 1, Source tariff 1, category 0: units included = 0, above price = 0
03.10.2019 22:21:11.617102 VERBOSE LWP10299 [src/radius_session.cpp:916] Billed traffic = 15983 bytes
03.10.2019 22:21:11.618753 INFO LWP10299 [src/charge_vgroup.cpp:181] Charging: vg_id = 1, tar_id = 1, cat_idx = 0, consumed = 0.0152426, climit = 0.142018, price = unlim, amount = 0
03.10.2019 22:21:11.632265 VERBOSE LWP10297 [src/radius.cpp:1762] Flush is done
03.10.2019 22:21:11.708935 VERBOSE LWP10299 [src/radius_session.cpp:1095] Total charge amount for '18:a9:05:cb:c3:0a'(vg_id = 1): 0
03.10.2019 22:21:58.228725 VERBOSE LWP10293 [src/shaper.cpp:59] Calculating shape is finished. Elapsed 5 ms
03.10.2019 22:22:12.637351 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:23:13.642749 VERBOSE LWP10297 [src/radius.cpp:1682] Flushing accounting cache
03.10.2019 22:23:24.110025 VERBOSE LWP10301 [src/radius_base.cpp:56] ============== Accounting packet #8 received from 192.168.200.200, size: 246 ==============
03.10.2019 22:23:24.110126 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Request (4), id: 0x6, length: 246
03.10.2019 22:23:24.110144 VERBOSE LWP10301 [src/radius_record.cpp:108] Authenticator: f8a13e3d65df24106e0cb92d9034968b
03.10.2019 22:23:24.110155 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:23:24.110165 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 22:23:24.110173 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 22:23:24.110181 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "573"
03.10.2019 22:23:24.110188 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 22:23:24.110195 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 22:23:24.110202 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:23:24.110209 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 22:23:24.110216 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Class", value: "026404d4-2481-4f7d-87bc-f40ce75830e3/1"
03.10.2019 22:23:24.110225 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 22:23:24.110235 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 22:23:24.110242 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Status-Type", value: "2"
03.10.2019 22:23:24.110249 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Authentic", value: "1"
03.10.2019 22:23:24.110256 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac4a057d"
03.10.2019 22:23:24.110263 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Time", value: "900"
03.10.2019 22:23:24.110269 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Octets", value: "297110"
03.10.2019 22:23:24.110275 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Octets", value: "94393"
03.10.2019 22:23:24.110282 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Packets", value: "3064"
03.10.2019 22:23:24.110288 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Packets", value: "902"
03.10.2019 22:23:24.110294 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Gigawords", value: "0"
03.10.2019 22:23:24.110301 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Gigawords", value: "0"
03.10.2019 22:23:24.110308 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 22:23:24.110317 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Terminate-Cause", value: "5"
03.10.2019 22:23:24.110326 VERBOSE LWP10301 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 22:23:24.110368 INFO LWP10301 [src/radius.cpp:2624] Acct-Status-Type = STOP
03.10.2019 22:23:24.110384 INFO LWP10301 [src/radius.cpp:2661] Acct STOP (Session-Timeout), Session-Id 774dcff2ac4a057d, vg_id 1, login 1234
03.10.2019 22:23:24.110390 VERBOSE LWP10301 [src/radius.cpp:2685] Record with SessionID = '774dcff2ac4a057d' found in cache
03.10.2019 22:23:24.111194 VERBOSE LWP10301 [src/radius.cpp:2826] Delegated prefix /0 released for session 774dcff2ac4a057d (Acct-STOP)
03.10.2019 22:23:24.111215 VERBOSE LWP10301 [src/radius.cpp:2829] Framed prefix /0 released for session 774dcff2ac4a057d (Acct-STOP)
03.10.2019 22:23:24.111222 VERBOSE LWP10301 [src/radius.cpp:2836] End DRadius::RunAcctRequestInst
03.10.2019 22:23:24.111334 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Response (5), id: 0x6, length: 20
03.10.2019 22:23:24.111420 VERBOSE LWP10301 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Accounting answer sent successfully, time: 1 <=<=<=<=<=<=<=<
03.10.2019 22:23:24.819765 INFO LWP10296 [src/radius.cpp:2433] Running ScriptStop for '1234' session '774dcff2ac4a057d', stopped [99]
03.10.2019 22:23:24.819816 VERBOSE LWP10296 [src/radius.cpp:2321] Session '774dcff2ac4a057d' is marked for removed from memory cache
03.10.2019 22:23:32.302423 VERBOSE LWP10300 [src/radius_base.cpp:56] ============== Authorization packet #9 received from 192.168.200.200, size: 174 ==============
03.10.2019 22:23:32.302471 VERBOSE LWP10300 [src/radius_record.cpp:90] Access-Request (1), id: 0x1, length: 174
03.10.2019 22:23:32.302487 VERBOSE LWP10300 [src/radius_record.cpp:108] Authenticator: 11fb72d992f674ab1469eca3665ea84a
03.10.2019 22:23:32.302507 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:23:32.302516 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 22:23:32.302525 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 22:23:32.302553 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "574"
03.10.2019 22:23:32.302561 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 22:23:32.302569 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 22:23:32.302585 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:23:32.302592 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 22:23:32.302602 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 22:23:32.302613 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 22:23:32.302622 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac4a057e"
03.10.2019 22:23:32.302640 VERBOSE LWP10300 [src/radius_record.cpp:113] Attribute "Password", value: "bc7c851febd1370a9bd1727269732da4191ede6faa841d592d84fc938a9a8588"
03.10.2019 22:23:32.302649 VERBOSE LWP10300 [src/radius_record.cpp:186] User-Password = "18:a9:05:cb:c3:0a"
03.10.2019 22:23:32.302659 VERBOSE LWP10300 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 22:23:32.302752 VERBOSE LWP10300 [src/radius_packet.cpp:652] Trying to authorize user by Opt82 params: "340804644984", 3
03.10.2019 22:23:32.303400 INFO LWP10300 [src/radius_packet.cpp:896] Auth by 'opt82' ok: [1], Session-Id 774dcff2ac4a057e
03.10.2019 22:23:32.304791 VERBOSE LWP10300 [src/radius_packet.cpp:1163] ANI '18:a9:05:cb:c3:0a' (User '18:a9:05:cb:c3:0a') is clean
03.10.2019 22:23:32.305071 VERBOSE LWP10300 [src/radius_packet.cpp:1074] User: '1234', bill by traffic, unlimited session timeout (900)
03.10.2019 22:23:32.307174 WARNING LWP10300 [src/radius.cpp:2062] ANI '18:a9:05:cb:c3:0a' is bound to 10.11.0.8/255.255.255.255 for user '18:a9:05:cb:c3:0a'
03.10.2019 22:23:32.307439 VERBOSE LWP10300 [src/radius.cpp:2144] Client IP/Netmask: 10.11.0.8/255.255.255.255, ANI: "18:a9:05:cb:c3:0a"
03.10.2019 22:23:32.307456 WARNING LWP10300 [src/radius.cpp:536] Unable to allocate delegated prefix
03.10.2019 22:23:32.307461 WARNING LWP10300 [src/radius.cpp:538] Unable to allocate framed prefix
03.10.2019 22:23:32.307478 INFO LWP10300 [src/radius.cpp:609] Access-Accept, <18:a9:05:cb:c3:0a> [1], Session-Id 774dcff2ac4a057e
03.10.2019 22:23:32.307484 VERBOSE LWP10300 [src/radius.cpp:612] =============== Output attributes dump: ===============
03.10.2019 22:23:32.307497 VERBOSE LWP10300 [src/radius.cpp:706] Attribute "Session-Timeout", value: "900"
03.10.2019 22:23:32.307506 VERBOSE LWP10300 [src/radius.cpp:711] Attribute "Service-Type", value: "2"
03.10.2019 22:23:32.307513 VERBOSE LWP10300 [src/radius.cpp:715] Attribute "Framed-Protocol", value: "1"
03.10.2019 22:23:32.307524 VERBOSE LWP10300 [src/radius.cpp:726] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 22:23:32.307549 VERBOSE LWP10300 [src/radius.cpp:746] Attribute "Framed-IP-Netmask", value: "255.255.255.255"
03.10.2019 22:23:32.308691 VERBOSE LWP10300 [src/radius.cpp:756] Attribute "Class", tag: "113", value: "46ca1230-3348-4271-abc0-34178d06213c/1"
03.10.2019 22:23:32.308752 VERBOSE LWP10300 [src/radius.cpp:799] Attribute "Acct-Interim-Interval", value: "150"
03.10.2019 22:23:32.308770 VERBOSE LWP10300 [src/radius.cpp:820] INSERT INTO CACHE NAS_IP_ADDRESS: 192.168.200.200; UUID(session_id): 774dcff2ac4a057e
03.10.2019 22:23:32.312398 WARNING LWP10300 [src/radius.cpp:879] Packet received from MAC = '18:a9:05:cb:c3:0a' while another MAC = '18:a9:05:cb:c3:0a' is assigned to vg_id = 1
03.10.2019 22:23:32.312432 VERBOSE LWP10300 [src/radius_record.cpp:90] Access-Accept (2), id: 0x1, length: 96
03.10.2019 22:23:32.312778 VERBOSE LWP10300 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Authentication answer sent successfully, time: 10 <=<=<=<=<=<=<=<
03.10.2019 22:23:32.321052 VERBOSE LWP10301 [src/radius_base.cpp:56] ============== Accounting packet #10 received from 192.168.200.200, size: 240 ==============
03.10.2019 22:23:32.321089 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Request (4), id: 0x1, length: 240
03.10.2019 22:23:32.321104 VERBOSE LWP10301 [src/radius_record.cpp:108] Authenticator: 0b443752daadc4f15f3c562db5f9af2a
03.10.2019 22:23:32.321117 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "User-Name", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:23:32.321128 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Identifier", value: "accel-ppp"
03.10.2019 22:23:32.321136 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-IP-Address", value: "192.168.200.200"
03.10.2019 22:23:32.321145 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port", value: "574"
03.10.2019 22:23:32.321152 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Id", value: "ipoe0"
03.10.2019 22:23:32.321159 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "NAS-Port-Type", value: "15"
03.10.2019 22:23:32.321166 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Calling-Station-Id", value: "18:a9:05:cb:c3:0a"
03.10.2019 22:23:32.321174 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Called-Station-Id", value: "eth0.111"
03.10.2019 22:23:32.321206 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Class", value: "46ca1230-3348-4271-abc0-34178d06213c/1"
03.10.2019 22:23:32.321217 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Remote-Id", value: "0006340804644984"
03.10.2019 22:23:32.321230 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Redback-Agent-Circuit-Id", value: "0004006f0003"
03.10.2019 22:23:32.321237 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Status-Type", value: "1"
03.10.2019 22:23:32.321244 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Authentic", value: "1"
03.10.2019 22:23:32.321251 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Id", value: "774dcff2ac4a057e"
03.10.2019 22:23:32.321263 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Session-Time", value: "0"
03.10.2019 22:23:32.321269 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Octets", value: "0"
03.10.2019 22:23:32.321275 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Octets", value: "0"
03.10.2019 22:23:32.321281 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Packets", value: "0"
03.10.2019 22:23:32.321287 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Packets", value: "0"
03.10.2019 22:23:32.321293 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Input-Gigawords", value: "0"
03.10.2019 22:23:32.321299 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Acct-Output-Gigawords", value: "0"
03.10.2019 22:23:32.321306 VERBOSE LWP10301 [src/radius_record.cpp:113] Attribute "Framed-IP-Address", value: "10.11.0.8"
03.10.2019 22:23:32.321319 VERBOSE LWP10301 [src/radius_packet.cpp:75] NAS IP replaced to 192.168.200.200 from NAS-Ip-Address
03.10.2019 22:23:32.321374 INFO LWP10301 [src/radius.cpp:2624] Acct-Status-Type = START
03.10.2019 22:23:32.321389 INFO LWP10301 [src/radius.cpp:2661] Acct START, Session-Id 774dcff2ac4a057e
03.10.2019 22:23:32.321424 VERBOSE LWP10301 [src/radius.cpp:2680] No record with SessionID = '774dcff2ac4a057e' found in cache
03.10.2019 22:23:32.322614 VERBOSE LWP10301 [src/radius.cpp:2696] Looking for auth session: NAS_IP_ADDRESS: 192.168.200.200; UUID(session_id): 774dcff2ac4a057e;
03.10.2019 22:23:32.322625 VERBOSE LWP10301 [src/radius.cpp:2699] FOUND IN AUTH CACHE!
03.10.2019 22:23:32.322631 INFO LWP10301 [src/radius.cpp:2745] Starting Handler:ScriptStart for 18:a9:05:cb:c3:0a
03.10.2019 22:23:32.322850 VERBOSE LWP10301 [src/radius.cpp:2774] End DRadius::RunAcctRequestInst
03.10.2019 22:23:32.322866 VERBOSE LWP10301 [src/radius_record.cpp:90] Accounting-Response (5), id: 0x1, length: 20
03.10.2019 22:23:32.322906 VERBOSE LWP10301 [src/radius_base.cpp:92] <=<=<=<=<=<=<=< Accounting answer sent successfully, time: 1 <=<=<=<=<=<=<=<
03.10.2019 22:23:58.243824 VERBOSE LWP10293 [src/shaper.cpp:59] Calculating shape is finished. Elapsed 4 ms

dimka88
Posts: 711
Joined: 13 Oct 2014, 05:51
Contact:

Re: IPoE+L2+dhcp+opt82 (dhcp_local_relay)

Post by dimka88 » 04 Oct 2019, 14:30

У вас радиус при авторизации клиента в Access-Accept передает атрибут 'Session-Timeout 900' от этого и завершается сессия.

baronzzz
Posts: 22
Joined: 22 Sep 2019, 12:01

Re: IPoE+L2+dhcp+opt82 (dhcp_local_relay)

Post by baronzzz » 04 Oct 2019, 14:35

Верно. Но разве клиент не должен через 150 сек выслать подтверждающий пакет что он намерен и дальше использовать ип адрес? Что подлит аренду сново на 300 секунд?

dimka88
Posts: 711
Joined: 13 Oct 2014, 05:51
Contact:

Re: IPoE+L2+dhcp+opt82 (dhcp_local_relay)

Post by dimka88 » 04 Oct 2019, 20:55

Аренду то клиент продлевает, но время сессии специально имеет приоритет над временем аренды. Таким способом вы указываете, что клиенту нужна переавторизация через 900 секунд. Вы можете поставить [ipoe]soft-terminate=1 , тогда сессия будет завершаться плавно, т.е. ждать REQUEST от клиента и отвечать NAK, таким образом заставив клиента послать DIscover.

baronzzz
Posts: 22
Joined: 22 Sep 2019, 12:01

Re: IPoE+L2+dhcp+opt82 (dhcp_local_relay)

Post by baronzzz » 05 Oct 2019, 02:21

dimka88 wrote:
04 Oct 2019, 20:55
Аренду то клиент продлевает, но время сессии специально имеет приоритет над временем аренды. Таким способом вы указываете, что клиенту нужна переавторизация через 900 секунд. Вы можете поставить [ipoe]soft-terminate=1 , тогда сессия будет завершаться плавно, т.е. ждать REQUEST от клиента и отвечать NAK, таким образом заставив клиента послать DIscover.
Попробую эту опцию и отпишусь. Спс.

baronzzz
Posts: 22
Joined: 22 Sep 2019, 12:01

Re: IPoE+L2+dhcp+opt82 (dhcp_local_relay)

Post by baronzzz » 05 Oct 2019, 15:49

ЧТо то не выходит задуманное.
Вопрос

1. ВОзможна ли такая схема как:
- максимальная арены IP сутки
- если кабель выдернули или комп\роутер выключили аренда IP стопится по истечению 5 или10минут.
2. возможно ли достигнуть схемы, за счёт параметров в биллинге а ен в accel-ppp ?

Post Reply

Who is online

Users browsing this forum: No registered users and 3 guests