forum.bitel.ru
http://forum.bitel.ru/

Опять вылезла проблема с постоянным закрытием сессии
http://forum.bitel.ru/viewtopic.php?f=44&t=9221		 Страница 1 из 1
Автор:  dm777 [ 08 май 2014, 15:40 ]
Заголовок сообщения:  Опять вылезла проблема с постоянным закрытием сессии
Код:
  Acct-Update-Reason=25
  Mac-Addr=00-25-22-b9-dc-a3
  Acct-Mcast-In-Octets=0
  Acct-Mcast-Out-Octets=0
  Acct-Mcast-In-Packets=0
  Acct-Mcast-Out-Packets=0
  Platform-Type=4
  Medium-Type=11
  Agent-Remote-Id={F8 F0 82 10 4D 0E}
  Agent-Circuit-Id={00 06 00 60 01 00 00 0E}
  IP-Interface-Name=CLIPS-001
  Service-Name=RSE-SVC-EXT
  Service-Options:0=1
  OS-Version=12.1.1.5
  UNKNOWN[2352-125]={4D 53 46 54 20 35 2E 30}
  NAS-Real-Port=553648328
  UNKNOWN[3561--1]={02 08 F8 F0 82 10 4D 0E}
  UNKNOWN[3561--1]={01 0A 00 06 00 60 01 00 00 0E}
Common options: {macAddress=00-25-22-b9-dc-a3, parentAcctSessionId=0100FFFF7800AC26-536BA9D6, serviceName=RSE-SVC-EXT}
05-08/13:31:00  INFO [rdsLstnr-p-7-t-7] InetRadiusProcessor - Session 0100FFFF7800AC26-536BA9D6-RSE-SVC-EXT-80B9EB93 found.
05-08/13:31:00  INFO [rdsLstnr-p-7-t-6] InetConnectionRuntime - Stopping connection with id=45432
05-08/13:31:00  INFO [rdsLstnr-p-7-t-9] RadiusListenerWorker - REQUEST:
Packet type: Accounting-Request


