URL: https://www.opennet.me/cgi-bin/openforum/vsluhboard.cgi
Форум: vsluhforumID1
Нить номер: 75672
[ Назад ]

Исходное сообщение
"FreeRadius. Cisco. PPPoE. Не пишет в mysql конец сессии."

Отправлено gsv , 14-Авг-07 14:12 
Добрый день.

Есть Сisco 5350. На ней терминируются pppoe соединения. Аутентификация и аккаунтинг пытаюсь настроить на freeradius с базой пользователей в mysql. С аутентификацией проблем нет. С аккаунтингом вот что:
NAS шлёт радиусу Interim-Update пакеты, они видны в логах для этого NASa. Записи также попадают в таблицу radacct. Т.е. отрабатывают запросы accounting_start_query и accounting_update_query, описанные в файле sql.conf. Это видно и в sqltrace.log.
Когда корректно завершаю сессию pppoe, на радиус посытается Acct-Status-Type = Stop.
Это видно в логах. Но запрос accounting_stop_query или accounting_stop_query_alt не отрабатывает и в таблице radacct остаётся незавершенная сессия с AcctStopTime = 0000-00-00 00:00:00.
В файле sqltrace.log тоже нет попытки выполнить запрос завершения сессии.
В чём может быть дело?
Почему не отрабатывает запрос в mysql при завершении сессии?


Содержание

Сообщения в этом обсуждении
"FreeRadius. Cisco. PPPoE. Не пишет в mysql конец сессии."
Отправлено STS , 14-Авг-07 15:29 
Как выглядит accounting_stop_query  в sql.conf ?

"FreeRadius. Cisco. PPPoE. Не пишет в mysql конец сессии."
Отправлено gsv , 14-Авг-07 15:32 
>Как выглядит accounting_stop_query  в sql.conf ?

  accounting_stop_query = "UPDATE ${acct_table2} SET AcctStopTime = '%S', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets = '%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}', AcctTerminateCause = '%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}', ConnectInfo_stop = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}' AND NASIPAddress = '%{NAS-IP-Address}'"


"FreeRadius. Cisco. PPPoE. Не пишет в mysql конец сессии."
Отправлено STS , 14-Авг-07 15:42 
>>Как выглядит accounting_stop_query  в sql.conf ?
>
>  accounting_stop_query = "UPDATE ${acct_table2} SET AcctStopTime = '%S', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets
>= '%{Acct-Input-Octets}', AcctOutputOctets = '%{Acct-Output-Octets}', AcctTerminateCause = '%{Acct-Terminate-Cause}', AcctStopDelay = '%{Acct-Delay-Time}',
>ConnectInfo_stop = '%{Connect-Info}' WHERE AcctSessionId = '%{Acct-Session-Id}' AND UserName = '%{SQL-User-Name}'
>AND NASIPAddress = '%{NAS-IP-Address}'"

Попробуйте этот же запрос (с реальными значениями вместо переменных) вручную, из шелла mysql. Мне кажется, он завершится ошибкой.


"FreeRadius. Cisco. PPPoE. Не пишет в mysql конец сессии."
Отправлено gsv , 14-Авг-07 15:48 
>Попробуйте этот же запрос (с реальными значениями вместо переменных) вручную, из шелла
>mysql. Мне кажется, он завершится ошибкой.

Попробывал этот запрос с реальными данными - отработал без ошибок.
UPDATE radacct SET AcctStopTime = '2007-08-14 15:33:06', AcctSessionTime = '1212', AcctInputOctets = '99999999', AcctOutputOctets = '777777777', AcctTerminateCause = 'User', AcctStopDelay = '1',
ConnectInfo_stop = '' WHERE AcctSessionId = '000023BF' AND UserName = 'gsv123' AND NASIPAddress = '192.168.99.1'


"FreeRadius. Cisco. PPPoE. Не пишет в mysql конец сессии."
Отправлено gsv , 14-Авг-07 16:50 
запускаем radiusd -X

