ArhAngel_John Опубликовано 27 августа, 2013 (изменено) · Жалоба Привет всем! Никак не могу наконец-то нормально настроить SE100 для IPoE (Dynamic CLIPS) Сессия поднимается, скорость нарезается, всё работает отлично, только сессия долго не живёт, и падает по истечении Session time left Вот моя схема. Я её упростил до невозможности дабы на самой элементарной конфигурации получить рабочий конфиг. Схема подключения: WWW ---- SE100 (net15) ---(vid 15)--- L2access switch ----- (DHCP) PC | | Bill (LanBilling) + LBinet (DHCP server) Конфигурация SE100 [local]Redback# [local]Redback#show ver Redback Networks SmartEdge OS Version SEOS-11.1.2.7p2-Release Built by sysbuild@eussjlx7059.sj.us.am.ericsson.se Wed Apr 10 02:38:40 PDT 2013 (null)System Bootstrap version is PowerPC,rev2.0.1.2 Installed minikernel version is 2.6 Router Up Time - 42 days, 16 hours 46 secs [local]Redback#show lice [local]Redback#show licenses Software Feature License Configured -------------------------- ------------------ subscriber active 8000 YES subscriber bandwidth 60 YES Total active subscriber license configured 8000 [local]Redback# [local]Redback# [local]Redback#show config Building configuration... Current configuration: ! ! Configuration last changed by user 'root' at Tue Aug 27 20:02:27 2013 ! ! ! aaa global accounting subscriber radius context local ! ! no service multiple-contexts ! ! ! software license subscriber active 8000 encrypted 1 xxx subscriber bandwidth 60 encrypted 1 xxx ! ! dpi traffic-management protocol http escape-conversion ! ! context local ! no ip domain-lookup ! interface INET description Int to INET ip address 1.2.3.4/27 ! interface LAN ip address 192.168.100.5/24 ! interface MGMT description Link to MGMT VLAN1 ip address 192.168.111.5/23 ip source-address radius ! interface net15 multibind ip address 3.4.5.225/29 dhcp proxy 65535 ip access-group acl-for-l3-relays-only in logging console ! ip access-list acl-for-l3-relays-only seq 10 permit ip host 3.4.5.225 seq 20 permit ip host 0.0.0.0 ! enable encrypted 1 xxx ! aaa authentication administrator local aaa authentication subscriber radius aaa accounting subscriber radius aaa accounting event dhcp radius accounting server 192.168.111.3 encrypted-key xxxxx radius coa server 192.168.111.3 encrypted-key xxxxx port 3799 ! administrator root encrypted 1 xxxxx ! radius server 192.168.111.3 encrypted-key xxxxxx radius max-retries 5 radius timeout 30 radius attribute username encaps clips strip-mac-delimiter ! subscriber default qos policy policing TARIF-DEFAULT-512K-IN qos policy metering TARIF-DEFAULT-512K-OUT dhcp max-addrs 1 subscriber profile PROFILE-FOR-TARIF-2M qos policy policing TARIF-2M-IN qos policy metering TARIF-2M-OUT subscriber profile PROFILE-FOR-TARIF-1M qos policy policing TARIF-1M-IN qos policy metering TARIF-1M-OUT ! ip route 0.0.0.0/0 1.2.3.4 no service ssh server service telnet server ! dhcp relay option dhcp relay server 192.168.111.3 ! ! ! ! ! ** End Context ** logging tdm console logging active logging standby short ! ! ! ! qos policy TARIF-1M-IN policing rate 1000 burst 125000 rate-calculation exclude layer-2-overhead ! qos policy TARIF-1M-OUT metering rate 1000 burst 125000 rate-calculation exclude layer-2-overhead ! qos policy TARIF-2M-IN policing rate 2000 burst 250000 rate-calculation exclude layer-2-overhead ! qos policy TARIF-2M-OUT metering rate 2000 burst 250000 rate-calculation exclude layer-2-overhead ! qos policy TARIF-DEFAULT-512K-IN policing rate 512 burst 64000 rate-calculation exclude layer-2-overhead ! qos policy TARIF-DEFAULT-512K-OUT metering rate 512 burst 64000 rate-calculation exclude layer-2-overhead ! system clock timezone IRKT 9 0 ! port ethernet 1/1 ! XCRP management port on slot 1 no shutdown bind interface LAN local ! card carrier 2 ! port ethernet 2/1 no shutdown medium-type copper encapsulation dot1q dot1q pvc 1 bind interface MGMT local dot1q pvc 183 bind interface INET local ! port ethernet 2/2 no shutdown encapsulation dot1q dot1q pvc 15 bind interface net15 local service clips dhcp context local ! ! no service console-break ! service crash-dump-dram ! no service auto-system-recovery ! ! ! end Я использую LANBilling 2.0base Core Server build 006 (May 30 2013 16:26:50), rev #34180 и LANBilling 2.0base RADIUS DialUp build 006 (May 30 2013 15:43:22), rev #34180 + LANBilling inet agent version 2.0base build 006 (May 30 2013 16:03:54) revision 34180 в качестве DHCP server. Вот конфига Агент ЛанБиллинга mysql> select * from agent_options where id=4; +----+----------------------+----------------------+-----------------------------------------------+ | id | name | descr | value | +----+----------------------+----------------------+-----------------------------------------------+ | 4 | dhcp-domain-name | dhcp-domain-name | ironnet.info | | 4 | dhcp-identifier | dhcp-identifier | 192.168.111.3 | | 4 | dhcp-lease-time | dhcp-lease-time | 120 | | 4 | dhcpd_ip | dhcpd_ip | 192.168.111.3 | | 4 | dhcpd_port | dhcpd_port | 67 | | 4 | enable-dhcp-request | NULL | 0 | | 4 | interim_update_time | NULL | 600 | | 4 | last_charge_date | NULL | 2013-02-14 | | 4 | macregex | NULL | /(..)-(..)-(..)-(..)-(..)-(..)/\1\2\3\4\5\6/i | | 4 | radius-nameserver | radius-nameserver | 1.2.3.10 | | 4 | radius-nameserver2 | radius-nameserver2 | 1.2.3.11 | | 4 | radius-uses-lbinet | NULL | 1 | | 4 | radius_auth_method | NULL | opt82 | | 4 | skip-empty-framed-ip | skip-empty-framed-ip | 1 | +----+----------------------+----------------------+-----------------------------------------------+ dhcp-lease-time = 120 сек при этом Максимальная длительность сессии выставлена на 180 сек. Что мы имеем в действии: Начинается сессия * Прилетает от РС DHCP DISCOVER на SE100 * SE100 его добропорядочно проксирует на сервер Биллинга * сервер биллинга используя два агента LBarcd - RADIUS и LBInet - DHCP авторизует клиента и выдаёт SE100 ай-пи для абонента * SE100 успешно запускает сессию и отдаёт ай-пи клиенту [local]Redback# [local]Redback#show subs act 10:bf:48:d9:cd:32 Session state Up Circuit 2/2 vlan-id 15 clips 133308 Internal Circuit 2/2:511:63:31/7/2/2236 Interface bound net15 Current port-limit unlimited Session time left 171 Protocol Stack IPV4 dhcp max-addrs 1 (applied) dhcp vendor class id MSFT 5.0 (applied) dhcp option client id 0x3d070110bf48d9cd32 (applied) dhcp option hostname 0x0c084b72697374696e61 (applied) timeout absolute 180 (applied) acct-interim-interval 600 (applied) qos-policing-policy TARIF-DEFAULT-512K-IN (applied from sub_default) qos-metering-policy TARIF-DEFAULT-512K-OUT (applied from sub_default) IP host entries installed by DHCP: (max_addr 1 cur_entries 1) 3.4.5.229 10:bf:48:d9:cd:32 Обратите внимание на Session Time. Он прилетает в ответе RADIUS Server 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [HandleRadius:65] >=>=>=>=>=>=>=> Auth Packet received from 192.168.111.5, size: 300 >=>=>=>=>=>=>=> 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:30] Authenticator: 6668b20b820d8cc4306c0a19f9653500 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] Attribute 'User-Name', value: "10bf48d9cd32" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] Attribute 'Password', value: "3cde187105f7da79ac8ac0e242bdf4fd" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseAttr:79] User-Password = "Redback" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] Attribute 'Service-Type', value: "5" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] Attribute 'NAS-Identifier', value: "Redback" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] Attribute 'NAS-Port', value: "33685504" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] VSA 'NAS-Real-Port', vendor 2352, value: "570425359" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] Attribute 'NAS-Port-Type', value: "5" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] Attribute 'NAS-Port-Id', value: "841953824" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] VSA 'Medium-Type', vendor 2352, value: "11" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] VSA 'Mac-Addr', vendor 2352, value: "10-bf-48-d9-cd-32" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] VSA 'Platform-Type', vendor 2352, value: "4" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] VSA 'OS-Version', vendor 2352, value: "11.1.2.7p2" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] VSA 'Redback-Agent-Remote-Id', vendor 2352, value: "0006c8be19f9e2c0" 28.08.2013 00:50:07 DEBUG 0x7f83514ce700 [ParseAttr:208] HWNAME: "c8be19f9e2c0" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] Unknown VSA 2, vendor 3561, value: "0006c8be19f9e2c0" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] VSA 'Redback-Agent-Circuit-Id', vendor 2352, value: "0004000f000f" 28.08.2013 00:50:07 DEBUG 0x7f83514ce700 [ParseAttr:222] HWPORT: 15 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] Unknown VSA 1, vendor 3561, value: "0004000f000f" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] VSA 'DHCP-Option', vendor 2352, value: "3d3d070110bf48d9cd32" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] VSA 'DHCP-Option', vendor 2352, value: "0c0c084b72697374696e61" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [ParseBody:37] VSA 'DHCP-Vendor-Class-ID', vendor 2352, value: "MSFT 5.0" 28.08.2013 00:50:07 DEBUG 0x7f83514ce700 [AuthenticateFromDB:506] Start authenticate from database for login '10bf48d9cd32' 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [TryAuthISG:416] Trying to authenticate ISG with method 'opt82' 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [TryAuthISGByOpt82:315] Opt82 params: "c8be19f9e2c0", 15 28.08.2013 00:50:07 DEBUG 0x7f83514ce700 [AddService:230] Service cat_idx=0 enabled=0 service= includes=0 above=0.000000 user_cat=<> lim_in=377851991 lim_out=149509883 28.08.2013 00:50:07 DEBUG 0x7f83514ce700 [AuthenticateFromDB:518] Auth ISG ok 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [CheckBlackList:750] ANI '10bf48d9cd32' (User 'user1') is clean 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [AuthenticateFromDB:632] User 'user1' (vg_id = 15742) 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [AuthenticateFromDB:701] User: 'user1', bill by traffic, unlimited session timeout (180) 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [GetClientIPAddr:1477] No IP address specified for login 'user1'. Assume NAS negotiated IP 28.08.2013 00:50:07 INFO 0x7f83514ce700 [RunAuthRequest:495] Access-Accept, <user1> [15742] 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [RunAuthRequest:498] =============== Output attributes dump: =============== 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [RunAuthRequest:601] Attribute 'Session-Timeout', value: "180" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [RunAuthRequest:607] Attribute 'Service-Type', value: "5" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [RunAuthRequest:630] Attribute 'Class', value: "00015742" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [RunAuthRequest:683] Attribute 'Acct-Interim-Interval', value: "600" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [AddAttrs:632] VSA 'DHCP-Max-Leases', vendor 2352, value: "1" 28.08.2013 00:50:07 VERBOSE 0x7f83514ce700 [HandleRadius:101] <=<=<=<=<=<=<=< Authentication answer sent successfully, time: 0.013 <=<=<=<=<=<=<=< 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [HandleRadius:65] >=>=>=>=>=>=>=> Acct Packet received from 192.168.111.5, size: 432 >=>=>=>=>=>=>=> 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:30] Authenticator: e3da8c3a85120f6f1e34d020e94376db 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'User-Name', value: "10bf48d9cd32" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Status-Type', value: "1" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Session-Id', value: "0101FFFF780008BD-521D0DBD" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Service-Type', value: "5" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Acct-Update-Reason', vendor 2352, value: "1" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'NAS-Identifier', value: "Redback" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'NAS-Port', value: "33685504" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'NAS-Real-Port', vendor 2352, value: "570425359" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'NAS-Port-Type', value: "5" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'NAS-Port-Id', value: "841953824" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Medium-Type', vendor 2352, value: "11" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Mac-Addr', vendor 2352, value: "10-bf-48-d9-cd-32" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Platform-Type', vendor 2352, value: "4" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'OS-Version', vendor 2352, value: "11.1.2.7p2" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Redback-Agent-Remote-Id', vendor 2352, value: "0006c8be19f9e2c0" 28.08.2013 00:50:07 DEBUG 0x7f8350acd700 [ParseAttr:208] HWNAME: "c8be19f9e2c0" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 2, vendor 3561, value: "0006c8be19f9e2c0" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Redback-Agent-Circuit-Id', vendor 2352, value: "0004000f000f" 28.08.2013 00:50:07 DEBUG 0x7f8350acd700 [ParseAttr:222] HWPORT: 15 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 1, vendor 3561, value: "0004000f000f" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Authentic', value: "1" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'DHCP-Max-Leases', vendor 2352, value: "1" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'DHCP-Vendor-Class-ID', vendor 2352, value: "MSFT 5.0" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'DHCP-Option', vendor 2352, value: "3d3d070110bf48d9cd32" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'DHCP-Option', vendor 2352, value: "0c0c084b72697374696e61" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Session-Timeout', value: "180" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Class', value: "00015742" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Interim-Interval', value: "600" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Qos-Policing-Profile-Name', vendor 2352, value: "TARIF-DEFAULT-512K-IN" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Qos-Metering-Profile-Name', vendor 2352, value: "TARIF-DEFAULT-512K-OUT" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Event-Timestamp', value: "1377635774" 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [RunAcctRequest:1775] Acct-Status-Type = START 28.08.2013 00:50:07 INFO 0x7f8350acd700 [RunAcctRequestInst:1802] Acct START, Session-Id 0101FFFF780008BD-521D0DBD 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [RunAcctRequestInst:1819] No record with SessionID = '0101FFFF780008BD-521D0DBD' found in cache, adding new entry 28.08.2013 00:50:07 VERBOSE 0x7f8350acd700 [HandleRadius:101] <=<=<=<=<=<=<=< Accounting answer sent successfully, time: 0.005 <=<=<=<=<=<=<=< 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [HandleRadius:65] >=>=>=>=>=>=>=> Acct Packet received from 192.168.111.5, size: 662 >=>=>=>=>=>=>=> 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:30] Authenticator: 2bede24eb55a01de72c756ac4698b3f3 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'User-Name', value: "10bf48d9cd32" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Status-Type', value: "3" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Session-Id', value: "0101FFFF780008BD-521D0DBD" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Service-Type', value: "5" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Acct-Update-Reason', vendor 2352, value: "10" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'NAS-Identifier', value: "Redback" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'NAS-Port', value: "33685504" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'NAS-Real-Port', vendor 2352, value: "570425359" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'NAS-Port-Type', value: "5" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'NAS-Port-Id', value: "841953824" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Medium-Type', vendor 2352, value: "11" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Mac-Addr', vendor 2352, value: "10-bf-48-d9-cd-32" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Platform-Type', vendor 2352, value: "4" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'OS-Version', vendor 2352, value: "11.1.2.7p2" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Redback-Agent-Remote-Id', vendor 2352, value: "0006c8be19f9e2c0" 28.08.2013 00:50:08 DEBUG 0x7f8350acd700 [ParseAttr:208] HWNAME: "c8be19f9e2c0" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 2, vendor 3561, value: "0006c8be19f9e2c0" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Redback-Agent-Circuit-Id', vendor 2352, value: "0004000f000f" 28.08.2013 00:50:08 DEBUG 0x7f8350acd700 [ParseAttr:222] HWPORT: 15 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 1, vendor 3561, value: "0004000f000f" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Authentic', value: "1" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'DHCP-Max-Leases', vendor 2352, value: "1" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'DHCP-Vendor-Class-ID', vendor 2352, value: "MSFT 5.0" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'DHCP-Option', vendor 2352, value: "3d3d070110bf48d9cd32" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'DHCP-Option', vendor 2352, value: "0c0c084b72697374696e61" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Session-Time', value: "0" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Input-Packets', value: "0" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Output-Packets', value: "0" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Input-Octets', value: "0" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Output-Octets', value: "0" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Input-Gigawords', value: "0" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Output-Gigawords', value: "0" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 130, vendor 2352, value: "0000000000000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 131, vendor 2352, value: "0000000000000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 128, vendor 2352, value: "0000000000000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 129, vendor 2352, value: "0000000000000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 149, vendor 2352, value: "00000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 150, vendor 2352, value: "00000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 147, vendor 2352, value: "00000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 148, vendor 2352, value: "00000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 135, vendor 2352, value: "0000000000000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 136, vendor 2352, value: "0000000000000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 133, vendor 2352, value: "0000000000000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Unknown VSA 134, vendor 2352, value: "0000000000000000" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Assigned-IP-Address', vendor 2352, value: "3.4.5.229" (replaces 'Framed-IP-Address') 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Session-Timeout', value: "180" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Class', value: "00015742" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Acct-Interim-Interval', value: "600" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Qos-Policing-Profile-Name', vendor 2352, value: "TARIF-DEFAULT-512K-IN" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] VSA 'Qos-Metering-Profile-Name', vendor 2352, value: "TARIF-DEFAULT-512K-OUT" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [ParseBody:37] Attribute 'Event-Timestamp', value: "1377635774" 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [RunAcctRequest:1775] Acct-Status-Type = UPDATE 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [RunAcctRequestInst:1825] Record with SessionID = '0101FFFF780008BD-521D0DBD' found in cache 28.08.2013 00:50:08 VERBOSE 0x7f8350acd700 [HandleRadius:101] <=<=<=<=<=<=<=< Accounting answer sent successfully, time: 0.004 <=<=<=<=<=<=<=< * у клиента всё начинает работать: инет работать, трафик резаться и прочее. * тут подходит время отправить со стороны клиента DHCP Request, что мол у меня время аренды заканчивается (оно же 120 секунд всего, меньше чем сама сессия) * включаем debug dhcp-relay all и смотрим Прилетает DHCP Request когда уже подходит время [local]Redback# [local]Redback# [local]Redback#Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Received pkt from 3.4.5.229 (dest addr 3.4.5.225). Aug 27 20:45:27: %DHCP-7-PKT: Packet Process handler thread: Process packet Aug 27 20:45:27: %DHCP-7-OPT: [dhcp_util_parse_options] Found client id option with len 7 type 1 Aug 27 20:45:27: %DHCP-7-OPT: [dhcp_util_parse_options] Found hostname option with len 8 hostname Kristina Aug 27 20:45:27: %DHCP-7-OPT: [dhcp_util_parse_dhcp_relay_opt] Trying to parse option 82 Aug 27 20:45:27: %DHCP-7-OPT: [dhcp_util_parse_dhcp_relay_opt] Found RAI sub-opt 1 with len 6 and value 0004000f000f Aug 27 20:45:27: %DHCP-7-OPT: [dhcp_util_parse_dhcp_relay_opt] Found RAI sub-opt 2 with len 8 and value 0006c8be19f9e2c0 Aug 27 20:45:27: %DHCP-7-OPT: [dhcp_util_parse_options] is_dhcp_pkt: Yes, msg_type: 3 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: >> Received DHCP REQUEST (len 320) from src 3.4.5.229, mac 10:bf:48:d9:cd:32 0 01 01 06 00 a8 98 d8 2d 00 00 00 00 1f 86 2f e5 16 00 00 00 00 00 00 00 00 00 00 00 00 10 bf 48 d9 32 cd 32 00 00 00 00 00 00 00 00 00 00 00 00 00 00 48 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 64 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 96 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 112 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 128 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 144 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 160 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 176 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 192 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 208 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 224 00 00 00 00 00 00 00 00 00 00 00 00 63 82 53 63 240 35 01 03 3d 07 01 10 bf 48 d9 cd 32 0c 08 4b 72 256 69 73 74 69 6e 61 51 0b 00 00 00 4b 72 69 73 74 272 69 6e 61 3c 08 4d 53 46 54 20 35 2e 30 37 0c 01 288 0f 03 06 2c 2e 2f 1f 21 79 f9 2b 52 12 01 06 00 304 04 00 0f 00 0f 02 08 00 06 c8 be 19 f9 e2 c0 ff Aug 27 20:45:27: %DHCP-7-GEN: Found mac cct entry for mac 10:bf:48:d9:cd:32 giaddr 0.0.0.0 Aug 27 20:45:27: [0000]: %DHCP-7-TIMER: Starting DHCP_PENDING_TIMER timer for 30 seconds; mac 00:00:00:00:00:00 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Inserted dhcp request with MAC 10:bf:48:d9:cd:32 on cct Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Process: DHCP REQUEST packet Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Received: DISCOVER cnt: 0, REQUEST cnt: 1 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Option 82 present the client: 10:bf:48:d9:cd:32 dhcp pkt Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Send DHCP pkt to server IP address 192.168.111.3 in context 0x40080001 for client on circuit 2/2:511:63:31/7/2/2239, pkt_len: 320 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT_DUMP: Sending out DHCP packet with options: 0 63 82 53 63 35 01 03 3d 07 01 10 bf 48 d9 cd 32 16 0c 08 4b 72 69 73 74 69 6e 61 51 0b 00 00 00 4b 32 72 69 73 74 69 6e 61 3c 08 4d 53 46 54 20 35 2e 48 30 37 0c 01 0f 03 06 2c 2e 2f 1f 21 79 f9 2b 52 Aug 27 20:45:27: %DHCP-7-GEN: [dhcp_pkt_packet_process_handler] Freeing DHCP pkt Aug 27 20:45:27: [0001]: [2/1:511:63:31/1/2/10]: %DHCP-7-PKT: Received pkt from 192.168.111.3 (dest addr 3.4.5.225). Aug 27 20:45:27: %DHCP-7-PKT: Packet Process handler thread: Process packet Aug 27 20:45:27: %DHCP-7-OPT: [dhcp_util_parse_dhcp_relay_opt] Trying to parse option 82 Aug 27 20:45:27: %DHCP-7-OPT: [dhcp_util_parse_dhcp_relay_opt] Found RAI sub-opt 1 with len 6 and value 0004000f000f Aug 27 20:45:27: %DHCP-7-OPT: [dhcp_util_parse_dhcp_relay_opt] Found RAI sub-opt 2 with len 8 and value 0006c8be19f9e2c0 Aug 27 20:45:27: %DHCP-7-OPT: [dhcp_util_parse_options] is_dhcp_pkt: Yes, msg_type: 5 Aug 27 20:45:27: [0001]: [2/1:511:63:31/1/2/10]: %DHCP-7-PKT: >> Received DHCP ACK (len 318) from src 192.168.111.3, mac 10:bf:48:d9:cd:32 Aug 27 20:45:27: %DHCP-7-GEN: Found mac cct entry for mac 10:bf:48:d9:cd:32 giaddr 0.0.0.0 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Received reply: found DHCP ACK for client with MAC 10:bf:48:d9:cd:32 on cct packet length 318 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Processing other Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Received reply for client on: ifgrid 0x1000001d, type 0x2 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Received DHCP packet from server with options: 0 63 82 53 63 01 04 ff ff ff f8 03 04 1f 86 2f e1 16 06 08 b2 d4 b7 f4 b2 d4 b7 fe 0f 0c 69 72 6f 6e 32 6e 65 74 2e 69 6e 66 6f 33 04 00 00 00 78 35 01 48 05 36 04 c0 a8 6f 03 39 02 05 78 52 12 01 06 00 64 04 00 0f 00 0f 02 08 00 06 c8 be 19 f9 e2 c0 ff Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Option: server id received as 192.168.111.3 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Proxy: Option 54 found: reset to 3.4.5.225 Aug 27 20:45:27: %DHCP-7-OPT: Made agent-id of relay option 82: 2/2 vlan-id 15, len: 14 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Option 82 is different, did not remove Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: DHCP Lease time is 120 seconds Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-TIMER: Stopping DHCP_PENDING_TIMER timer; mac 10:bf:48:d9:cd:32 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Process reply for mac 10:bf:48:d9:cd:32 ip 3.4.5.229 create time: Tue Aug 27 20:45:27 2013 , lease 120 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Process entry lookup: exist, no mismatch Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Found IP node for 3.4.5.229, lease 120 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: IP address and mac entry exists: update file Aug 27 20:45:27: %DHCP-7-FILE: Update entry: ip 3.4.5.229. Aug 27 20:45:27: %DHCP-7-FILE: Enqueued msg (opn: 2) to active dhelperd Aug 27 20:45:27: %DHCP-7-FILE: ipc ep for standby not valid Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-FILE: Update existing file record for mac:10:bf:48:d9:cd:32, ip: 3.4.5.229, lease time: 120 Aug 27 20:45:27: [2/2:511:63:31/7/2/2239]: %DHCP-7-OPT: Deleting cached request from MAC 10:bf:48:d9:cd:32 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-TIMER: Stopping DHCP_PENDING_TIMER timer; mac 10:bf:48:d9:cd:32 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: siaddr set to 192.168.111.3 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: giaddr received as 3.4.5.225 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Saved packet (len 318) for client: 10:bf:48:d9:cd:32 to sent later Aug 27 20:45:27: %DHCP-7-IPC: Received msg 3 from dhelperd with length 60 Aug 27 20:45:27: %DHCP-7-DHELPER: Received UPDATE resp for mac: 10:bf:48:d9:cd:32, resp_code: 1, page: 1858/0, cct info (slot = 1, port = 1 channel 65535, level 2, encap 0x1014400, session id 0, dot1q_pvc 15, dot1q_inner_pvc 0, vpi 0, vci 0), giaddr 0.0.0.0 Aug 27 20:45:27: %DHCP-7-GEN: Found mac cct entry for mac 10:bf:48:d9:cd:32 giaddr 0.0.0.0 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-TIMER: Starting DHCP_LEASE_EXP_TIMER timer for 120 seconds; mac 10:bf:48:d9:cd:32 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: dhcp_pkt_send_pkt_to_client: process sending packet on cct for IP 3.4.5.229 pkt_len:318 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: Broadcast bit is not set. Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: << Send DHCP response (DHCP ACK) (raw) to client in context 0x40080001 on circuit 2/2:511:63:31/7/2/2239 for MAC 10:bf:48:d9:cd:32, IP address 3.4.5.229, pkt len 318, as 3.4.5.229 using source address 3.4.5.225, pkt giaddr: 0.0 Aug 27 20:45:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: [dhcp_pkt_send_raw_to_client] Sent server response of length (364) to MAC 10:bf:48:d9:cd:32(src MAC 00:30:88:1c:5e:fd) 0 02 01 06 00 a8 98 d8 2d 00 00 00 00 00 00 00 00 16 1f 86 2f e5 c0 a8 6f 03 00 00 00 00 10 bf 48 d9 32 cd 32 00 00 00 00 00 00 00 00 00 00 00 00 00 00 48 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 64 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 96 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 112 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 128 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 144 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 160 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 176 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 192 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 208 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 224 00 00 00 00 00 00 00 00 00 00 00 00 63 82 53 63 240 01 04 ff ff ff f8 03 04 1f 86 2f e1 06 08 b2 d4 256 b7 f4 b2 d4 b7 fe 0f 0c 69 72 6f 6e 6e 65 74 2e 272 69 6e 66 6f 33 04 00 00 00 78 35 01 05 36 04 1f 288 86 2f e1 39 02 05 78 52 12 01 06 00 04 00 0f 00 304 0f 02 08 00 06 c8 be 19 f9 e2 c0 ff 00 00 Aug 27 20:45:27: %DHCP-7-GEN: Process ip-mac node: free client packet. Aug 27 20:45:27: %DHCP-7-GEN: [dhcp_util_release_ip_mac_node_pkt] Freeing DHCP pkt [local]Redback# [local]Redback# Таймаут сессии не обновился [local]Redback# [local]Redback#show subs act 10:bf:48:d9:cd:32 Session state Up Circuit 2/2 vlan-id 15 clips 133311 Internal Circuit 2/2:511:63:31/7/2/2239 Interface bound net15 Current port-limit unlimited Session time left 85 Protocol Stack IPV4 dhcp max-addrs 1 (applied) dhcp vendor class id MSFT 5.0 (applied) dhcp option client id 0x3d070110bf48d9cd32 (applied) dhcp option hostname 0x0c084b72697374696e61 (applied) timeout absolute 180 (applied) acct-interim-interval 600 (applied) qos-policing-policy TARIF-DEFAULT-512K-IN (applied from sub_default) qos-metering-policy TARIF-DEFAULT-512K-OUT (applied from sub_default) IP host entries installed by DHCP: (max_addr 1 cur_entries 1) 3.4.5.229 10:bf:48:d9:cd:32 [local]Redback# И сессия продолжает умирать и умирает до конца [local]Redback# [local]Redback# [local]Redback#Aug 27 20:47:27: %DHCP-7-IPC: Received IPC command 0xd4d with length 80 Aug 27 20:47:27: %DHCP-7-IPC: IPC MSG Q Thread woken up, Q count: 0 Aug 27 20:47:27: [0001]: %DHCP-7-ISM: Interface 0x1000001d : event Interface STATE (0x1), sub event (0x20) Aug 27 20:47:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-ISM: Unbind cct Aug 27 20:47:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: Delete circuit: ifgrid 0x1000001d, entry delete not set, save iphost set . Aug 27 20:47:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: Save iphosts on cct, slot 1 port 1 channel 65535 level 2 to cct-cfg tree Aug 27 20:47:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: Save iphost on cct cfg tree: ip 3.4.5.229 mac 10:bf:48:d9:cd:32, clips entry: TRUE, flags: 0x403805 Aug 27 20:47:27: %DHCP-7-GEN: Add cct entry to cct-wait tree: slot 1 port 1 channel 65535 level 2, encap 0x1014400 dot1q_pvc 15 dot1q_inner_pvc 0 vpi 0 vci 0, ip 3.4.5.229 o_giaddr: 0.0.0.0 lease 120, mac 10:bf:48:d9:cd:32, flags 0xb, file page active:1859/0 sta Aug 27 20:47:27: %DHCP-7-GEN: Add cct entry to cct-wait tree: level: 2, encaps[0]: 0x0encaps[1]: 0x1014400, encaps[2]: 0x0 Aug 27 20:47:27: %DHCP-7-GEN: Adding: record to cct-cfg tree for 3.4.5.229. Aug 27 20:47:27: %DHCP-7-GEN: Start cct-cfg timer: IP: 3.4.5.229, mac 10:bf:48:d9:cd:32 create_time Tue Aug 27 20:47:27 2013 , lease time 120 current time Tue Aug 27 20:47:27 2013 : starting timer. Aug 27 20:47:27: %DHCP-7-GEN: Start cct-cfg timer: IP: 3.4.5.229, mac 10:bf:48:d9:cd:32 create_time: 1377636387, curr_time: 1377636447 Aug 27 20:47:27: %DHCP-7-TIMER: Starting DHCP_CCT_CFG_LEASE_EXPIRY_TIMER timer for 60 seconds; mac 10:bf:48:d9:cd:32 Aug 27 20:47:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: Delete ip-mac node: delete ALL iphost entry Aug 27 20:47:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: Delete ip-mac node: ip 3.4.5.229 mac 10:bf:48:d9:cd:32, iphost: do not send, Aug 27 20:47:27: [0001]: %DHCP-7-GEN: RTN Delete ip node: 3.4.5.229 context 0x40080001: success. Aug 27 20:47:27: [0001]: %DHCP-7-GEN: Delete ip node: 3.4.5.229 context 0x40080001: success. Aug 27 20:47:27: %DHCP-7-GEN: Deleted mac cct node for mac 10:bf:48:d9:cd:32 Aug 27 20:47:27: %DHCP-7-GEN: Deleted mac node for mac 10:bf:48:d9:cd:32 Aug 27 20:47:27: %DHCP-7-TIMER: Stopping DHCP_LEASE_EXP_TIMER timer; mac 10:bf:48:d9:cd:32 Aug 27 20:47:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: Delete ip-mac node: Flush. Aug 27 20:47:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-PKT: [dhcp_util_delete_ip_mac_entry]: Decremented disc cnt to 0 Aug 27 20:47:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: Delete ip-mac node: freed iphost on cct. Aug 27 20:47:27: [0001]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: UnBinding: cct 2/2:511:63:31/7/2/2239 from ifgrid 0x1000001d. Aug 27 20:47:27: %DHCP-7-GEN: dhcp_cct_on_if_node_free: free 0x42686420 Aug 27 20:47:28: %DHCP-7-IPC: Received IPC command 0xd4d with length 448 Aug 27 20:47:28: %DHCP-7-IPC: IPC MSG Q Thread woken up, Q count: 0 Aug 27 20:47:28: [2/2:511:63:31/7/2/2239]: %DHCP-7-ISM: [dhcp_ism_process_cct_events] Received ISM event (0x5) Circuit STATE, sub event (0x4) Circuit DEL for context 0x0 Aug 27 20:47:28: [2/2:511:63:31/7/2/2239]: %DHCP-7-ISM: circuit term cause 143 Aug 27 20:47:28: [0000]: [2/2:511:63:31/7/2/2239]: %DHCP-7-CLIPS: [dhcp_ism_process_clips_cct_delete] Clips CCT DELETE for mac_addr: 10:bf:48:d9:cd:32 Aug 27 20:47:28: [0000]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: Delete circuit: ifgrid 0x0, entry delete set, save iphost set . Aug 27 20:47:28: [0000]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: Save iphosts on cct, slot 1 port 1 channel 65535 level 2 to cct-cfg tree Aug 27 20:47:28: [0000]: [2/2:511:63:31/7/2/2239]: %DHCP-7-GEN: Delete ip-mac node: delete ALL iphost entry Aug 27 20:47:28: %DHCP-7-GEN: dhcp_cct_node_free: free 0x42686310 Aug 27 20:47:28: %DHCP-7-GEN: dhcp_cct_node_free: free 0x42686310: not referenced, free cct node 0x42686310 Aug 27 20:47:28: [2/2:511:63:31/1/2/13]: %DHCP-7-ISM: [dhcp_ism_process_cct_events] Received ISM event (0x6) Circuit Config CHANGE, sub event (0x10) Circuit 1QCFG for context 0x40080001 Aug 27 20:47:28: [2/2:511:63:31/1/2/13]: %DHCP-7-ISM: cct is NOT configured as subscriber cct. Aug 27 20:47:28: [0001]: [2/2:511:63:31/1/2/13]: %DHCP-7-ISM: Received cct config event 0x6, sub event 0x10 for slot/port/channel:1/1/65535, level 2, encap type (0x1000400): ether-dot1q. Aug 27 20:47:28: [0001]: [2/2:511:63:31/1/2/13]: %DHCP-7-ISM: dynamic CLIPS enabled on cct Aug 27 20:47:28: [0001]: [2/2:511:63:31/1/2/13]: %DHCP-7-ISM: CLIPS Relay Disabled on cct Aug 27 20:47:28: [0001]: [2/2:511:63:31/1/2/13]: %DHCP-7-ISM: Received cct config event 0x6, sub event 0x10 for slot/port/channel:1/1/65535, level 2, encap type (0x1000400): ether-dot1q vlan_id 0xf inner_vlan_id 0x0 ethertype 0x8100 dot1q_flags 0x0. Aug 27 20:47:28: [0001]: [2/2:511:63:31/1/2/13]: %DHCP-7-GEN: [dhcp_util_mark_all_iphosts_in_cct_cfg_unstale] Walking cct-cfg tree for cct, with key: (slot = 1, port = 1 channel 65535, level 2, encap 0x1000400, session id 0, dot1q_pvc 15, dot1q_inner_pvc 0, vpi 0, vci 0) Aug 27 20:47:28: [0001]: [2/2:511:63:31/1/2/13]: %DHCP-7-GEN: dhcp_util_mark_all_iphosts_in_cct_cfg_unstale: Start walking through cct_sav_cfg_tree_head. Aug 27 20:47:28: [0001]: [2/2:511:63:31/1/2/13]: %DHCP-7-GEN: dhcp_util_mark_all_iphosts_in_cct_cfg_unstale: End walking through cct_sav_cfg_tree_head. [local]Redback# [local]Redback# Курение документации по SEOS пока ничего не дало. Не могу там найти механизм поддержания сессия. Благодаря чему она должна обновляться? Если благодаря DHCP Request-ам со сторона клиента , который отсылает их по истечении leased-time, то почему в такой простой схеме оно не работает? Не могу понять. Может что-то ещё отдебажить надо. По статистике show dhcp relay stats вот что [local]Redback#show dhcp relay stats detail Current time: Tue Aug 27 20:57:44 2013 Last cleared: Tue Aug 27 19:41:12 2013 Packets Received : 224 Packets Relayed : 186 Packet received----------------------------------------------------- DHCP Discover : 18 DHCP Offer : 18 DHCP Request : 58 DHCP Decline : 0 DHCP Ack : 58 DHCP Nack : 0 DHCP Release : 0 Packet Sent--------------------------------------------------------- DHCP Discover : 18 DHCP Offer : 18 DHCP Request : 58 DHCP Decline : 0 DHCP Ack : 58 DHCP Nack : 2 DHCP Release : 0 Unknown Packet : 34 BOOTP Request : 0 BOOTP Reply : 0 Tx server error : 0 Tx client error : 0 Split Lease-------------------------------------------------------- Request handled : 0 Ack sent : 0 Lease misconfiguration: 0 Renewal failed : 0 No server id for ack : 0 No subnet mask for ack: 0 Sub lease timer expiry: 0 ------------------------------------------------------------------- Dropped packets----------------------------------------------------- Bad Ack : 0 Internal Error : 0 Bad Length : 0 Bad Circuit : 0 Bad Circuit UP : 0 Bad Circuit Kern : 0 Bad Circuit EOF : 0 Bad Circuit slot : 0 Bad Context : 0 Bad Server IP : 0 No Server : 0 No Interface : 0 Unbound Circuit : 0 Disabled Interface : 0 Min Wait Error : 0 Max Hops Error : 0 Bad IP : 0 Unknown Packet Type : 34 Dropped Discover : 0 Dropped Request : 0 Dropped Offer : 0 Dropped Ack : 0 Dropped Release : 0 del_pending_dropped : 0 EP Down : 0 Error in Options : 0 max-addr dropped : 0 non-clips mac : 0 Invalid mac-addr : 0 MAC entry not found : 0 Dup cct-cfg entry : 2 Mismatch ip/mac : 0 No renewal marked : 0 Dropped invalid server: 0 Bcast/Mcast mac : 0 Context not found : 0 Interface not found : 0 Circuit not found : 0 Request entry not found: 0 Drop dup disc/del req : 0 Drop dup discover : 0 Throttle dropped disc : 0 Timers------------------------------------------------------------- Server timeout : 0 Del Req : 110 Lease timer exp : 0 cfg lease exp : 16 Timer started : 223 Timer start failed : 0 Timer stopped : 223 AAA---------------------------------------------------------------- IPH ADD sent : 18 IPH DEL Sent : 0 cct-cfg ADD sent : 0 cct-cfg DEL sent : 18 IPH Reject rcvd : 0 Pending Del sent : 0 Clips-------------------------------------------------------------- clips msg add : 18 clips msg del : 0 clips msg enq : 18 clips throttle : 0 clips resp msg : 0 clips del on resp : 0 clips cct del mrk : 0 clips cct del : 0 clips delete resp : 0 ISM---------------------------------------------------------------- IPH Add Rcvd : 18 IPH Del Rcvd : 0 ism cct create : 18 ism cct delete : 19 ism cct up : 18 ism cct down : 17 ism cct bind : 18 ism cct unbind : 19 dhcp_cct_del : 19 IPH ADD matched : 18 ism if create : 0 ism if delete : 0 ism if down : 0 ism if up : 0 ism port down : 0 ism port delete : 0 ism clips group down : 0 ism clips group up : 0 ism clips group delete: 0 ism throttle hit : 0 Interface Stale Processing: Create Stale Mark : 0 Create Stale Clear : 0 Up Stale Mark : 0 Up Stale Clear : 0 Bind Stale Mark : 0 Bind Stale Clear : 0 I/F Bind Stale : 0 I/F Up Stale : 0 I/F Create Stale : 0 Circuit Stale Processing: Create Stale Mark : 0 Create Stale Clear : 0 Up Stale Mark : 0 Up Stale Clear : 0 Bind Stale Mark : 0 Bind Stale Clear : 0 Cct Bind Stale : 0 Cct Up Stale : 0 Cct Create Stale : 0 ARP---------------------------------------------------------------- Router id add sent : 0 Router id del sent : 0 Router id add failed : 0 Router id del failed : 0 Input pack Q full (packet drops):: 0 Input pack Q (enqueued) count:: 224 Input pack Q (dequeued) count:: 224 Recovery Signalled count:: 0 Packet Receive Blocked count:: 0 Packet Processing Blocked count:: 0 [local]Redback# Куда копать, уже ума не приложу. Бьюсь над этими сессия уже 2-ю неделю. Изменено 27 августа, 2013 пользователем ArhAngel_John Вставить ник Цитата Ответить с цитированием Поделиться сообщением Ссылка на сообщение Поделиться на других сайтах More sharing options...
dmvy Опубликовано 27 августа, 2013 · Жалоба Обновление сессии происходит unicast. Возможно вы в admin access list не разрешили абонентам обращаться к роутеру на udp 67. Лиза заканчивается, сессия падает, клиент переходит в состояние init и отправляет dhcp discover broadcast и он уже попадает на se100. Вставить ник Цитата Ответить с цитированием Поделиться сообщением Ссылка на сообщение Поделиться на других сайтах More sharing options...
ArhAngel_John Опубликовано 27 августа, 2013 (изменено) · Жалоба Обновление сессии происходит unicast. Возможно вы в admin access list не разрешили абонентам обращаться к роутеру на udp 67. Лиза заканчивается, сессия падает, клиент переходит в состояние init и отправляет dhcp discover broadcast и он уже попадает на se100. В логах видно что юникаст с реквестом от абонента приходит на СЕ. смотрите логи под спойлером Прилетает DHCP Request когда уже подходит время и без ACL на клиентском интерфейсе происходит тоже самое Изменено 27 августа, 2013 пользователем ArhAngel_John Вставить ник Цитата Ответить с цитированием Поделиться сообщением Ссылка на сообщение Поделиться на других сайтах More sharing options...
ArhAngel_John Опубликовано 28 августа, 2013 · Жалоба Может быть потому что нет у лицензии на subscriber dynamic-service ? [local]Redback#show licenses al [local]Redback#show licenses all Software Feature License Configured -------------------------- ------------------ subscriber dynamic-service NO l2tp NO mpls NO subscriber high-availability NO subscriber active 8000 YES subscriber bandwidth 60 YES media-gateway multimedia NO media-gateway calls NO ipv6 NO multicast-routing NO subscriber active ipv6 NO ces NO all-ports NO nat enhanced NO media-gateway msrp NO media-gateway srtp NO eps sgw NO eps combined-gw NO eps pgw NO eps gn-gp NO eps charging offline cdr NO eps charging offline rf NO eps gx NO Total active subscriber license configured 8000 [local]Redback# [local]Redback# Вставить ник Цитата Ответить с цитированием Поделиться сообщением Ссылка на сообщение Поделиться на других сайтах More sharing options...
ArhAngel_John Опубликовано 4 сентября, 2013 · Жалоба Тогда вопрос: а время жизни сессии в SE вообще должно обновляться? Или всё-таки сессия рано или поздно всё равно умрёт? Вставить ник Цитата Ответить с цитированием Поделиться сообщением Ссылка на сообщение Поделиться на других сайтах More sharing options...
ArhAngel_John Опубликовано 6 сентября, 2013 · Жалоба Сделал в настройках LBarcd Максимальная длительность сессии (сек): 0 Теперь в Access-Accept передаётся 06.09.2013 12:33:44 VERBOSE 0x7f9cfd7fb700 [RunAuthRequest:498] =============== Output attributes dump: =============== 06.09.2013 12:33:44 VERBOSE 0x7f9cfd7fb700 [RunAuthRequest:601] Attribute 'Session-Timeout', value: "0" 06.09.2013 12:33:44 VERBOSE 0x7f9cfd7fb700 [RunAuthRequest:607] Attribute 'Service-Type', value: "5" 06.09.2013 12:33:44 VERBOSE 0x7f9cfd7fb700 [RunAuthRequest:622] VSA 'Assigned-IP-Address', vendor 2352, value: "3.4.5.230" (replaces 'Framed-IP-Address') 06.09.2013 12:33:44 VERBOSE 0x7f9cfd7fb700 [RunAuthRequest:630] Attribute 'Class', value: "00015864" 06.09.2013 12:33:44 VERBOSE 0x7f9cfd7fb700 [RunAuthRequest:633] Attribute 'Tunnel-Private-Group-ID', value: "15" 06.09.2013 12:33:44 VERBOSE 0x7f9cfd7fb700 [RunAuthRequest:683] Attribute 'Acct-Interim-Interval', value: "600" 06.09.2013 12:33:44 VERBOSE 0x7f9cfd7fb700 [AddAttrs:632] VSA 'DHCP-Max-Leases', vendor 2352, value: "1" 06.09.2013 12:33:44 VERBOSE 0x7f9cfd7fb700 [AddAttrs:632] VSA 'IP-Interface-Name', vendor 2352, value: "CLIENTS" 06.09.2013 12:33:44 VERBOSE 0x7f9cfd7fb700 [HandleRadius:101] <=<=<=<=<=<=<=< Authentication answer sent successfully, time: 0.012 <=<=<=<=<=<=<=< [local]Redback#show subs act 10:bf:48:d9:cd:32 Session state Up Circuit 2/2 clips 131141 Internal Circuit 2/2:511:63:31/7/2/69 Interface bound CLIENTS Current port-limit unlimited Protocol Stack IPV4 dhcp max-addrs 1 (applied) dhcp vendor class id MSFT 5.0 (applied) dhcp option client id 0x3d070110bf48d9cd32 (applied) dhcp option hostname 0x0c084b72697374696e61 (applied) timeout absolute 0 (applied) acct-interim-interval 600 (applied) qos-policing-policy TARIF-DEFAULT-512K-IN (applied from sub_default) qos-metering-policy TARIF-DEFAULT-512K-OUT (applied from sub_default) IP host entries installed by DHCP: (max_addr 1 cur_entries 1) 3.4.5.230 10:bf:48:d9:cd:32 [local]Redback# И сессия живёт до тех пока не придёт disconnect по CoA, либо не закончиться ttl в привязке DHCP Proxy. (show dhcp relay hosts) Вставить ник Цитата Ответить с цитированием Поделиться сообщением Ссылка на сообщение Поделиться на других сайтах More sharing options...