Это происходит только для абонентов с одного коммутатора у остальных все нормально ...
Автор:  Amir [ 08 май 2014, 15:52 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
Нужен более полный лог для потока [rdsLstnr-p-7-t-6].
И RADIUS/DHCP лог сессии, которая была закрыта.
Автор:  dm777 [ 08 май 2014, 16:00 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
Код:
Process time start: 311

05-08/13:31:00  INFO [rdsLstnr-p-7-t-6] RadiusListenerWorker - REQUEST:
Packet type: Accounting-Request
Identifier: 158
Authenticator: {42 0B 05 39 D6 C8 A9 55 3B 22 3A 72 4E C4 96 71}
Attributes:
  User-Name=00:25:22:b9:dc:a3
  NAS-Identifier=Redback-IPOE
  NAS-Port=553648328
  Service-Type=5
  Acct-Input-Octets=0
  Acct-Output-Octets=0
  Acct-Status-Type=2
  Acct-Delay-Time=10
  Acct-Session-Time=1
  Acct-Input-Packets=0
  Acct-Session-Id=0100FFFF7800AC26-536BA9D6
  Acct-Authentic=1
  Acct-Interim-Interval=900
  NAS-Port-Id=2/1 vlan-id 200 clips 175142
 Acct-Terminate-Cause=1
  Acct-Output-Packets=0
  Event-Timestamp=1399564760
  Acct-Output-Gigawords=0
  Acct-Input-Gigawords=0
  NAS-Port-Type=5
  Called-Station-Id=10.1.0.1
  Acct-Mcast-Out-Packets-64={00 00 00 00 00 00 00 00}
  DHCP-Max-Leases=1
  Context-Name=IPOE
  UNKNOWN[2352-201]={01 0A 01 00 01}
  Session-Error-Msg=Client released DHCP lease
  UNKNOWN[2352-202]={3D 3D 07 01 00 25 22 B9 DC A3}
  UNKNOWN[2352-202]={0C 0C 06 55 53 45 52 2D 43}
  Session-Error-Code=190
  Acct-Output-Octets-64={00 00 00 00 00 00 00 00}
  Acct-Input-Octets-64={00 00 00 00 00 00 00 00}
  Acct-Output-Packets-64={00 00 00 00 00 00 00 00}
  Acct-Input-Packets-64={00 00 00 00 00 00 00 00}
  Acct-Mcast-In-Octets-64={00 00 00 00 00 00 00 00}
Assigned-IP-Address=10.1.0.21
  Acct-Mcast-In-Packets-64={00 00 00 00 00 00 00 00}
  Acct-Mcast-Out-Octets-64={00 00 00 00 00 00 00 00}
  Qos-Policing-Profile-Name=RATE-DEF-IN
  Acct-Update-Reason=2
  Mac-Addr=00-25-22-b9-dc-a3
  Acct-Mcast-In-Octets=0
  Acct-Mcast-Out-Octets=0
  Qos-Metering-Profile-Name=RATE-DEF-OUT
  Acct-Mcast-In-Packets=0
  Acct-Mcast-Out-Packets=0
  Platform-Type=4
  Medium-Type=11
  Agent-Remote-Id={F8 F0 82 10 4D 0E}
  Agent-Circuit-Id={00 06 00 60 01 00 00 0E}
  IP-Interface-Name=CLIPS-001
  NAT-Policy-Name=1
  OS-Version=12.1.1.5
  UNKNOWN[2352-125]={4D 53 46 54 20 35 2E 30}
  NAS-Real-Port=553648328
UNKNOWN[3561--1]={02 08 F8 F0 82 10 4D 0E}
  UNKNOWN[3561--1]={01 0A 00 06 00 60 01 00 00 0E}

05-08/13:31:00  INFO [rdsLstnr-p-7-t-6] XSmartEdgeClipsProtocolHandler - Radius SNR: setAgentOption

05-08/13:31:00  INFO [rdsLstnr-p-7-t-6] InetRadiusProcessor - REQUEST_AFTER_PREPROCESS:
Packet type: Accounting-Request
Identifier: 158
Authenticator: {42 0B 05 39 D6 C8 A9 55 3B 22 3A 72 4E C4 96 71}
Attributes:
  User-Name=f8f082104d0e:000600600100000e
  NAS-Identifier=Redback-IPOE
  NAS-Port=553648328
  Service-Type=5
  Acct-Input-Octets=0
  Acct-Output-Octets=0
  Acct-Status-Type=2
  Acct-Delay-Time=10
  Acct-Session-Time=1
  Acct-Input-Packets=0
Acct-Session-Id=0100FFFF7800AC26-536BA9D6
  Acct-Authentic=1
  Acct-Interim-Interval=900
  NAS-Port-Id=2/1 vlan-id 200 clips 175142
  Acct-Terminate-Cause=1
  Acct-Output-Packets=0
  Event-Timestamp=1399564760
  Acct-Output-Gigawords=0
  Acct-Input-Gigawords=0
  Calling-Station-Id=002522b9dca3
  NAS-Port-Type=5
  Called-Station-Id=10.1.0.1
  Acct-Mcast-Out-Packets-64={00 00 00 00 00 00 00 00}
  DHCP-Max-Leases=1
  Context-Name=IPOE
  UNKNOWN[2352-201]={01 0A 01 00 01}
  Session-Error-Msg=Client released DHCP lease
  UNKNOWN[2352-202]={3D 3D 07 01 00 25 22 B9 DC A3}
  UNKNOWN[2352-202]={0C 0C 06 55 53 45 52 2D 43}
  Session-Error-Code=190
Acct-Output-Octets-64={00 00 00 00 00 00 00 00}
  Acct-Input-Octets-64={00 00 00 00 00 00 00 00}
  Acct-Output-Packets-64={00 00 00 00 00 00 00 00}
  Acct-Input-Packets-64={00 00 00 00 00 00 00 00}
  Acct-Mcast-In-Octets-64={00 00 00 00 00 00 00 00}
  Assigned-IP-Address=10.1.0.21
  Acct-Mcast-In-Packets-64={00 00 00 00 00 00 00 00}
  Acct-Mcast-Out-Octets-64={00 00 00 00 00 00 00 00}
  Qos-Policing-Profile-Name=RATE-DEF-IN
  Acct-Update-Reason=2
  Mac-Addr=00-25-22-b9-dc-a3
  Acct-Mcast-In-Octets=0
  Acct-Mcast-Out-Octets=0
  Qos-Metering-Profile-Name=RATE-DEF-OUT
  Acct-Mcast-In-Packets=0
  Acct-Mcast-Out-Packets=0
  Platform-Type=4
  Medium-Type=11
  Agent-Remote-Id={F8 F0 82 10 4D 0E}
  Agent-Circuit-Id={00 06 00 60 01 00 00 0E}
IP-Interface-Name=CLIPS-001
  NAT-Policy-Name=1
  OS-Version=12.1.1.5
  UNKNOWN[2352-125]={4D 53 46 54 20 35 2E 30}
  NAS-Real-Port=553648328
  UNKNOWN[3561--1]={02 08 F8 F0 82 10 4D 0E}
  UNKNOWN[3561--1]={01 0A 00 06 00 60 01 00 00 0E}
Common options: {agentRemoteId={f8f082104d0e}, macAddress=00-25-22-b9-dc-a3, agentCircuitId={000600600100000e}}
05-08/13:31:00  INFO [rdsLstnr-p-7-t-6] InetRadiusProcessor - Session 0100FFFF7800AC26-536BA9D6 found.

05-08/13:31:00  INFO [rdsLstnr-p-7-t-6] InetNas - Stopping NasConnection
05-08/13:31:00  INFO [rdsLstnr-p-7-t-6] connection - 45432:45638 Stopping NasConnection

05-08/13:31:00  INFO [rdsLstnr-p-7-t-6] RadiusListenerWorker - RESPONSE:
Packet type: Accounting-Response
Identifier: 158
Authenticator: {81 1F 9C 46 25 A6 7E 01 7A A7 41 07 E2 AA BF 81}
Attributes:

Process time stop: 40
Автор:  Amir [ 08 май 2014, 16:12 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
Как-будто абонент не продлил DHCP lease во время или не получил ACK на запрос о продлении.
Нужно посмотреть по логам на этот MAC когда последний раз приходил DHCP-запрос до того, как SE прислал stop-пакет, и что на него ответил Access.
Автор:  dm777 [ 08 май 2014, 16:40 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
Странно, но проблема решилась удалением из сети другого коммутатора D-LINK ...
Автор:  dm777 [ 08 май 2014, 17:54 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
Теперь появилась такая ошибка

Код:
dhcp 05-08/15:49:43 ERROR [main] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
dhcp 05-08/15:49:43 ERROR [main] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
dhcp 05-08/15:49:43 ERROR [main] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
dhcp 05-08/15:49:43 ERROR [main] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
dhcp 05-08/15:49:43 ERROR [main] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
dhcp 05-08/15:49:43 ERROR [main] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
dhcp 05-08/15:49:43 ERROR [main] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
dhcp 05-08/15:49:43 ERROR [main] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
radius 05-08/15:50:09 ERROR [rdsLstnr-p-8-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:50:09 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:50:09 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:50:11 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:50:12 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
dhcp 05-08/15:50:29 ERROR [dhcpLstnr-p-10-t-5] InetDhcpHelperProcessor - Not found params for request: 2:F8F082710B31:003A0109:10BF486D877F (pattern: $deviceId:$remote$
mq 05-08/15:50:38 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:50:43 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:51:28 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:52:07 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
radius 05-08/15:52:37 ERROR [rdsLstnr-p-8-t-4] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:52:37 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
radius 05-08/15:52:37 ERROR [rdsLstnr-p-8-t-5] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:52:38 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:52:38 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:52:38 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:52:40 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:52:40 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:52:42 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:52:44 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:53:05 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/15:53:27 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
Автор:  Amir [ 08 май 2014, 17:59 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
InetDhcpHelperProcessor - Not found params for request: 2:F8F082710B31:003A0109:10BF486D877F (pattern: $deviceId:$remote$

Это пришел DHCP-запрос, который Access не смог связать ни с одной текущей сессией.
Автор:  dm777 [ 08 май 2014, 18:03 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
а это откуда
Код:
mq 05-08/15:53:27 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
Автор:  dm777 [ 08 май 2014, 18:13 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
Код:
Common options: {agentRemoteId={f8f082107692}, macAddress=c0-4a-00-98-be-b3, agentCircuitId={0006004901000002}}
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetNas - Found agentDevice:5
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetNas - Search serv on deviceId=5; interfaceId=2
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetNas - Search child serv by mac on device=c04a0098beb3
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetRadiusProcessor - [username=f8f082107692:0006004901000002] Authenticated as inetServId:13
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetApplication - TariffOptionMap: {}
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetApplication - inetServ[id=13] balance ok: 202.58 [0]
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetUtils - Alive session count 2>1
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetConnectionManager - Close duplicate session method 8
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetConnectionManager - Remove connection: InetConnection [id=46070-46069, iface=2:553648328, sessId=0100FFFF7800ADA6-536BCD9B-$
05-08/16:05:53 ERROR [rdsLstnr-p-8-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetConnectionManager - Remove connection: InetConnection [id=46069-0, iface=2:553648328, sessId=0100FFFF7800ADA6-536BCD9B, sta$
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetDhcpHelperProcessor - Remove connection remove 2:F8F082107692:0006004901000002:001A791B39C9
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetApplication - OptionSet: [1, 6]
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetRadiusProcessor - Write new waiting connection to DB
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetRadiusProcessor - New connection id=46093
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetRadiusProcessor - Return code=0
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetDhcpHelperProcessor - Put auth accept 2:F8F082107692:0006004901000002:C04A0098BEB3
05-08/16:05:53  INFO [rdsLstnr-p-8-t-1] InetRadiusProcessor - RESPONSE_BEFORE_POSTPROCESS:
Автор:  Amir [ 08 май 2014, 18:23 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
Это не должно влиять на работу вроде бы, скорее всего и раньше было.
Отображается при поиске по логину, а не по порту или VLAN.
Автор:  dm777 [ 08 май 2014, 18:37 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
вроде работает все только в лог с ошибками сыпется

mq 05-08/16:34:32 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
connection 05-08/16:34:32 ERROR [sa-p-13-t-15] InetSaStateModifyEvent - Connection not found with id=46195
mq 05-08/16:36:27 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
mq 05-08/16:36:28 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT
Автор:  dm777 [ 13 май 2014, 20:54 ]
Заголовок сообщения:  Re: Опять вылезла проблема с постоянным закрытием сессии
Если в конфиге SE100

radius.servSearchMode=1-2

radius.password.verification=0

radius.macAddress.vendor=2352
radius.macAddress.type=145

в логах постоянно сыплет ошибкой, но при этом все работает

mq 05-08/16:34:32 ERROR [event-proc-p-2-t-1] InetDhcpHelperProcessor - Incorrect userName: RSE-SVC-EXT

если

radius.servSearchMode=1

ошибок нет, но возникает проблема с дочерними сервисами по МАКу (IPTV)

некоторые приставки получают адреса нормально, некоторые постоянно "отбирают" адрес у родительского сервиса
Страница 1 из 1 Часовой пояс: UTC + 5 часов [ Летнее время ]
Powered by phpBB® Forum Software © phpBB Group
http://www.phpbb.com/