Когда приходит пакет от NAS с промежуточным обновлением, видим, что запрос выполняется:
rad_recv: Accounting-Request packet from host 192.168.99.1:1646, id=211, length=278
        Acct-Session-Id = "000023CA"
        Cisco-AVPair = "client-mac-address=0014.2a41.3dd1"
        Framed-Protocol = PPP
        Framed-IP-Address = 192.168.222.222
        User-Name = "gsv123"
        Cisco-AVPair = "connect-progress=LAN Ses Up"
        Cisco-AVPair = "nas-tx-speed=950000"
        Cisco-AVPair = "nas-rx-speed=950000"
        Acct-Session-Time = 63
        Acct-Input-Octets = 1523
        Acct-Output-Octets = 290
        Acct-Input-Packets = 26
        Acct-Output-Packets = 19
        Acct-Authentic = RADIUS
        Acct-Status-Type = Interim-Update
        NAS-Port-Type = Virtual
        Cisco-NAS-Port = "0/0/1/33"
        NAS-Port = 0
        NAS-Port-Id = "0/0/1/33"
        Service-Type = Framed-User
        NAS-IP-Address = 192.168.99.1
        Acct-Delay-Time = 15
  Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 0
  modcall[preacct]: module "preprocess" returns noop for request 0
rlm_acct_unique: Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.99.1,NAS-IP-Address = 192.168.99.1,Acct-Session-Id = "000023CA",User-Name = "gsv123"'
rlm_acct_unique: Acct-Unique-Session-ID = "42cd7dcfe62ebb17".
  modcall[preacct]: module "acct_unique" returns ok for request 0
    rlm_realm: No '@' in User-Name = "gsv123", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[preacct]: module "suffix" returns noop for request 0
modcall: leaving group preacct (returns ok) for request 0
  Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 0
radius_xlat:  '/var/log/radacct/192.168.99.1/detail-20070814'
rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/192.168.99.1/detail-20070814
  modcall[accounting]: module "detail" returns ok for request 0
  modcall[accounting]: module "unix" returns noop for request 0
radius_xlat:  '/var/log/radutmp'
radius_xlat:  'gsv123'
  modcall[accounting]: module "radutmp" returns ok for request 0
radius_xlat:  'gsv123'
rlm_sql (sql): sql_set_user escaped user --> 'gsv123'
radius_xlat:  'UPDATE radacct           SET FramedIPAddress = '192.168.222.222',           AcctSessionTime = '63',           AcctInputOctets = '1523',           AcctOutputOctets = '290'           WHERE AcctSessionId = '000023CA'           AND UserName = 'gsv123'           AND NASIPAddress= '192.168.99.1''
radius_xlat:  '/var/log/radacct/sqltrace.sql'
rlm_sql (sql): Reserving sql socket id: 4
rlm_sql_mysql: query:  UPDATE radacct           SET FramedIPAddress = '192.168.222.222',           AcctSessionTime = '63',           AcctInputOctets = '1523',           AcctOutputOctets = '290'           WHERE AcctSessionId = '000023CA'           AND UserName = 'gsv123'           AND NASIPAddress= '192.168.99.1'
rlm_sql (sql): Released sql socket id: 4
  modcall[accounting]: module "sql" returns ok for request 0
modcall: leaving group accounting (returns ok) for request 0
Sending Accounting-Response of id 211 to 192.168.99.1 port 1646
Finished request 0
Going to the next request

когда приходит пакет stop, видим:

Cleaning up request 0 ID 252 with timestamp 46c1a480
Nothing to do.  Sleeping until we see a request.
rad_recv: Accounting-Request packet from host 192.168.99.1:1646, id=254, length=323
        Acct-Session-Id = "000023CA"
        Cisco-AVPair = "client-mac-address=0014.2a41.3dd1"
        Framed-Protocol = PPP
        Framed-IP-Address = 192.168.222.222
        User-Name = "gsv123"
        Acct-Authentic = RADIUS
        Cisco-AVPair = "connect-progress=LAN Ses Up"
        Cisco-AVPair = "nas-tx-speed=950000"
        Cisco-AVPair = "nas-rx-speed=950000"
        Acct-Session-Time = 194
        Acct-Input-Octets = 2069
        Acct-Output-Octets = 646
        Acct-Input-Packets = 53
        Acct-Output-Packets = 45
        Acct-Terminate-Cause = User-Request
        Cisco-AVPair = "disc-cause-ext=PPP Receive Term"
        Acct-Status-Type = Stop
        NAS-Port-Type = Virtual
        Cisco-NAS-Port = "0/0/1/33"
        NAS-Port = 0
        NAS-Port-Id = "0/0/1/33"
        Service-Type = Framed-User
        NAS-IP-Address = 192.168.99.1
        Acct-Delay-Time = 0
  Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 1
  modcall[preacct]: module "preprocess" returns noop for request 1
rlm_acct_unique: Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.99.1,NAS-IP-Address = 192.168.99.1,Acct-Session-Id = "000023CA",User-Name = "gsv123"'
rlm_acct_unique: Acct-Unique-Session-ID = "42cd7dcfe62ebb17".
  modcall[preacct]: module "acct_unique" returns ok for request 1
    rlm_realm: No '@' in User-Name = "gsv123", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[preacct]: module "suffix" returns noop for request 1
modcall: leaving group preacct (returns ok) for request 1
  Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 1
radius_xlat:  '/var/log/radacct/192.168.99.1/detail-20070814'
rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/192.168.99.1/detail-20070814
  modcall[accounting]: module "detail" returns ok for request 1
  modcall[accounting]: module "unix" returns fail for request 1
modcall: leaving group accounting (returns fail) for request 1
Finished request 1
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Accounting-Request packet from host 192.168.99.1:1646, id=2, length=323
        Acct-Session-Id = "000023CA"
        Cisco-AVPair = "client-mac-address=0014.2a41.3dd1"
        Framed-Protocol = PPP
        Framed-IP-Address = 192.168.222.222
        User-Name = "gsv123"
        Acct-Authentic = RADIUS
        Cisco-AVPair = "connect-progress=LAN Ses Up"
        Cisco-AVPair = "nas-tx-speed=950000"
        Cisco-AVPair = "nas-rx-speed=950000"
        Acct-Session-Time = 194
        Acct-Input-Octets = 2069
        Acct-Output-Octets = 646
        Acct-Input-Packets = 53
        Acct-Output-Packets = 45
        Acct-Terminate-Cause = User-Request
        Cisco-AVPair = "disc-cause-ext=PPP Receive Term"
        Acct-Status-Type = Stop
        NAS-Port-Type = Virtual
        Cisco-NAS-Port = "0/0/1/33"
        NAS-Port = 0
        NAS-Port-Id = "0/0/1/33"
        Service-Type = Framed-User
        NAS-IP-Address = 192.168.99.1
        Acct-Delay-Time = 5
  Processing the preacct section of radiusd.conf
modcall: entering group preacct for request 2
  modcall[preacct]: module "preprocess" returns noop for request 2
rlm_acct_unique: Hashing 'NAS-Port = 0,Client-IP-Address = 192.168.99.1,NAS-IP-Address = 192.168.99.1,Acct-Session-Id = "000023CA",User-Name = "gsv123"'
rlm_acct_unique: Acct-Unique-Session-ID = "42cd7dcfe62ebb17".
  modcall[preacct]: module "acct_unique" returns ok for request 2
    rlm_realm: No '@' in User-Name = "gsv123", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[preacct]: module "suffix" returns noop for request 2
modcall: leaving group preacct (returns ok) for request 2
  Processing the accounting section of radiusd.conf
modcall: entering group accounting for request 2
radius_xlat:  '/var/log/radacct/192.168.99.1/detail-20070814'
rlm_detail: /var/log/radacct/%{Client-IP-Address}/detail-%Y%m%d expands to /var/log/radacct/192.168.99.1/detail-20070814
  modcall[accounting]: module "detail" returns ok for request 2
  modcall[accounting]: module "unix" returns fail for request 2
modcall: leaving group accounting (returns fail) for request 2
Finished request 2
Going to the next request
--- Walking the entire request list ---
Cleaning up request 1 ID 254 with timestamp 46c1a486
Waking up in 6 seconds...                                                                          

т.е. даже нет попытки выполнить какой-то sql запрос...
А может быть радиус не понимает, что пришел stop пакет?
Есть какие-то соображения?


"FreeRadius. Cisco. PPPoE. Не пишет в mysql конец сессии."
Отправлено gsv , 15-Авг-07 11:35 
На Cisco настройки, как рекомендовано:

aaa new-model
radius-server host 192.168.99.5 auth-port 1745 acct-port 1746
aaa authorization network radius
aaa authorization exec radius
aaa authentication login radius_auth local radius
aaa authentication ppp ppp_auth radius
aaa accounting network start-stop radius
aaa accounting connection start-stop radius
aaa accounting update newinfo periodic 1


interface Virtual-Template4
mtu 1460
ip unnumbered Loopback0
ip tcp adjust-mss 1420
no logging event link-status
no peer default ip address
keepalive 5
ppp mtu adaptive
ppp authentication chap default
ppp authorization default
ppp accounting default
ppp chap hostname gsv
end