Ошибка 691
4 views
Skip to first unread message
JasonX
May 16, 2008, 5:28:42 AM5/16/08
to cakebilling
Debian 4 etch r0
resin-3.0.24
postgresql-7.4
freeradius_1.1.7-1
radiusclient1_0.3.2-11
libradius1_0.3.2-11
java-common_0.25
postgresql-8.3-603.jdbc3.jar
sun-java5-jdk_1.5.0-14-1etch1
cake-1.0.3.war
cake-v1.0.1.sql
При попытке подключения к pptp серверу пользователю после проверки
имени пользователя выдаётся сообщение об ошибке 691(не правильное имя
или пароль) . Пользователя создал через веб-интерфейс. В логах
postgresql ошибок нет(вообще ничего не выдаёт в процесе создания;)
В базе он есть
psql -h 127.0.0.1 -U cake -c "select * from cake.users;"
Password:
id | login | name | pwd | balance | userblock | overtraffblock |
ip_addr | id_tariff | grp
----+-------+-------+------+---------+-----------+----------------
+---------+-----------+-----
1 | admin | Admin | 1234 | 0.00 | f | t
| 2 | 1 | 1
2 | 111 | 111 | 111 | 1.00 | f | t
| 3 | 1 | 0
3 | 1 | 1 | 1 | 1.00 | f | t
| 4 | 1 | 0
(3 rows)
Логи pptpd
May 23 00:11:53 localhost pppd[5730]: Plugin radius.so loaded.
May 23 00:11:53 localhost pppd[5730]: RADIUS plugin initialized.
May 23 00:11:53 localhost pppd[5730]: pppd options in effect:
May 23 00:11:53 localhost pppd[5730]: debug debug^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: dump^I^I# (from /etc/ppp/pptpd-
options)
May 23 00:11:53 localhost pppd[5730]: plugin radius.so^I^I# (from /etc/
ppp/pptpd-options)
May 23 00:11:53 localhost pppd[5730]: +mschap^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: name pptpd^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: 115200^I^I# (from command line)
May 23 00:11:53 localhost pppd[5730]: lock^I^I# (from /etc/ppp/pptpd-
options)
May 23 00:11:53 localhost pppd[5730]: crtscts^I^I# (from /etc/ppp/
options)
May 23 00:11:53 localhost pppd[5730]: local^I^I# (from command line)
May 23 00:11:53 localhost pppd[5730]: asyncmap 0^I^I# (from /etc/ppp/
options)
May 23 00:11:53 localhost pppd[5730]: silent^I^I# (from /etc/ppp/pptpd-
options)
May 23 00:11:53 localhost pppd[5730]: lcp-echo-failure 4^I^I# (from /
etc/ppp/options)
May 23 00:11:53 localhost pppd[5730]: lcp-echo-interval 30^I^I# (from /
etc/ppp/options)
May 23 00:11:53 localhost pppd[5730]: hide-password^I^I# (from /etc/
ppp/options)
May 23 00:11:53 localhost pppd[5730]: ipparam 192.168.1.10^I^I# (from
command line)
May 23 00:11:53 localhost pppd[5730]: ms-dns xxx # [don't know how to
print value]^I^I# (from /etc/ppp/pptpd-options)
May 23 00:11:53 localhost pppd[5730]: proxyarp^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: 192.168.1.1:192.168.1.1^I^I#
(from command line)
May 23 00:11:53 localhost pppd[5730]: nobsdcomp^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: nodeflate^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: noipx^I^I# (from /etc/ppp/
options)
May 23 00:11:53 localhost pppd[5730]: pppd 2.4.4 started by root, uid
0
May 23 00:11:53 localhost pppd[5730]: Using interface ppp0
May 23 00:11:53 localhost pppd[5730]: Connect: ppp0 <--> /dev/pts/5
May 23 00:11:54 localhost pppd[5730]: Peer 123 failed CHAP
authentication
May 23 00:11:54 localhost pppd[5730]: Connection terminated.
May 23 00:11:54 localhost pppd[5730]: tcflush failed: Input/output
error
May 23 00:11:54 localhost pppd[5730]: Exit.
resin-3.0.24
postgresql-7.4
freeradius_1.1.7-1
radiusclient1_0.3.2-11
libradius1_0.3.2-11
java-common_0.25
postgresql-8.3-603.jdbc3.jar
sun-java5-jdk_1.5.0-14-1etch1
cake-1.0.3.war
cake-v1.0.1.sql
При попытке подключения к pptp серверу пользователю после проверки
имени пользователя выдаётся сообщение об ошибке 691(не правильное имя
или пароль) . Пользователя создал через веб-интерфейс. В логах
postgresql ошибок нет(вообще ничего не выдаёт в процесе создания;)
В базе он есть
psql -h 127.0.0.1 -U cake -c "select * from cake.users;"
Password:
id | login | name | pwd | balance | userblock | overtraffblock |
ip_addr | id_tariff | grp
----+-------+-------+------+---------+-----------+----------------
+---------+-----------+-----
1 | admin | Admin | 1234 | 0.00 | f | t
| 2 | 1 | 1
2 | 111 | 111 | 111 | 1.00 | f | t
| 3 | 1 | 0
3 | 1 | 1 | 1 | 1.00 | f | t
| 4 | 1 | 0
(3 rows)
Логи pptpd
May 23 00:11:53 localhost pppd[5730]: Plugin radius.so loaded.
May 23 00:11:53 localhost pppd[5730]: RADIUS plugin initialized.
May 23 00:11:53 localhost pppd[5730]: pppd options in effect:
May 23 00:11:53 localhost pppd[5730]: debug debug^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: dump^I^I# (from /etc/ppp/pptpd-
options)
May 23 00:11:53 localhost pppd[5730]: plugin radius.so^I^I# (from /etc/
ppp/pptpd-options)
May 23 00:11:53 localhost pppd[5730]: +mschap^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: name pptpd^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: 115200^I^I# (from command line)
May 23 00:11:53 localhost pppd[5730]: lock^I^I# (from /etc/ppp/pptpd-
options)
May 23 00:11:53 localhost pppd[5730]: crtscts^I^I# (from /etc/ppp/
options)
May 23 00:11:53 localhost pppd[5730]: local^I^I# (from command line)
May 23 00:11:53 localhost pppd[5730]: asyncmap 0^I^I# (from /etc/ppp/
options)
May 23 00:11:53 localhost pppd[5730]: silent^I^I# (from /etc/ppp/pptpd-
options)
May 23 00:11:53 localhost pppd[5730]: lcp-echo-failure 4^I^I# (from /
etc/ppp/options)
May 23 00:11:53 localhost pppd[5730]: lcp-echo-interval 30^I^I# (from /
etc/ppp/options)
May 23 00:11:53 localhost pppd[5730]: hide-password^I^I# (from /etc/
ppp/options)
May 23 00:11:53 localhost pppd[5730]: ipparam 192.168.1.10^I^I# (from
command line)
May 23 00:11:53 localhost pppd[5730]: ms-dns xxx # [don't know how to
print value]^I^I# (from /etc/ppp/pptpd-options)
May 23 00:11:53 localhost pppd[5730]: proxyarp^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: 192.168.1.1:192.168.1.1^I^I#
(from command line)
May 23 00:11:53 localhost pppd[5730]: nobsdcomp^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: nodeflate^I^I# (from /etc/ppp/
pptpd-options)
May 23 00:11:53 localhost pppd[5730]: noipx^I^I# (from /etc/ppp/
options)
May 23 00:11:53 localhost pppd[5730]: pppd 2.4.4 started by root, uid
0
May 23 00:11:53 localhost pppd[5730]: Using interface ppp0
May 23 00:11:53 localhost pppd[5730]: Connect: ppp0 <--> /dev/pts/5
May 23 00:11:54 localhost pppd[5730]: Peer 123 failed CHAP
authentication
May 23 00:11:54 localhost pppd[5730]: Connection terminated.
May 23 00:11:54 localhost pppd[5730]: tcflush failed: Input/output
error
May 23 00:11:54 localhost pppd[5730]: Exit.
Anatoly Shipitsin
May 16, 2008, 5:34:21 AM5/16/08
to cakeb...@googlegroups.com
16 мая 2008 г. 15:28 пользователь JasonX <Jas...@tut.by> написал:
Debian 4 etch r0
resin-3.0.24
postgresql-7.4
freeradius_1.1.7-1
radiusclient1_0.3.2-11
libradius1_0.3.2-11
java-common_0.25
postgresql-8.3-603.jdbc3.jar
sun-java5-jdk_1.5.0-14-1etch1
cake-1.0.3.war
cake-v1.0.1.sql
Во первых перестаньте писать эту муть каждый раз. В случае если у вас спросят тогда и пишите.
Я эту штуку вижу уже не впервый раз.
Я эту штуку вижу уже не впервый раз.
При попытке подключения к pptp серверу пользователю после проверки
имени пользователя выдаётся сообщение об ошибке 691(не правильное имя
или пароль) .
Значит или неправильно введены данные или у вас неверно настроен компьютер.
May 23 00:11:54 localhost pppd[5730]: Peer 123 failed CHAP
authentication
А вот эта строка говорит что пользователь у вас 123 а в базе пользователь 111.
Включайте уже голову и читайте логи. Если вы хотите чтобы мы за вас читали логи за вас,
то извольте платить деньги за платную тех поддержку.
Включайте уже голову и читайте логи. Если вы хотите чтобы мы за вас читали логи за вас,
то извольте платить деньги за платную тех поддержку.
JasonX
May 23, 2008, 10:23:21 AM5/23/08
to cakebilling
Извините
Я привёл в postgresql созданных пользователей, когда там ещё не было
пользователя 123. На самоа деле он там есть.
Я привёл в postgresql созданных пользователей, когда там ещё не было
пользователя 123. На самоа деле он там есть.
Anatoly Shipitsin
May 23, 2008, 11:45:08 AM5/23/08
to cakeb...@googlegroups.com
23 мая 2008 г. 20:23 пользователь JasonX <Jas...@tut.by> написал:
Извините
Я привёл в postgresql созданных пользователей, когда там ещё не было
пользователя 123. На самоа деле он там есть.
Запускайте FreeRADIUS с дебагом и смотрите что и как.
JasonX
May 26, 2008, 8:25:54 AM5/26/08
to cakebilling
freeradius -X -X
Mon Jun 2 03:15:45 2008 : Info: Starting - reading configuration
files ...
Mon Jun 2 03:15:45 2008 : Debug: reread_config: reading radiusd.conf
Mon Jun 2 03:15:45 2008 : Debug: Config: including file: /etc/
freeradius/proxy.conf
Mon Jun 2 03:15:45 2008 : Debug: Config: including file: /etc/
freeradius/clients.conf
Mon Jun 2 03:15:45 2008 : Debug: Config: including file: /etc/
freeradius/snmp.conf
Mon Jun 2 03:15:45 2008 : Debug: Config: including file: /etc/
freeradius/eap.conf
Mon Jun 2 03:15:45 2008 : Debug: Config: including file: /etc/
freeradius/sql.conf
Mon Jun 2 03:15:45 2008 : Debug: main: prefix = "/usr"
Mon Jun 2 03:15:45 2008 : Debug: main: localstatedir = "/var"
Mon Jun 2 03:15:45 2008 : Debug: main: logdir = "/var/log/
freeradius"
Mon Jun 2 03:15:45 2008 : Debug: main: libdir = "/usr/lib/
freeradius"
Mon Jun 2 03:15:45 2008 : Debug: main: radacctdir = "/var/log/
freeradius/radacct"
Mon Jun 2 03:15:45 2008 : Debug: main: hostname_lookups = no
Mon Jun 2 03:15:45 2008 : Debug: main: snmp = no
Mon Jun 2 03:15:45 2008 : Debug: main: max_request_time = 30
Mon Jun 2 03:15:45 2008 : Debug: main: cleanup_delay = 5
Mon Jun 2 03:15:45 2008 : Debug: main: max_requests = 1024
Mon Jun 2 03:15:45 2008 : Debug: main: delete_blocked_requests = 0
Mon Jun 2 03:15:45 2008 : Debug: main: port = 0
Mon Jun 2 03:15:45 2008 : Debug: main: allow_core_dumps = no
Mon Jun 2 03:15:45 2008 : Debug: main: log_stripped_names = no
Mon Jun 2 03:15:45 2008 : Debug: main: log_file = "/var/log/
freeradius/radius.log"
Mon Jun 2 03:15:45 2008 : Debug: main: log_auth = no
Mon Jun 2 03:15:45 2008 : Debug: main: log_auth_badpass = no
Mon Jun 2 03:15:45 2008 : Debug: main: log_auth_goodpass = no
Mon Jun 2 03:15:45 2008 : Debug: main: pidfile = "/var/run/
freeradius/freeradius.pid"
Mon Jun 2 03:15:45 2008 : Debug: main: user = "freerad"
Mon Jun 2 03:15:45 2008 : Debug: main: group = "freerad"
Mon Jun 2 03:15:45 2008 : Debug: main: usercollide = no
Mon Jun 2 03:15:45 2008 : Debug: main: lower_user = "no"
Mon Jun 2 03:15:45 2008 : Debug: main: lower_pass = "no"
Mon Jun 2 03:15:45 2008 : Debug: main: nospace_user = "no"
Mon Jun 2 03:15:45 2008 : Debug: main: nospace_pass = "no"
Mon Jun 2 03:15:45 2008 : Debug: main: checkrad = "/usr/sbin/
checkrad"
Mon Jun 2 03:15:45 2008 : Debug: main: proxy_requests = yes
Mon Jun 2 03:15:45 2008 : Debug: proxy: retry_delay = 5
Mon Jun 2 03:15:45 2008 : Debug: proxy: retry_count = 3
Mon Jun 2 03:15:45 2008 : Debug: proxy: synchronous = no
Mon Jun 2 03:15:45 2008 : Debug: proxy: default_fallback = yes
Mon Jun 2 03:15:45 2008 : Debug: proxy: dead_time = 120
Mon Jun 2 03:15:45 2008 : Debug: proxy: post_proxy_authorize = no
Mon Jun 2 03:15:45 2008 : Debug: proxy: wake_all_if_all_dead = no
Mon Jun 2 03:15:45 2008 : Debug: security: max_attributes = 200
Mon Jun 2 03:15:45 2008 : Debug: security: reject_delay = 1
Mon Jun 2 03:15:45 2008 : Debug: security: status_server = no
Mon Jun 2 03:15:45 2008 : Debug: main: debug_level = 0
Mon Jun 2 03:15:45 2008 : Debug: read_config_files: reading
dictionary
Mon Jun 2 03:15:46 2008 : Debug: read_config_files: reading naslist
Mon Jun 2 03:15:46 2008 : Info: Using deprecated naslist file.
Support for this will go away soon.
Mon Jun 2 03:15:46 2008 : Debug: read_config_files: reading clients
Mon Jun 2 03:15:46 2008 : Debug: read_config_files: reading realms
Mon Jun 2 03:15:46 2008 : Debug: radiusd: entering modules setup
Mon Jun 2 03:15:46 2008 : Debug: Module: Library search path is /usr/
lib/freeradius
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded exec
Mon Jun 2 03:15:46 2008 : Debug: exec: wait = yes
Mon Jun 2 03:15:46 2008 : Debug: exec: program = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: exec: input_pairs = "request"
Mon Jun 2 03:15:46 2008 : Debug: exec: output_pairs = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: exec: packet_type = "(null)"
Mon Jun 2 03:15:46 2008 : Info: rlm_exec: Wait=yes but no output
defined. Did you mean output=none?
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated exec (exec)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded expr
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated expr (expr)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded PAP
Mon Jun 2 03:15:46 2008 : Debug: pap: encryption_scheme = "crypt"
Mon Jun 2 03:15:46 2008 : Debug: pap: auto_header = yes
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated pap (pap)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded CHAP
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated chap (chap)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded MS-CHAP
Mon Jun 2 03:15:46 2008 : Debug: mschap: use_mppe = yes
Mon Jun 2 03:15:46 2008 : Debug: mschap: require_encryption = no
Mon Jun 2 03:15:46 2008 : Debug: mschap: require_strong = no
Mon Jun 2 03:15:46 2008 : Debug: mschap: with_ntdomain_hack = no
Mon Jun 2 03:15:46 2008 : Debug: mschap: passwd = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: mschap: ntlm_auth = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated mschap (mschap)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded System
Mon Jun 2 03:15:46 2008 : Debug: unix: cache = no
Mon Jun 2 03:15:46 2008 : Debug: unix: passwd = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: unix: shadow = "/etc/shadow"
Mon Jun 2 03:15:46 2008 : Debug: unix: group = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: unix: radwtmp = "/var/log/
freeradius/radwtmp"
Mon Jun 2 03:15:46 2008 : Debug: unix: usegroup = no
Mon Jun 2 03:15:46 2008 : Debug: unix: cache_reload = 600
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated unix (unix)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded eap
Mon Jun 2 03:15:46 2008 : Debug: eap: default_eap_type = "md5"
Mon Jun 2 03:15:46 2008 : Debug: eap: timer_expire = 60
Mon Jun 2 03:15:46 2008 : Debug: eap: ignore_unknown_eap_types = no
Mon Jun 2 03:15:46 2008 : Debug: eap: cisco_accounting_username_bug
= no
Mon Jun 2 03:15:46 2008 : Debug: rlm_eap: Loaded and initialized type
md5
Mon Jun 2 03:15:46 2008 : Debug: rlm_eap: Loaded and initialized type
leap
Mon Jun 2 03:15:46 2008 : Debug: gtc: challenge = "Password: "
Mon Jun 2 03:15:46 2008 : Debug: gtc: auth_type = "PAP"
Mon Jun 2 03:15:46 2008 : Debug: rlm_eap: Loaded and initialized type
gtc
Mon Jun 2 03:15:46 2008 : Debug: mschapv2: with_ntdomain_hack = no
Mon Jun 2 03:15:46 2008 : Debug: rlm_eap: Loaded and initialized type
mschapv2
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated eap (eap)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded preprocess
Mon Jun 2 03:15:46 2008 : Debug: preprocess: huntgroups = "/etc/
freeradius/huntgroups"
Mon Jun 2 03:15:46 2008 : Debug: preprocess: hints = "/etc/
freeradius/hints"
Mon Jun 2 03:15:46 2008 : Debug: preprocess: with_ascend_hack = no
Mon Jun 2 03:15:46 2008 : Debug: preprocess:
ascend_channels_per_line = 23Mon Jun 2 03:15:46 2008 : Debug:
preprocess: with_ntdomain_hack = no
Mon Jun 2 03:15:46 2008 : Debug: preprocess:
with_specialix_jetstream_hack = no
Mon Jun 2 03:15:46 2008 : Debug: preprocess: with_cisco_vsa_hack =
no
Mon Jun 2 03:15:46 2008 : Debug: preprocess: with_alvarion_vsa_hack
= no
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated preprocess
(preprocess)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded realm
Mon Jun 2 03:15:46 2008 : Debug: realm: format = "suffix"
Mon Jun 2 03:15:46 2008 : Debug: realm: delimiter = "@"
Mon Jun 2 03:15:46 2008 : Debug: realm: ignore_default = no
Mon Jun 2 03:15:46 2008 : Debug: realm: ignore_null = no
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated realm (suffix)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded files
Mon Jun 2 03:15:46 2008 : Debug: files: usersfile = "/etc/freeradius/
users"
Mon Jun 2 03:15:46 2008 : Debug: files: acctusersfile = "/etc/
freeradius/acct_users"
Mon Jun 2 03:15:46 2008 : Debug: files: preproxy_usersfile = "/etc/
freeradius/preproxy_users"
Mon Jun 2 03:15:46 2008 : Debug: files: compat = "no"
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated files (files)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded Acct-Unique-Session-
Id
Mon Jun 2 03:15:46 2008 : Debug: acct_unique: key = "User-Name, Acct-
Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated acct_unique
(acct_unique)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded detail
Mon Jun 2 03:15:46 2008 : Debug: detail: detailfile = "/var/log/
freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Mon Jun 2 03:15:46 2008 : Debug: detail: detailperm = 384
Mon Jun 2 03:15:46 2008 : Debug: detail: dirperm = 493
Mon Jun 2 03:15:46 2008 : Debug: detail: locking = no
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated detail (detail)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded radutmp
Mon Jun 2 03:15:46 2008 : Debug: radutmp: filename = "/var/log/
freeradius/radutmp"
Mon Jun 2 03:15:46 2008 : Debug: radutmp: username = "%{User-Name}"
Mon Jun 2 03:15:46 2008 : Debug: radutmp: case_sensitive = yes
Mon Jun 2 03:15:46 2008 : Debug: radutmp: check_with_nas = yes
Mon Jun 2 03:15:46 2008 : Debug: radutmp: perm = 384
Mon Jun 2 03:15:46 2008 : Debug: radutmp: callerid = yes
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated radutmp
(radutmp)
Mon Jun 2 03:15:46 2008 : Debug: Listening on authentication *:1812
Mon Jun 2 03:15:46 2008 : Debug: Listening on accounting *:1813
Mon Jun 2 03:15:46 2008 : Info: Ready to process requests.
Freeradius ведёт себя так, будто никакого подключения не происходит...
Mon Jun 2 03:15:45 2008 : Info: Starting - reading configuration
files ...
Mon Jun 2 03:15:45 2008 : Debug: reread_config: reading radiusd.conf
Mon Jun 2 03:15:45 2008 : Debug: Config: including file: /etc/
freeradius/proxy.conf
Mon Jun 2 03:15:45 2008 : Debug: Config: including file: /etc/
freeradius/clients.conf
Mon Jun 2 03:15:45 2008 : Debug: Config: including file: /etc/
freeradius/snmp.conf
Mon Jun 2 03:15:45 2008 : Debug: Config: including file: /etc/
freeradius/eap.conf
Mon Jun 2 03:15:45 2008 : Debug: Config: including file: /etc/
freeradius/sql.conf
Mon Jun 2 03:15:45 2008 : Debug: main: prefix = "/usr"
Mon Jun 2 03:15:45 2008 : Debug: main: localstatedir = "/var"
Mon Jun 2 03:15:45 2008 : Debug: main: logdir = "/var/log/
freeradius"
Mon Jun 2 03:15:45 2008 : Debug: main: libdir = "/usr/lib/
freeradius"
Mon Jun 2 03:15:45 2008 : Debug: main: radacctdir = "/var/log/
freeradius/radacct"
Mon Jun 2 03:15:45 2008 : Debug: main: hostname_lookups = no
Mon Jun 2 03:15:45 2008 : Debug: main: snmp = no
Mon Jun 2 03:15:45 2008 : Debug: main: max_request_time = 30
Mon Jun 2 03:15:45 2008 : Debug: main: cleanup_delay = 5
Mon Jun 2 03:15:45 2008 : Debug: main: max_requests = 1024
Mon Jun 2 03:15:45 2008 : Debug: main: delete_blocked_requests = 0
Mon Jun 2 03:15:45 2008 : Debug: main: port = 0
Mon Jun 2 03:15:45 2008 : Debug: main: allow_core_dumps = no
Mon Jun 2 03:15:45 2008 : Debug: main: log_stripped_names = no
Mon Jun 2 03:15:45 2008 : Debug: main: log_file = "/var/log/
freeradius/radius.log"
Mon Jun 2 03:15:45 2008 : Debug: main: log_auth = no
Mon Jun 2 03:15:45 2008 : Debug: main: log_auth_badpass = no
Mon Jun 2 03:15:45 2008 : Debug: main: log_auth_goodpass = no
Mon Jun 2 03:15:45 2008 : Debug: main: pidfile = "/var/run/
freeradius/freeradius.pid"
Mon Jun 2 03:15:45 2008 : Debug: main: user = "freerad"
Mon Jun 2 03:15:45 2008 : Debug: main: group = "freerad"
Mon Jun 2 03:15:45 2008 : Debug: main: usercollide = no
Mon Jun 2 03:15:45 2008 : Debug: main: lower_user = "no"
Mon Jun 2 03:15:45 2008 : Debug: main: lower_pass = "no"
Mon Jun 2 03:15:45 2008 : Debug: main: nospace_user = "no"
Mon Jun 2 03:15:45 2008 : Debug: main: nospace_pass = "no"
Mon Jun 2 03:15:45 2008 : Debug: main: checkrad = "/usr/sbin/
checkrad"
Mon Jun 2 03:15:45 2008 : Debug: main: proxy_requests = yes
Mon Jun 2 03:15:45 2008 : Debug: proxy: retry_delay = 5
Mon Jun 2 03:15:45 2008 : Debug: proxy: retry_count = 3
Mon Jun 2 03:15:45 2008 : Debug: proxy: synchronous = no
Mon Jun 2 03:15:45 2008 : Debug: proxy: default_fallback = yes
Mon Jun 2 03:15:45 2008 : Debug: proxy: dead_time = 120
Mon Jun 2 03:15:45 2008 : Debug: proxy: post_proxy_authorize = no
Mon Jun 2 03:15:45 2008 : Debug: proxy: wake_all_if_all_dead = no
Mon Jun 2 03:15:45 2008 : Debug: security: max_attributes = 200
Mon Jun 2 03:15:45 2008 : Debug: security: reject_delay = 1
Mon Jun 2 03:15:45 2008 : Debug: security: status_server = no
Mon Jun 2 03:15:45 2008 : Debug: main: debug_level = 0
Mon Jun 2 03:15:45 2008 : Debug: read_config_files: reading
dictionary
Mon Jun 2 03:15:46 2008 : Debug: read_config_files: reading naslist
Mon Jun 2 03:15:46 2008 : Info: Using deprecated naslist file.
Support for this will go away soon.
Mon Jun 2 03:15:46 2008 : Debug: read_config_files: reading clients
Mon Jun 2 03:15:46 2008 : Debug: read_config_files: reading realms
Mon Jun 2 03:15:46 2008 : Debug: radiusd: entering modules setup
Mon Jun 2 03:15:46 2008 : Debug: Module: Library search path is /usr/
lib/freeradius
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded exec
Mon Jun 2 03:15:46 2008 : Debug: exec: wait = yes
Mon Jun 2 03:15:46 2008 : Debug: exec: program = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: exec: input_pairs = "request"
Mon Jun 2 03:15:46 2008 : Debug: exec: output_pairs = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: exec: packet_type = "(null)"
Mon Jun 2 03:15:46 2008 : Info: rlm_exec: Wait=yes but no output
defined. Did you mean output=none?
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated exec (exec)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded expr
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated expr (expr)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded PAP
Mon Jun 2 03:15:46 2008 : Debug: pap: encryption_scheme = "crypt"
Mon Jun 2 03:15:46 2008 : Debug: pap: auto_header = yes
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated pap (pap)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded CHAP
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated chap (chap)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded MS-CHAP
Mon Jun 2 03:15:46 2008 : Debug: mschap: use_mppe = yes
Mon Jun 2 03:15:46 2008 : Debug: mschap: require_encryption = no
Mon Jun 2 03:15:46 2008 : Debug: mschap: require_strong = no
Mon Jun 2 03:15:46 2008 : Debug: mschap: with_ntdomain_hack = no
Mon Jun 2 03:15:46 2008 : Debug: mschap: passwd = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: mschap: ntlm_auth = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated mschap (mschap)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded System
Mon Jun 2 03:15:46 2008 : Debug: unix: cache = no
Mon Jun 2 03:15:46 2008 : Debug: unix: passwd = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: unix: shadow = "/etc/shadow"
Mon Jun 2 03:15:46 2008 : Debug: unix: group = "(null)"
Mon Jun 2 03:15:46 2008 : Debug: unix: radwtmp = "/var/log/
freeradius/radwtmp"
Mon Jun 2 03:15:46 2008 : Debug: unix: usegroup = no
Mon Jun 2 03:15:46 2008 : Debug: unix: cache_reload = 600
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated unix (unix)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded eap
Mon Jun 2 03:15:46 2008 : Debug: eap: default_eap_type = "md5"
Mon Jun 2 03:15:46 2008 : Debug: eap: timer_expire = 60
Mon Jun 2 03:15:46 2008 : Debug: eap: ignore_unknown_eap_types = no
Mon Jun 2 03:15:46 2008 : Debug: eap: cisco_accounting_username_bug
= no
Mon Jun 2 03:15:46 2008 : Debug: rlm_eap: Loaded and initialized type
md5
Mon Jun 2 03:15:46 2008 : Debug: rlm_eap: Loaded and initialized type
leap
Mon Jun 2 03:15:46 2008 : Debug: gtc: challenge = "Password: "
Mon Jun 2 03:15:46 2008 : Debug: gtc: auth_type = "PAP"
Mon Jun 2 03:15:46 2008 : Debug: rlm_eap: Loaded and initialized type
gtc
Mon Jun 2 03:15:46 2008 : Debug: mschapv2: with_ntdomain_hack = no
Mon Jun 2 03:15:46 2008 : Debug: rlm_eap: Loaded and initialized type
mschapv2
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated eap (eap)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded preprocess
Mon Jun 2 03:15:46 2008 : Debug: preprocess: huntgroups = "/etc/
freeradius/huntgroups"
Mon Jun 2 03:15:46 2008 : Debug: preprocess: hints = "/etc/
freeradius/hints"
Mon Jun 2 03:15:46 2008 : Debug: preprocess: with_ascend_hack = no
Mon Jun 2 03:15:46 2008 : Debug: preprocess:
ascend_channels_per_line = 23Mon Jun 2 03:15:46 2008 : Debug:
preprocess: with_ntdomain_hack = no
Mon Jun 2 03:15:46 2008 : Debug: preprocess:
with_specialix_jetstream_hack = no
Mon Jun 2 03:15:46 2008 : Debug: preprocess: with_cisco_vsa_hack =
no
Mon Jun 2 03:15:46 2008 : Debug: preprocess: with_alvarion_vsa_hack
= no
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated preprocess
(preprocess)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded realm
Mon Jun 2 03:15:46 2008 : Debug: realm: format = "suffix"
Mon Jun 2 03:15:46 2008 : Debug: realm: delimiter = "@"
Mon Jun 2 03:15:46 2008 : Debug: realm: ignore_default = no
Mon Jun 2 03:15:46 2008 : Debug: realm: ignore_null = no
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated realm (suffix)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded files
Mon Jun 2 03:15:46 2008 : Debug: files: usersfile = "/etc/freeradius/
users"
Mon Jun 2 03:15:46 2008 : Debug: files: acctusersfile = "/etc/
freeradius/acct_users"
Mon Jun 2 03:15:46 2008 : Debug: files: preproxy_usersfile = "/etc/
freeradius/preproxy_users"
Mon Jun 2 03:15:46 2008 : Debug: files: compat = "no"
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated files (files)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded Acct-Unique-Session-
Id
Mon Jun 2 03:15:46 2008 : Debug: acct_unique: key = "User-Name, Acct-
Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated acct_unique
(acct_unique)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded detail
Mon Jun 2 03:15:46 2008 : Debug: detail: detailfile = "/var/log/
freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
Mon Jun 2 03:15:46 2008 : Debug: detail: detailperm = 384
Mon Jun 2 03:15:46 2008 : Debug: detail: dirperm = 493
Mon Jun 2 03:15:46 2008 : Debug: detail: locking = no
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated detail (detail)
Mon Jun 2 03:15:46 2008 : Debug: Module: Loaded radutmp
Mon Jun 2 03:15:46 2008 : Debug: radutmp: filename = "/var/log/
freeradius/radutmp"
Mon Jun 2 03:15:46 2008 : Debug: radutmp: username = "%{User-Name}"
Mon Jun 2 03:15:46 2008 : Debug: radutmp: case_sensitive = yes
Mon Jun 2 03:15:46 2008 : Debug: radutmp: check_with_nas = yes
Mon Jun 2 03:15:46 2008 : Debug: radutmp: perm = 384
Mon Jun 2 03:15:46 2008 : Debug: radutmp: callerid = yes
Mon Jun 2 03:15:46 2008 : Debug: Module: Instantiated radutmp
(radutmp)
Mon Jun 2 03:15:46 2008 : Debug: Listening on authentication *:1812
Mon Jun 2 03:15:46 2008 : Debug: Listening on accounting *:1813
Mon Jun 2 03:15:46 2008 : Info: Ready to process requests.
Freeradius ведёт себя так, будто никакого подключения не происходит...
JasonX
May 26, 2008, 8:54:02 AM5/26/08
to cakebilling
По поводу молчания радиуса я разобрался - забыл в radiusclient его
прописать.
Но он на правильный пароль, отвечает отказом...
rad_recv: Access-Request packet from host 127.0.0.1:1030, id=255,
length=106 Service-Type = Framed-User
Framed-Protocol = PPP
User-Name = "111"
CHAP-Challenge =
0x829504dd27ae2a01424664e616b967214b7867effcd1
CHAP-Password = 0x16db1f3b8bb7ea2e0130ff5869009bac83
Calling-Station-Id = "192.168.1.10"
NAS-IP-Address = 127.0.0.1
NAS-Port = 0
Mon Jun 2 03:49:49 2008 : Debug: Processing the authorize section
of radiusd.conf
Mon Jun 2 03:49:49 2008 : Debug: modcall: entering group authorize
for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module
"preprocess" returns ok for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling chap
(rlm_chap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rlm_chap: Setting 'Auth-Type :=
CHAP'
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from chap (rlm_chap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module "chap"
returns ok for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling
mschap (rlm_mschap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from mschap (rlm_mschap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module
"mschap" returns noop for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling
suffix (rlm_realm) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rlm_realm: No '@' in User-Name =
"111", looking up realm NULL
Mon Jun 2 03:49:49 2008 : Debug: rlm_realm: No such realm "NULL"
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from suffix (rlm_realm) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module
"suffix" returns noop for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rlm_eap: No EAP-Message, not doing
EAP
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from eap (rlm_eap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module "eap"
returns noop for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling
files (rlm_files) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from files (rlm_files) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module "files"
returns notfound for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling pap
(rlm_pap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rlm_pap: WARNING! No "known good"
password found for the user. Authentication may fail because of this.
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from pap (rlm_pap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module "pap"
returns noop for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall: leaving group authorize
(returns ok) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rad_check_password: Found Auth-
Type CHAP
Mon Jun 2 03:49:49 2008 : Debug: auth: type "CHAP"
Mon Jun 2 03:49:49 2008 : Debug: Processing the authenticate
section of radiusd.conf
Mon Jun 2 03:49:49 2008 : Debug: modcall: entering group CHAP for
request 3Mon Jun 2 03:49:49 2008 : Debug: modsingle[authenticate]:
calling chap (rlm_chap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rlm_chap: login attempt by "111"
with CHAP password
Mon Jun 2 03:49:49 2008 : Debug: rlm_chap: Could not find clear
text password for user 111
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authenticate]: returned
from chap (rlm_chap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authenticate]: module
"chap" returns invalid for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall: leaving group CHAP (returns
invalid) for request 3
Mon Jun 2 03:49:49 2008 : Debug: auth: Failed to validate the user.
Mon Jun 2 03:49:49 2008 : Debug: Delaying request 3 for 1 seconds
Mon Jun 2 03:49:49 2008 : Debug: Finished request 3
Mon Jun 2 03:49:49 2008 : Debug: Going to the next request
Mon Jun 2 03:49:49 2008 : Debug: --- Walking the entire request list
---
Mon Jun 2 03:49:49 2008 : Debug: Waking up in 1 seconds...
Mon Jun 2 03:49:50 2008 : Debug: --- Walking the entire request list
---
Mon Jun 2 03:49:50 2008 : Debug: Waking up in 1 seconds...
Mon Jun 2 03:49:51 2008 : Debug: --- Walking the entire request list
---
Sending Access-Reject of id 255 to 127.0.0.1 port 1030
Mon Jun 2 03:49:51 2008 : Debug: Waking up in 4 seconds...
Mon Jun 2 03:49:55 2008 : Debug: --- Walking the entire request list
---
Mon Jun 2 03:49:55 2008 : Debug: Cleaning up request 3 ID 255 with
timestamp 484343ad
Mon Jun 2 03:49:55 2008 : Debug: Nothing to do. Sleeping until we
see a request.
прописать.
Но он на правильный пароль, отвечает отказом...
rad_recv: Access-Request packet from host 127.0.0.1:1030, id=255,
length=106 Service-Type = Framed-User
Framed-Protocol = PPP
User-Name = "111"
CHAP-Challenge =
0x829504dd27ae2a01424664e616b967214b7867effcd1
CHAP-Password = 0x16db1f3b8bb7ea2e0130ff5869009bac83
Calling-Station-Id = "192.168.1.10"
NAS-IP-Address = 127.0.0.1
NAS-Port = 0
Mon Jun 2 03:49:49 2008 : Debug: Processing the authorize section
of radiusd.conf
Mon Jun 2 03:49:49 2008 : Debug: modcall: entering group authorize
for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module
"preprocess" returns ok for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling chap
(rlm_chap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rlm_chap: Setting 'Auth-Type :=
CHAP'
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from chap (rlm_chap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module "chap"
returns ok for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling
mschap (rlm_mschap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from mschap (rlm_mschap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module
"mschap" returns noop for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling
suffix (rlm_realm) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rlm_realm: No '@' in User-Name =
"111", looking up realm NULL
Mon Jun 2 03:49:49 2008 : Debug: rlm_realm: No such realm "NULL"
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from suffix (rlm_realm) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module
"suffix" returns noop for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rlm_eap: No EAP-Message, not doing
EAP
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from eap (rlm_eap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module "eap"
returns noop for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling
files (rlm_files) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from files (rlm_files) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module "files"
returns notfound for request 3
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: calling pap
(rlm_pap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rlm_pap: WARNING! No "known good"
password found for the user. Authentication may fail because of this.
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authorize]: returned
from pap (rlm_pap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authorize]: module "pap"
returns noop for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall: leaving group authorize
(returns ok) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rad_check_password: Found Auth-
Type CHAP
Mon Jun 2 03:49:49 2008 : Debug: auth: type "CHAP"
Mon Jun 2 03:49:49 2008 : Debug: Processing the authenticate
section of radiusd.conf
Mon Jun 2 03:49:49 2008 : Debug: modcall: entering group CHAP for
request 3Mon Jun 2 03:49:49 2008 : Debug: modsingle[authenticate]:
calling chap (rlm_chap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: rlm_chap: login attempt by "111"
with CHAP password
Mon Jun 2 03:49:49 2008 : Debug: rlm_chap: Could not find clear
text password for user 111
Mon Jun 2 03:49:49 2008 : Debug: modsingle[authenticate]: returned
from chap (rlm_chap) for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall[authenticate]: module
"chap" returns invalid for request 3
Mon Jun 2 03:49:49 2008 : Debug: modcall: leaving group CHAP (returns
invalid) for request 3
Mon Jun 2 03:49:49 2008 : Debug: auth: Failed to validate the user.
Mon Jun 2 03:49:49 2008 : Debug: Delaying request 3 for 1 seconds
Mon Jun 2 03:49:49 2008 : Debug: Finished request 3
Mon Jun 2 03:49:49 2008 : Debug: Going to the next request
Mon Jun 2 03:49:49 2008 : Debug: --- Walking the entire request list
---
Mon Jun 2 03:49:49 2008 : Debug: Waking up in 1 seconds...
Mon Jun 2 03:49:50 2008 : Debug: --- Walking the entire request list
---
Mon Jun 2 03:49:50 2008 : Debug: Waking up in 1 seconds...
Mon Jun 2 03:49:51 2008 : Debug: --- Walking the entire request list
---
Sending Access-Reject of id 255 to 127.0.0.1 port 1030
Mon Jun 2 03:49:51 2008 : Debug: Waking up in 4 seconds...
Mon Jun 2 03:49:55 2008 : Debug: --- Walking the entire request list
---
Mon Jun 2 03:49:55 2008 : Debug: Cleaning up request 3 ID 255 with
timestamp 484343ad
Mon Jun 2 03:49:55 2008 : Debug: Nothing to do. Sleeping until we
see a request.
JasonX
May 26, 2008, 8:55:47 AM5/26/08
to cakebilling
А вот логи pptpd
Jun 2 03:49:49 localhost pppd[3151]: Plugin radius.so loaded.
Jun 2 03:49:49 localhost pppd[3151]: RADIUS plugin initialized.
Jun 2 03:49:49 localhost pppd[3151]: pppd options in effect:
Jun 2 03:49:49 localhost pppd[3151]: debug debug^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: dump^I^I# (from /etc/ppp/pptpd-
options)
Jun 2 03:49:49 localhost pppd[3151]: plugin radius.so^I^I# (from /etc/
ppp/pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: +mschap^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: name pptpd^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: 115200^I^I# (from command line)
Jun 2 03:49:49 localhost pppd[3151]: lock^I^I# (from /etc/ppp/pptpd-
options)
Jun 2 03:49:49 localhost pppd[3151]: crtscts^I^I# (from /etc/ppp/
options)
Jun 2 03:49:49 localhost pppd[3151]: local^I^I# (from command line)
Jun 2 03:49:49 localhost pppd[3151]: asyncmap 0^I^I# (from /etc/ppp/
options)
Jun 2 03:49:49 localhost pppd[3151]: silent^I^I# (from /etc/ppp/pptpd-
options)
Jun 2 03:49:49 localhost pppd[3151]: lcp-echo-failure 4^I^I# (from /
etc/ppp/options)
Jun 2 03:49:49 localhost pppd[3151]: lcp-echo-interval 30^I^I# (from /
etc/ppp/options)
Jun 2 03:49:49 localhost pppd[3151]: hide-password^I^I# (from /etc/
ppp/options)
Jun 2 03:49:49 localhost pppd[3151]: ipparam 192.168.1.10^I^I# (from
command line)
Jun 2 03:49:49 localhost pppd[3151]: ms-dns xxx # [don't know how to
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: 192.168.1.1:192.168.1.1^I^I#
(from command line)
Jun 2 03:49:49 localhost pppd[3151]: nobsdcomp^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: nodeflate^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: noipx^I^I# (from /etc/ppp/
options)
Jun 2 03:49:49 localhost pppd[3151]: pppd 2.4.4 started by root, uid
0
Jun 2 03:49:49 localhost pppd[3151]: Using interface ppp0
Jun 2 03:49:49 localhost pppd[3151]: Connect: ppp0 <--> /dev/pts/6
Jun 2 03:49:51 localhost pppd[3151]: Peer 111 failed CHAP
authentication
Jun 2 03:49:51 localhost pppd[3151]: Connection terminated.
Jun 2 03:49:51 localhost pppd[3151]: tcflush failed: Input/output
error
Jun 2 03:49:51 localhost pppd[3151]: Exit.
Jun 2 03:49:49 localhost pppd[3151]: Plugin radius.so loaded.
Jun 2 03:49:49 localhost pppd[3151]: RADIUS plugin initialized.
Jun 2 03:49:49 localhost pppd[3151]: pppd options in effect:
Jun 2 03:49:49 localhost pppd[3151]: debug debug^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: dump^I^I# (from /etc/ppp/pptpd-
options)
Jun 2 03:49:49 localhost pppd[3151]: plugin radius.so^I^I# (from /etc/
ppp/pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: +mschap^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: name pptpd^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: 115200^I^I# (from command line)
Jun 2 03:49:49 localhost pppd[3151]: lock^I^I# (from /etc/ppp/pptpd-
options)
Jun 2 03:49:49 localhost pppd[3151]: crtscts^I^I# (from /etc/ppp/
options)
Jun 2 03:49:49 localhost pppd[3151]: local^I^I# (from command line)
Jun 2 03:49:49 localhost pppd[3151]: asyncmap 0^I^I# (from /etc/ppp/
options)
Jun 2 03:49:49 localhost pppd[3151]: silent^I^I# (from /etc/ppp/pptpd-
options)
Jun 2 03:49:49 localhost pppd[3151]: lcp-echo-failure 4^I^I# (from /
etc/ppp/options)
Jun 2 03:49:49 localhost pppd[3151]: lcp-echo-interval 30^I^I# (from /
etc/ppp/options)
Jun 2 03:49:49 localhost pppd[3151]: hide-password^I^I# (from /etc/
ppp/options)
Jun 2 03:49:49 localhost pppd[3151]: ipparam 192.168.1.10^I^I# (from
command line)
Jun 2 03:49:49 localhost pppd[3151]: ms-dns xxx # [don't know how to
print value]^I^I# (from /etc/ppp/pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: proxyarp^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: 192.168.1.1:192.168.1.1^I^I#
(from command line)
Jun 2 03:49:49 localhost pppd[3151]: nobsdcomp^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: nodeflate^I^I# (from /etc/ppp/
pptpd-options)
Jun 2 03:49:49 localhost pppd[3151]: noipx^I^I# (from /etc/ppp/
options)
Jun 2 03:49:49 localhost pppd[3151]: pppd 2.4.4 started by root, uid
0
Jun 2 03:49:49 localhost pppd[3151]: Using interface ppp0
Jun 2 03:49:49 localhost pppd[3151]: Connect: ppp0 <--> /dev/pts/6
Jun 2 03:49:51 localhost pppd[3151]: Peer 111 failed CHAP
authentication
Jun 2 03:49:51 localhost pppd[3151]: Connection terminated.
Jun 2 03:49:51 localhost pppd[3151]: tcflush failed: Input/output
error
Jun 2 03:49:51 localhost pppd[3151]: Exit.
Anatoly Shipitsin
May 26, 2008, 9:22:53 AM5/26/08
to cakeb...@googlegroups.com
Я у вас в первом выводе старта FreeRADIUS не вижу подключения к SQL серверу.
Далее при авторизации видим:
>rlm_chap: Could not find clear text password for user 111
Это говорит о том что у вас не подключен SQL модуль и FreeRADIUS вполне естественно не находит пользователя.
Далее при авторизации видим:
>rlm_chap: Could not find clear text password for user 111
JasonX
May 27, 2008, 8:08:20 AM5/27/08
to cakebilling
Добился корректной работы freeradius. Он авторизует пользователя, но
pptpd не авторизует... конфиги брал с http://code.google.com/p/cakebilling
debian:/home/user# freeradius -X -X
Tue Jun 3 02:36:11 2008 : Info: Starting - reading configuration
files ...
Tue Jun 3 02:36:11 2008 : Debug: reread_config: reading radiusd.conf
Tue Jun 3 02:36:11 2008 : Debug: Config: including file: /etc/
freeradius/clients.conf
Tue Jun 3 02:36:11 2008 : Debug: Config: including file: /etc/
freeradius/cakesql.conf
Tue Jun 3 02:36:12 2008 : Debug: main: prefix = "/usr"
Tue Jun 3 02:36:12 2008 : Debug: main: localstatedir = "/var"
Tue Jun 3 02:36:12 2008 : Debug: main: logdir = "/var/log/
freeradius"
Tue Jun 3 02:36:12 2008 : Debug: main: libdir = "/usr/lib/
freeradius"
Tue Jun 3 02:36:12 2008 : Debug: main: radacctdir = "/var/log/
freeradius/radacct"
Tue Jun 3 02:36:12 2008 : Debug: main: hostname_lookups = no
Tue Jun 3 02:36:12 2008 : Debug: main: snmp = no
Tue Jun 3 02:36:12 2008 : Debug: main: max_request_time = 30
Tue Jun 3 02:36:12 2008 : Debug: main: cleanup_delay = 5
Tue Jun 3 02:36:12 2008 : Debug: main: max_requests = 5120
Tue Jun 3 02:36:12 2008 : Debug: main: delete_blocked_requests = 0
Tue Jun 3 02:36:12 2008 : Debug: main: port = 0
Tue Jun 3 02:36:12 2008 : Debug: main: allow_core_dumps = no
Tue Jun 3 02:36:12 2008 : Debug: main: log_stripped_names = no
Tue Jun 3 02:36:12 2008 : Debug: main: log_file = "/var/log/
freeradius/radius.log"
Tue Jun 3 02:36:12 2008 : Debug: main: log_auth = yes
Tue Jun 3 02:36:12 2008 : Debug: main: log_auth_badpass = yes
Tue Jun 3 02:36:12 2008 : Debug: main: log_auth_goodpass = no
Tue Jun 3 02:36:12 2008 : Debug: main: pidfile = "/var/run/
freeradius/freeradius.pid"
Tue Jun 3 02:36:12 2008 : Debug: main: user = "freerad"
Tue Jun 3 02:36:12 2008 : Debug: main: group = "freerad"
Tue Jun 3 02:36:12 2008 : Debug: main: usercollide = no
Tue Jun 3 02:36:12 2008 : Debug: main: lower_user = "no"
Tue Jun 3 02:36:12 2008 : Debug: main: lower_pass = "no"
Tue Jun 3 02:36:12 2008 : Debug: main: nospace_user = "no"
Tue Jun 3 02:36:12 2008 : Debug: main: nospace_pass = "no"
Tue Jun 3 02:36:12 2008 : Debug: main: checkrad = "/usr/sbin/
checkrad"
Tue Jun 3 02:36:12 2008 : Debug: main: proxy_requests = yes
Tue Jun 3 02:36:12 2008 : Debug: security: max_attributes = 200
Tue Jun 3 02:36:12 2008 : Debug: security: reject_delay = 1
Tue Jun 3 02:36:12 2008 : Debug: security: status_server = no
Tue Jun 3 02:36:12 2008 : Debug: main: debug_level = 0
Tue Jun 3 02:36:12 2008 : Debug: read_config_files: reading
dictionary
Tue Jun 3 02:36:12 2008 : Debug: read_config_files: reading naslist
Tue Jun 3 02:36:12 2008 : Info: Using deprecated naslist file.
Tue Jun 3 02:36:13 2008 : Debug: read_config_files: reading realms
Tue Jun 3 02:36:13 2008 : Debug: radiusd: entering modules setup
Tue Jun 3 02:36:13 2008 : Debug: Module: Library search path is /usr/
lib/freeradius
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded PAP
Tue Jun 3 02:36:13 2008 : Debug: pap: encryption_scheme = "clear"
Tue Jun 3 02:36:13 2008 : Debug: pap: auto_header = no
Tue Jun 3 02:36:13 2008 : Debug: Module: Instantiated pap (pap)
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded CHAP
Tue Jun 3 02:36:13 2008 : Debug: Module: Instantiated chap (chap)
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded MS-CHAP
Tue Jun 3 02:36:13 2008 : Debug: mschap: use_mppe = no
Tue Jun 3 02:36:13 2008 : Debug: mschap: require_encryption = no
Tue Jun 3 02:36:13 2008 : Debug: mschap: require_strong = no
Tue Jun 3 02:36:13 2008 : Debug: mschap: with_ntdomain_hack = no
Tue Jun 3 02:36:13 2008 : Debug: mschap: passwd = "(null)"
Tue Jun 3 02:36:13 2008 : Debug: mschap: ntlm_auth = "(null)"
Tue Jun 3 02:36:13 2008 : Debug: Module: Instantiated mschap (mschap)
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded preprocess
Tue Jun 3 02:36:13 2008 : Debug: preprocess: huntgroups = "/etc/
freeradius/huntgroups"
Tue Jun 3 02:36:13 2008 : Debug: preprocess: hints = "/etc/
freeradius/hints"
Tue Jun 3 02:36:13 2008 : Debug: preprocess: with_ascend_hack = no
Tue Jun 3 02:36:13 2008 : Debug: preprocess:
ascend_channels_per_line = 23Tue Jun 3 02:36:13 2008 : Debug:
preprocess: with_ntdomain_hack = no
Tue Jun 3 02:36:13 2008 : Debug: preprocess:
with_specialix_jetstream_hack = no
Tue Jun 3 02:36:13 2008 : Debug: preprocess: with_cisco_vsa_hack =
no
Tue Jun 3 02:36:13 2008 : Debug: preprocess: with_alvarion_vsa_hack
= no
Tue Jun 3 02:36:13 2008 : Debug: Module: Instantiated preprocess
(preprocess)
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded files
Tue Jun 3 02:36:13 2008 : Debug: files: usersfile = "/etc/freeradius/
users"
Tue Jun 3 02:36:13 2008 : Debug: files: acctusersfile = "/etc/
freeradius/acct_users"
Tue Jun 3 02:36:13 2008 : Debug: files: preproxy_usersfile = "/etc/
freeradius/preproxy_users"
Tue Jun 3 02:36:13 2008 : Debug: files: compat = "no"
Tue Jun 3 02:36:13 2008 : Debug: Module: Instantiated files (files)
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded SQL
Tue Jun 3 02:36:13 2008 : Debug: sql: driver = "rlm_sql_postgresql"
Tue Jun 3 02:36:13 2008 : Debug: sql: server = "127.0.0.1"
Tue Jun 3 02:36:13 2008 : Debug: sql: port = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: login = "cake"
Tue Jun 3 02:36:13 2008 : Debug: sql: password = "cake"
Tue Jun 3 02:36:13 2008 : Debug: sql: radius_db = "cake"
Tue Jun 3 02:36:13 2008 : Debug: sql: nas_table = "nas"
Tue Jun 3 02:36:13 2008 : Debug: sql: sqltrace = yes
Tue Jun 3 02:36:13 2008 : Debug: sql: sqltracefile = "/var/log/
freeradius/sqltrace.sql"
Tue Jun 3 02:36:13 2008 : Debug: sql: readclients = no
Tue Jun 3 02:36:13 2008 : Debug: sql: deletestalesessions = no
Tue Jun 3 02:36:13 2008 : Debug: sql: num_sql_socks = 30
Tue Jun 3 02:36:13 2008 : Debug: sql: sql_user_name = "%{User-Name}"
Tue Jun 3 02:36:13 2008 : Debug: sql: default_user_profile = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: query_on_not_found = no
Tue Jun 3 02:36:13 2008 : Debug: sql: authorize_check_query =
"select * from cake.auth_check('%{SQL-User-Name}')"
Tue Jun 3 02:36:13 2008 : Debug: sql: authorize_reply_query =
"select * from cake.auth_reply('%{SQL-User-Name}')"
Tue Jun 3 02:36:13 2008 : Debug: sql: authorize_group_check_query =
""
Tue Jun 3 02:36:13 2008 : Debug: sql: authorize_group_reply_query =
""
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_onoff_query = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_update_query =
"select cake.acct_update('%{Acct-Unique-Session-Id}', %{Acct-Output-
Octets},%{Acct-Input-Octets})"
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_update_query_alt =
""
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_start_query =
"select start_session('%{Acct-Unique-Session-Id}','%{SQL-User-Name}')"
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_start_query_alt =
""
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_stop_query =
"select stop_session(%{Acct-Input-Octets},%{Acct-Output-Octets},'%
{Acct-Unique-Session-Id}')"
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_stop_query_alt = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: group_membership_query = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: connect_failure_retry_delay =
60
Tue Jun 3 02:36:13 2008 : Debug: sql: simul_count_query = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: simul_verify_query = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: postauth_query = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-
_: /"
Tue Jun 3 02:36:13 2008 : Info: rlm_sql (cake_sql): Driver
rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked
Tue Jun 3 02:36:13 2008 : Info: rlm_sql (cake_sql): Attempting to
connect to ca...@127.0.0.1:/cake
Tue Jun 3 02:36:13 2008 : Debug: rlm_sql (cake_sql): starting 0
Tue Jun 3 02:36:13 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #0
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #0
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): starting 1
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #1
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #1
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): starting 2
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #2
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #2
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): starting 3
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #3
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #3
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 4
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #4
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #4
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 5
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #5
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #5
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 6
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #6
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #6
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 7
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #7
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #7
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 8
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #8
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #8
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 9
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #9
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #9
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 10
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #10
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #10
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 11
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #11
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #11
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 12
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #12
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #12
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 13
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #13
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #13
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 14
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #14
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #14
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 15
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #15
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #15
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 16
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #16
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #16
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 17
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #17
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #17
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 18
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #18
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #18
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 19
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #19
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #19
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 20
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #20
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #20
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 21
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #21
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #21
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 22
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #22
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #22
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 23
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #23
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #23
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 24
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #24
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #24
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 25
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #25
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #25
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 26
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #26
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #26
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 27
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #27
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #27
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 28
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #28
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #28
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 29
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #29
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #29
Tue Jun 3 02:36:16 2008 : Debug: Module: Instantiated sql (cake_sql)
Tue Jun 3 02:36:16 2008 : Debug: Module: Loaded Acct-Unique-Session-
Id
Tue Jun 3 02:36:16 2008 : Debug: acct_unique: key = "User-Name, Acct-
Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Tue Jun 3 02:36:16 2008 : Debug: Module: Instantiated acct_unique
(acct_unique)
Tue Jun 3 02:36:16 2008 : Debug: Listening on authentication *:1812
Tue Jun 3 02:36:16 2008 : Debug: Listening on accounting *:1813
Tue Jun 3 02:36:16 2008 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1:1030, id=159,
length=100 Service-Type = Framed-User
CHAP-Password = 0x30368f41334399a7f492786a4fff578608
of radiusd.conf
Tue Jun 3 02:37:12 2008 : Debug: modcall: entering group authorize
for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modcall[authorize]: module
"preprocess" returns ok for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: calling chap
(rlm_chap) for request 0
Tue Jun 3 02:37:12 2008 : Debug: rlm_chap: Setting 'Auth-Type :=
CHAP'
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: returned
from chap (rlm_chap) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modcall[authorize]: module "chap"
returns ok for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: calling
mschap (rlm_mschap) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: returned
from mschap (rlm_mschap) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modcall[authorize]: module
"mschap" returns noop for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: calling
files (rlm_files) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: returned
from files (rlm_files) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modcall[authorize]: module "files"
returns notfound for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: calling
cake_sql (rlm_sql) for request 0
Tue Jun 3 02:37:12 2008 : Debug: radius_xlat: '111'
Tue Jun 3 02:37:12 2008 : Debug: rlm_sql (cake_sql): sql_set_user
escaped user --> '111'
Tue Jun 3 02:37:12 2008 : Debug: radius_xlat: 'select * from
cake.auth_check('111')'
Tue Jun 3 02:37:12 2008 : Debug: rlm_sql (cake_sql): Reserving sql
socket id: 29
Tue Jun 3 02:37:12 2008 : Debug: rlm_sql_postgresql: query: select *
from cake.auth_check('111')
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OK
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql_postgresql: affected rows =
Tue Jun 3 02:37:14 2008 : Debug: radius_xlat: ''
Tue Jun 3 02:37:14 2008 : Debug: radius_xlat: 'select * from
cake.auth_reply('111')'
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql_postgresql: query: select *
from cake.auth_reply('111')
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OK
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql_postgresql: affected rows =
Tue Jun 3 02:37:14 2008 : Debug: radius_xlat: ''
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql (cake_sql): Released sql
socket id: 29
Tue Jun 3 02:37:14 2008 : Debug: modsingle[authorize]: returned
from cake_sql (rlm_sql) for request 0
Tue Jun 3 02:37:14 2008 : Debug: modcall[authorize]: module
"cake_sql" returns ok for request 0
Tue Jun 3 02:37:14 2008 : Debug: modcall: leaving group authorize
(returns ok) for request 0
Tue Jun 3 02:37:14 2008 : Debug: rad_check_password: Found Auth-
Type CHAP
Tue Jun 3 02:37:14 2008 : Debug: auth: type "CHAP"
Tue Jun 3 02:37:14 2008 : Debug: Processing the authenticate
section of radiusd.conf
Tue Jun 3 02:37:14 2008 : Debug: modcall: entering group CHAP for
request 0Tue Jun 3 02:37:14 2008 : Debug: modsingle[authenticate]:
calling chap (rlm_chap) for request 0
Tue Jun 3 02:37:14 2008 : Debug: rlm_chap: login attempt by "111"
with CHAP password
Tue Jun 3 02:37:14 2008 : Debug: rlm_chap: Using clear text
password "111" for user 111 authentication.
Tue Jun 3 02:37:14 2008 : Debug: rlm_chap: chap user 111
authenticated succesfully
Tue Jun 3 02:37:14 2008 : Debug: modsingle[authenticate]: returned
from chap (rlm_chap) for request 0
Tue Jun 3 02:37:14 2008 : Debug: modcall[authenticate]: module
"chap" returns ok for request 0
Tue Jun 3 02:37:14 2008 : Debug: modcall: leaving group CHAP (returns
ok) for request 0
Tue Jun 3 02:37:14 2008 : Auth: Login OK: [111] (from client
localhost port 0 cli 192.168.1.10)
Sending Access-Accept of id 159 to 127.0.0.1 port 1030
Framed-IP-Address := 192.168.2.3
Framed-IP-Netmask := 255.255.255.0
Session-Timeout := 43200
Idle-Timeout := 7200
Acct-Interim-Interval := 60
Octets-Direction := Output
Tue Jun 3 02:37:14 2008 : Debug: Finished request 0
Tue Jun 3 02:37:14 2008 : Debug: Going to the next request
Tue Jun 3 02:37:14 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 02:37:14 2008 : Debug: Waking up in 6 seconds...
Tue Jun 3 02:37:20 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 02:37:20 2008 : Debug: Cleaning up request 0 ID 159 with
timestamp 48448428
Tue Jun 3 02:37:20 2008 : Debug: Nothing to do. Sleeping until we
see a request.
Конфиг pptpd-options
lock
name pptpd
nodeflate
nobsdcomp
auth
+chap
+mschap-v2
+mschap
-pap
nomppe
silent
proxyarp
ms-dns 192.168.39.1
ms-dns 192.168.251.1
plugin radius.so
debug
dump
Конфиг pptpd.conf
debug
localip локальный ip сервера
option /etc/ppp/pptpd-options
pptpd не авторизует... конфиги брал с http://code.google.com/p/cakebilling
debian:/home/user# freeradius -X -X
Tue Jun 3 02:36:11 2008 : Info: Starting - reading configuration
files ...
Tue Jun 3 02:36:11 2008 : Debug: reread_config: reading radiusd.conf
Tue Jun 3 02:36:11 2008 : Debug: Config: including file: /etc/
freeradius/clients.conf
Tue Jun 3 02:36:11 2008 : Debug: Config: including file: /etc/
freeradius/cakesql.conf
Tue Jun 3 02:36:12 2008 : Debug: main: prefix = "/usr"
Tue Jun 3 02:36:12 2008 : Debug: main: localstatedir = "/var"
Tue Jun 3 02:36:12 2008 : Debug: main: logdir = "/var/log/
freeradius"
Tue Jun 3 02:36:12 2008 : Debug: main: libdir = "/usr/lib/
freeradius"
Tue Jun 3 02:36:12 2008 : Debug: main: radacctdir = "/var/log/
freeradius/radacct"
Tue Jun 3 02:36:12 2008 : Debug: main: hostname_lookups = no
Tue Jun 3 02:36:12 2008 : Debug: main: snmp = no
Tue Jun 3 02:36:12 2008 : Debug: main: max_request_time = 30
Tue Jun 3 02:36:12 2008 : Debug: main: cleanup_delay = 5
Tue Jun 3 02:36:12 2008 : Debug: main: max_requests = 5120
Tue Jun 3 02:36:12 2008 : Debug: main: delete_blocked_requests = 0
Tue Jun 3 02:36:12 2008 : Debug: main: port = 0
Tue Jun 3 02:36:12 2008 : Debug: main: allow_core_dumps = no
Tue Jun 3 02:36:12 2008 : Debug: main: log_stripped_names = no
Tue Jun 3 02:36:12 2008 : Debug: main: log_file = "/var/log/
freeradius/radius.log"
Tue Jun 3 02:36:12 2008 : Debug: main: log_auth = yes
Tue Jun 3 02:36:12 2008 : Debug: main: log_auth_badpass = yes
Tue Jun 3 02:36:12 2008 : Debug: main: log_auth_goodpass = no
Tue Jun 3 02:36:12 2008 : Debug: main: pidfile = "/var/run/
freeradius/freeradius.pid"
Tue Jun 3 02:36:12 2008 : Debug: main: user = "freerad"
Tue Jun 3 02:36:12 2008 : Debug: main: group = "freerad"
Tue Jun 3 02:36:12 2008 : Debug: main: usercollide = no
Tue Jun 3 02:36:12 2008 : Debug: main: lower_user = "no"
Tue Jun 3 02:36:12 2008 : Debug: main: lower_pass = "no"
Tue Jun 3 02:36:12 2008 : Debug: main: nospace_user = "no"
Tue Jun 3 02:36:12 2008 : Debug: main: nospace_pass = "no"
Tue Jun 3 02:36:12 2008 : Debug: main: checkrad = "/usr/sbin/
checkrad"
Tue Jun 3 02:36:12 2008 : Debug: main: proxy_requests = yes
Tue Jun 3 02:36:12 2008 : Debug: security: max_attributes = 200
Tue Jun 3 02:36:12 2008 : Debug: security: reject_delay = 1
Tue Jun 3 02:36:12 2008 : Debug: security: status_server = no
Tue Jun 3 02:36:12 2008 : Debug: main: debug_level = 0
Tue Jun 3 02:36:12 2008 : Debug: read_config_files: reading
dictionary
Tue Jun 3 02:36:12 2008 : Debug: read_config_files: reading naslist
Tue Jun 3 02:36:12 2008 : Info: Using deprecated naslist file.
Support for this will go away soon.
Tue Jun 3 02:36:13 2008 : Debug: read_config_files: reading clients
Tue Jun 3 02:36:13 2008 : Debug: read_config_files: reading realms
Tue Jun 3 02:36:13 2008 : Debug: radiusd: entering modules setup
Tue Jun 3 02:36:13 2008 : Debug: Module: Library search path is /usr/
lib/freeradius
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded PAP
Tue Jun 3 02:36:13 2008 : Debug: pap: encryption_scheme = "clear"
Tue Jun 3 02:36:13 2008 : Debug: pap: auto_header = no
Tue Jun 3 02:36:13 2008 : Debug: Module: Instantiated pap (pap)
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded CHAP
Tue Jun 3 02:36:13 2008 : Debug: Module: Instantiated chap (chap)
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded MS-CHAP
Tue Jun 3 02:36:13 2008 : Debug: mschap: use_mppe = no
Tue Jun 3 02:36:13 2008 : Debug: mschap: require_encryption = no
Tue Jun 3 02:36:13 2008 : Debug: mschap: require_strong = no
Tue Jun 3 02:36:13 2008 : Debug: mschap: with_ntdomain_hack = no
Tue Jun 3 02:36:13 2008 : Debug: mschap: passwd = "(null)"
Tue Jun 3 02:36:13 2008 : Debug: mschap: ntlm_auth = "(null)"
Tue Jun 3 02:36:13 2008 : Debug: Module: Instantiated mschap (mschap)
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded preprocess
Tue Jun 3 02:36:13 2008 : Debug: preprocess: huntgroups = "/etc/
freeradius/huntgroups"
Tue Jun 3 02:36:13 2008 : Debug: preprocess: hints = "/etc/
freeradius/hints"
Tue Jun 3 02:36:13 2008 : Debug: preprocess: with_ascend_hack = no
Tue Jun 3 02:36:13 2008 : Debug: preprocess:
ascend_channels_per_line = 23Tue Jun 3 02:36:13 2008 : Debug:
preprocess: with_ntdomain_hack = no
Tue Jun 3 02:36:13 2008 : Debug: preprocess:
with_specialix_jetstream_hack = no
Tue Jun 3 02:36:13 2008 : Debug: preprocess: with_cisco_vsa_hack =
no
Tue Jun 3 02:36:13 2008 : Debug: preprocess: with_alvarion_vsa_hack
= no
Tue Jun 3 02:36:13 2008 : Debug: Module: Instantiated preprocess
(preprocess)
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded files
Tue Jun 3 02:36:13 2008 : Debug: files: usersfile = "/etc/freeradius/
users"
Tue Jun 3 02:36:13 2008 : Debug: files: acctusersfile = "/etc/
freeradius/acct_users"
Tue Jun 3 02:36:13 2008 : Debug: files: preproxy_usersfile = "/etc/
freeradius/preproxy_users"
Tue Jun 3 02:36:13 2008 : Debug: files: compat = "no"
Tue Jun 3 02:36:13 2008 : Debug: Module: Instantiated files (files)
Tue Jun 3 02:36:13 2008 : Debug: Module: Loaded SQL
Tue Jun 3 02:36:13 2008 : Debug: sql: driver = "rlm_sql_postgresql"
Tue Jun 3 02:36:13 2008 : Debug: sql: server = "127.0.0.1"
Tue Jun 3 02:36:13 2008 : Debug: sql: port = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: login = "cake"
Tue Jun 3 02:36:13 2008 : Debug: sql: password = "cake"
Tue Jun 3 02:36:13 2008 : Debug: sql: radius_db = "cake"
Tue Jun 3 02:36:13 2008 : Debug: sql: nas_table = "nas"
Tue Jun 3 02:36:13 2008 : Debug: sql: sqltrace = yes
Tue Jun 3 02:36:13 2008 : Debug: sql: sqltracefile = "/var/log/
freeradius/sqltrace.sql"
Tue Jun 3 02:36:13 2008 : Debug: sql: readclients = no
Tue Jun 3 02:36:13 2008 : Debug: sql: deletestalesessions = no
Tue Jun 3 02:36:13 2008 : Debug: sql: num_sql_socks = 30
Tue Jun 3 02:36:13 2008 : Debug: sql: sql_user_name = "%{User-Name}"
Tue Jun 3 02:36:13 2008 : Debug: sql: default_user_profile = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: query_on_not_found = no
Tue Jun 3 02:36:13 2008 : Debug: sql: authorize_check_query =
"select * from cake.auth_check('%{SQL-User-Name}')"
Tue Jun 3 02:36:13 2008 : Debug: sql: authorize_reply_query =
"select * from cake.auth_reply('%{SQL-User-Name}')"
Tue Jun 3 02:36:13 2008 : Debug: sql: authorize_group_check_query =
""
Tue Jun 3 02:36:13 2008 : Debug: sql: authorize_group_reply_query =
""
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_onoff_query = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_update_query =
"select cake.acct_update('%{Acct-Unique-Session-Id}', %{Acct-Output-
Octets},%{Acct-Input-Octets})"
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_update_query_alt =
""
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_start_query =
"select start_session('%{Acct-Unique-Session-Id}','%{SQL-User-Name}')"
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_start_query_alt =
""
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_stop_query =
"select stop_session(%{Acct-Input-Octets},%{Acct-Output-Octets},'%
{Acct-Unique-Session-Id}')"
Tue Jun 3 02:36:13 2008 : Debug: sql: accounting_stop_query_alt = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: group_membership_query = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: connect_failure_retry_delay =
60
Tue Jun 3 02:36:13 2008 : Debug: sql: simul_count_query = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: simul_verify_query = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: postauth_query = ""
Tue Jun 3 02:36:13 2008 : Debug: sql: safe-characters =
"@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-
_: /"
Tue Jun 3 02:36:13 2008 : Info: rlm_sql (cake_sql): Driver
rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked
Tue Jun 3 02:36:13 2008 : Info: rlm_sql (cake_sql): Attempting to
connect to ca...@127.0.0.1:/cake
Tue Jun 3 02:36:13 2008 : Debug: rlm_sql (cake_sql): starting 0
Tue Jun 3 02:36:13 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #0
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #0
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): starting 1
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #1
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #1
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): starting 2
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #2
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #2
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): starting 3
Tue Jun 3 02:36:14 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #3
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #3
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 4
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #4
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #4
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 5
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #5
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #5
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 6
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #6
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #6
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 7
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #7
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #7
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 8
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #8
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #8
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 9
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #9
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #9
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 10
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #10
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #10
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 11
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #11
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #11
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 12
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #12
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #12
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 13
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #13
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #13
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 14
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #14
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #14
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 15
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #15
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #15
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 16
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #16
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #16
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 17
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #17
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #17
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): starting 18
Tue Jun 3 02:36:15 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #18
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #18
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 19
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #19
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #19
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 20
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #20
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #20
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 21
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #21
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #21
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 22
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #22
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #22
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 23
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #23
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #23
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 24
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #24
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #24
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 25
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #25
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #25
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 26
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #26
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #26
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 27
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #27
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #27
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 28
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #28
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #28
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): starting 29
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Attempting to
connect rlm_sql_postgresql #29
Tue Jun 3 02:36:16 2008 : Debug: rlm_sql (cake_sql): Connected new DB
handle, #29
Tue Jun 3 02:36:16 2008 : Debug: Module: Instantiated sql (cake_sql)
Tue Jun 3 02:36:16 2008 : Debug: Module: Loaded Acct-Unique-Session-
Id
Tue Jun 3 02:36:16 2008 : Debug: acct_unique: key = "User-Name, Acct-
Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port"
Tue Jun 3 02:36:16 2008 : Debug: Module: Instantiated acct_unique
(acct_unique)
Tue Jun 3 02:36:16 2008 : Debug: Listening on authentication *:1812
Tue Jun 3 02:36:16 2008 : Debug: Listening on accounting *:1813
Tue Jun 3 02:36:16 2008 : Info: Ready to process requests.
rad_recv: Access-Request packet from host 127.0.0.1:1030, id=159,
length=100 Service-Type = Framed-User
Framed-Protocol = PPP
User-Name = "111"
CHAP-Challenge = 0x0d79320cf117ae968cd988b91d49f4c4
User-Name = "111"
CHAP-Password = 0x30368f41334399a7f492786a4fff578608
Calling-Station-Id = "192.168.1.10"
NAS-IP-Address = 127.0.0.1
NAS-Port = 0
Tue Jun 3 02:37:12 2008 : Debug: Processing the authorize section
NAS-IP-Address = 127.0.0.1
NAS-Port = 0
of radiusd.conf
Tue Jun 3 02:37:12 2008 : Debug: modcall: entering group authorize
for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modcall[authorize]: module
"preprocess" returns ok for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: calling chap
(rlm_chap) for request 0
Tue Jun 3 02:37:12 2008 : Debug: rlm_chap: Setting 'Auth-Type :=
CHAP'
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: returned
from chap (rlm_chap) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modcall[authorize]: module "chap"
returns ok for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: calling
mschap (rlm_mschap) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: returned
from mschap (rlm_mschap) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modcall[authorize]: module
"mschap" returns noop for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: calling
files (rlm_files) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: returned
from files (rlm_files) for request 0
Tue Jun 3 02:37:12 2008 : Debug: modcall[authorize]: module "files"
returns notfound for request 0
Tue Jun 3 02:37:12 2008 : Debug: modsingle[authorize]: calling
cake_sql (rlm_sql) for request 0
Tue Jun 3 02:37:12 2008 : Debug: radius_xlat: '111'
Tue Jun 3 02:37:12 2008 : Debug: rlm_sql (cake_sql): sql_set_user
escaped user --> '111'
Tue Jun 3 02:37:12 2008 : Debug: radius_xlat: 'select * from
cake.auth_check('111')'
Tue Jun 3 02:37:12 2008 : Debug: rlm_sql (cake_sql): Reserving sql
socket id: 29
Tue Jun 3 02:37:12 2008 : Debug: rlm_sql_postgresql: query: select *
from cake.auth_check('111')
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OK
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql_postgresql: affected rows =
Tue Jun 3 02:37:14 2008 : Debug: radius_xlat: ''
Tue Jun 3 02:37:14 2008 : Debug: radius_xlat: 'select * from
cake.auth_reply('111')'
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql_postgresql: query: select *
from cake.auth_reply('111')
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OK
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql_postgresql: affected rows =
Tue Jun 3 02:37:14 2008 : Debug: radius_xlat: ''
Tue Jun 3 02:37:14 2008 : Debug: rlm_sql (cake_sql): Released sql
socket id: 29
Tue Jun 3 02:37:14 2008 : Debug: modsingle[authorize]: returned
from cake_sql (rlm_sql) for request 0
Tue Jun 3 02:37:14 2008 : Debug: modcall[authorize]: module
"cake_sql" returns ok for request 0
Tue Jun 3 02:37:14 2008 : Debug: modcall: leaving group authorize
(returns ok) for request 0
Tue Jun 3 02:37:14 2008 : Debug: rad_check_password: Found Auth-
Type CHAP
Tue Jun 3 02:37:14 2008 : Debug: auth: type "CHAP"
Tue Jun 3 02:37:14 2008 : Debug: Processing the authenticate
section of radiusd.conf
Tue Jun 3 02:37:14 2008 : Debug: modcall: entering group CHAP for
request 0Tue Jun 3 02:37:14 2008 : Debug: modsingle[authenticate]:
calling chap (rlm_chap) for request 0
Tue Jun 3 02:37:14 2008 : Debug: rlm_chap: login attempt by "111"
with CHAP password
Tue Jun 3 02:37:14 2008 : Debug: rlm_chap: Using clear text
password "111" for user 111 authentication.
Tue Jun 3 02:37:14 2008 : Debug: rlm_chap: chap user 111
authenticated succesfully
Tue Jun 3 02:37:14 2008 : Debug: modsingle[authenticate]: returned
from chap (rlm_chap) for request 0
Tue Jun 3 02:37:14 2008 : Debug: modcall[authenticate]: module
"chap" returns ok for request 0
Tue Jun 3 02:37:14 2008 : Debug: modcall: leaving group CHAP (returns
ok) for request 0
Tue Jun 3 02:37:14 2008 : Auth: Login OK: [111] (from client
localhost port 0 cli 192.168.1.10)
Sending Access-Accept of id 159 to 127.0.0.1 port 1030
Framed-IP-Address := 192.168.2.3
Framed-IP-Netmask := 255.255.255.0
Session-Timeout := 43200
Idle-Timeout := 7200
Acct-Interim-Interval := 60
Octets-Direction := Output
Tue Jun 3 02:37:14 2008 : Debug: Finished request 0
Tue Jun 3 02:37:14 2008 : Debug: Going to the next request
Tue Jun 3 02:37:14 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 02:37:14 2008 : Debug: Waking up in 6 seconds...
Tue Jun 3 02:37:20 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 02:37:20 2008 : Debug: Cleaning up request 0 ID 159 with
timestamp 48448428
Tue Jun 3 02:37:20 2008 : Debug: Nothing to do. Sleeping until we
see a request.
Конфиг pptpd-options
lock
name pptpd
nodeflate
nobsdcomp
auth
+chap
+mschap-v2
+mschap
-pap
nomppe
silent
proxyarp
ms-dns 192.168.39.1
ms-dns 192.168.251.1
plugin radius.so
debug
dump
Конфиг pptpd.conf
debug
localip локальный ip сервера
option /etc/ppp/pptpd-options
JasonX
May 27, 2008, 8:47:11 AM5/27/08
to cakebilling
!!! Работает !!!
В /etc/freeradius/clients.conf неправильный secret был !!!
Извините за беспокойство :)
rad_recv: Access-Request packet from host 127.0.0.1:1030, id=175,
CHAP-Challenge = 0x4221294ee06ccd531e002ecb59362083
CHAP-Password = 0x76a4a3b9fed0c3651444fae543721d2249
of radiusd.conf
Tue Jun 3 03:45:26 2008 : Debug: modcall: entering group authorize
for request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: calling
(rlm_chap) for request 0
Tue Jun 3 03:45:26 2008 : Debug: rlm_chap: Setting 'Auth-Type :=
CHAP'
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: returned
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql (cake_sql): sql_set_user
escaped user --> 'qwe'
Tue Jun 3 03:45:26 2008 : Debug: radius_xlat: 'select * from
cake.auth_check('qwe')'
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql (cake_sql): Reserving sql
socket id: 29
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql: query: select *
from cake.auth_check('qwe')
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OKTue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql:
affected rows =
Tue Jun 3 03:45:26 2008 : Debug: radius_xlat: ''
Tue Jun 3 03:45:26 2008 : Debug: radius_xlat: 'select * from
cake.auth_reply('qwe')'
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql: query: select *
from cake.auth_reply('qwe')
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OKTue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql:
affected rows =
Tue Jun 3 03:45:26 2008 : Debug: radius_xlat: ''
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql (cake_sql): Released sql
socket id: 29
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: returned
Type CHAPTue Jun 3 03:45:26 2008 : Debug: auth: type "CHAP"
Tue Jun 3 03:45:26 2008 : Debug: Processing the authenticate
section of radiusd.conf
Tue Jun 3 03:45:26 2008 : Debug: modcall: entering group CHAP for
request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authenticate]: calling
with CHAP password
Tue Jun 3 03:45:26 2008 : Debug: rlm_chap: Using clear text
password "123" for user qwe authentication.
Tue Jun 3 03:45:26 2008 : Debug: rlm_chap: chap user qwe
authenticated succesfully
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authenticate]: returned
ok) for request 0
Tue Jun 3 03:45:26 2008 : Auth: Login OK: [qwe] (from client
Framed-IP-Address := 192.168.2.5
Tue Jun 3 03:45:26 2008 : Debug: Going to the next request
Tue Jun 3 03:45:26 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 03:45:26 2008 : Debug: Waking up in 6 seconds...
rad_recv: Accounting-Request packet from host 127.0.0.1:1030, id=176,
length=109
Acct-Session-Id = "484494270D3300"
User-Name = "qwe"
Acct-Status-Type = Start
Acct-Authentic = RADIUS
NAS-Port-Type = Async
Framed-IP-Address = 192.168.2.5
Tue Jun 3 03:45:27 2008 : Debug: Processing the preacct section of
radiusd.conf
Tue Jun 3 03:45:27 2008 : Debug: modcall: entering group preacct for
request 1
Tue Jun 3 03:45:27 2008 : Debug: modsingle[preacct]: calling
preprocess (rlm_preprocess) for request 1
Tue Jun 3 03:45:27 2008 : Debug: modsingle[preacct]: returned from
preprocess (rlm_preprocess) for request 1
Tue Jun 3 03:45:27 2008 : Debug: modcall[preacct]: module
"preprocess" returns noop for request 1
Tue Jun 3 03:45:27 2008 : Debug: modcall: leaving group preacct
(returns noop) for request 1
Tue Jun 3 03:45:27 2008 : Debug: Processing the accounting section
of radiusd.conf
Tue Jun 3 03:45:27 2008 : Debug: modcall: entering group accounting
for request 1
Tue Jun 3 03:45:27 2008 : Debug: modsingle[accounting]: calling
acct_unique (rlm_acct_unique) for request 1
Tue Jun 3 03:45:27 2008 : Debug: rlm_acct_unique: Hashing 'NAS-Port =
0,Client-IP-Address = 127.0.0.1,NAS-IP-Address = 127.0.0.1,Acct-
Session-Id = "484494270D3300",User-Name = "qwe"'
Tue Jun 3 03:45:27 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-
ID = "06c9d395f27246ac".
Tue Jun 3 03:45:27 2008 : Debug: modsingle[accounting]: returned
from acct_unique (rlm_acct_unique) for request 1
Tue Jun 3 03:45:27 2008 : Debug: modcall[accounting]: module
"acct_unique" returns ok for request 1
Tue Jun 3 03:45:27 2008 : Debug: modsingle[accounting]: calling
cake_sql (rlm_sql) for request 1
Tue Jun 3 03:45:27 2008 : Debug: radius_xlat: 'qwe'
Tue Jun 3 03:45:27 2008 : Debug: rlm_sql (cake_sql): sql_set_user
escaped user --> 'qwe'
Tue Jun 3 03:45:27 2008 : Debug: radius_xlat: 'select
start_session('06c9d395f27246ac','qwe')'
Tue Jun 3 03:45:27 2008 : Debug: radius_xlat: '/var/log/freeradius/
sqltrace.sql'
Tue Jun 3 03:45:27 2008 : Debug: rlm_sql (cake_sql): Reserving sql
socket id: 28
Tue Jun 3 03:45:27 2008 : Debug: rlm_sql_postgresql: query: select
start_session('06c9d395f27246ac','qwe')
Tue Jun 3 03:45:27 2008 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OKTue Jun 3 03:45:27 2008 : Debug: rlm_sql_postgresql:
affected rows =
Tue Jun 3 03:45:27 2008 : Debug: rlm_sql (cake_sql): Released sql
socket id: 28
Tue Jun 3 03:45:27 2008 : Debug: modsingle[accounting]: returned
from cake_sql (rlm_sql) for request 1
Tue Jun 3 03:45:27 2008 : Debug: modcall[accounting]: module
"cake_sql" returns ok for request 1
Tue Jun 3 03:45:27 2008 : Debug: modcall: leaving group accounting
(returns ok) for request 1
Sending Accounting-Response of id 176 to 127.0.0.1 port 1030
Tue Jun 3 03:45:27 2008 : Debug: Finished request 1
Tue Jun 3 03:45:27 2008 : Debug: Going to the next request
Tue Jun 3 03:45:27 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 03:45:27 2008 : Debug: Waking up in 5 seconds...
Tue Jun 3 03:45:32 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 03:45:32 2008 : Debug: Cleaning up request 0 ID 175 with
timestamp 48449426
Tue Jun 3 03:45:32 2008 : Debug: Waking up in 1 seconds...
Tue Jun 3 03:45:33 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 03:45:33 2008 : Debug: Cleaning up request 1 ID 176 with
timestamp 48449427
Tue Jun 3 03:45:33 2008 : Debug: Nothing to do. Sleeping until we
see a request.
В /etc/freeradius/clients.conf неправильный secret был !!!
Извините за беспокойство :)
rad_recv: Access-Request packet from host 127.0.0.1:1030, id=175,
length=100
Service-Type = Framed-User
Framed-Protocol = PPP
User-Name = "qwe"
Service-Type = Framed-User
Framed-Protocol = PPP
CHAP-Challenge = 0x4221294ee06ccd531e002ecb59362083
CHAP-Password = 0x76a4a3b9fed0c3651444fae543721d2249
Calling-Station-Id = "192.168.1.10"
NAS-IP-Address = 127.0.0.1
NAS-Port = 0
Tue Jun 3 03:45:26 2008 : Debug: Processing the authorize section
NAS-IP-Address = 127.0.0.1
NAS-Port = 0
of radiusd.conf
Tue Jun 3 03:45:26 2008 : Debug: modcall: entering group authorize
for request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: calling
preprocess (rlm_preprocess) for request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: returned
from preprocess (rlm_preprocess) for request 0
Tue Jun 3 03:45:26 2008 : Debug: modcall[authorize]: module
"preprocess" returns ok for request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: calling chap
(rlm_chap) for request 0
Tue Jun 3 03:45:26 2008 : Debug: rlm_chap: Setting 'Auth-Type :=
CHAP'
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: returned
from chap (rlm_chap) for request 0
Tue Jun 3 03:45:26 2008 : Debug: modcall[authorize]: module "chap"
returns ok for request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: calling
mschap (rlm_mschap) for request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: returned
from mschap (rlm_mschap) for request 0
Tue Jun 3 03:45:26 2008 : Debug: modcall[authorize]: module
"mschap" returns noop for request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: calling
files (rlm_files) for request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: returned
from files (rlm_files) for request 0
Tue Jun 3 03:45:26 2008 : Debug: modcall[authorize]: module "files"
returns notfound for request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: calling
cake_sql (rlm_sql) for request 0
Tue Jun 3 03:45:26 2008 : Debug: radius_xlat: 'qwe'
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql (cake_sql): sql_set_user
escaped user --> 'qwe'
Tue Jun 3 03:45:26 2008 : Debug: radius_xlat: 'select * from
cake.auth_check('qwe')'
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql (cake_sql): Reserving sql
socket id: 29
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql: query: select *
from cake.auth_check('qwe')
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OKTue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql:
affected rows =
Tue Jun 3 03:45:26 2008 : Debug: radius_xlat: ''
Tue Jun 3 03:45:26 2008 : Debug: radius_xlat: 'select * from
cake.auth_reply('qwe')'
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql: query: select *
from cake.auth_reply('qwe')
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OKTue Jun 3 03:45:26 2008 : Debug: rlm_sql_postgresql:
affected rows =
Tue Jun 3 03:45:26 2008 : Debug: radius_xlat: ''
Tue Jun 3 03:45:26 2008 : Debug: rlm_sql (cake_sql): Released sql
socket id: 29
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authorize]: returned
from cake_sql (rlm_sql) for request 0
Tue Jun 3 03:45:26 2008 : Debug: modcall[authorize]: module
"cake_sql" returns ok for request 0
Tue Jun 3 03:45:26 2008 : Debug: modcall: leaving group authorize
(returns ok) for request 0
Tue Jun 3 03:45:26 2008 : Debug: rad_check_password: Found Auth-
Type CHAPTue Jun 3 03:45:26 2008 : Debug: auth: type "CHAP"
Tue Jun 3 03:45:26 2008 : Debug: Processing the authenticate
section of radiusd.conf
Tue Jun 3 03:45:26 2008 : Debug: modcall: entering group CHAP for
request 0
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authenticate]: calling
chap (rlm_chap) for request 0
Tue Jun 3 03:45:26 2008 : Debug: rlm_chap: login attempt by "qwe"
with CHAP password
Tue Jun 3 03:45:26 2008 : Debug: rlm_chap: Using clear text
password "123" for user qwe authentication.
Tue Jun 3 03:45:26 2008 : Debug: rlm_chap: chap user qwe
authenticated succesfully
Tue Jun 3 03:45:26 2008 : Debug: modsingle[authenticate]: returned
from chap (rlm_chap) for request 0
Tue Jun 3 03:45:26 2008 : Debug: modcall[authenticate]: module
"chap" returns ok for request 0
Tue Jun 3 03:45:26 2008 : Debug: modcall: leaving group CHAP (returns
ok) for request 0
Tue Jun 3 03:45:26 2008 : Auth: Login OK: [qwe] (from client
localhost port 0 cli 192.168.1.10)
Sending Access-Accept of id 175 to 127.0.0.1 port 1030
Framed-IP-Address := 192.168.2.5
Framed-IP-Netmask := 255.255.255.0
Session-Timeout := 43200
Idle-Timeout := 7200
Session-Octets-Limit := 10485760
Session-Timeout := 43200
Idle-Timeout := 7200
Acct-Interim-Interval := 60
Octets-Direction := Output
Tue Jun 3 03:45:26 2008 : Debug: Finished request 0
Octets-Direction := Output
Tue Jun 3 03:45:26 2008 : Debug: Going to the next request
Tue Jun 3 03:45:26 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 03:45:26 2008 : Debug: Waking up in 6 seconds...
rad_recv: Accounting-Request packet from host 127.0.0.1:1030, id=176,
length=109
Acct-Session-Id = "484494270D3300"
User-Name = "qwe"
Acct-Status-Type = Start
Service-Type = Framed-User
Framed-Protocol = PPP
Calling-Station-Id = "192.168.1.10"
Framed-Protocol = PPP
Acct-Authentic = RADIUS
NAS-Port-Type = Async
Framed-IP-Address = 192.168.2.5
NAS-IP-Address = 127.0.0.1
NAS-Port = 0
Acct-Delay-Time = 0
NAS-Port = 0
Tue Jun 3 03:45:27 2008 : Debug: Processing the preacct section of
radiusd.conf
Tue Jun 3 03:45:27 2008 : Debug: modcall: entering group preacct for
request 1
Tue Jun 3 03:45:27 2008 : Debug: modsingle[preacct]: calling
preprocess (rlm_preprocess) for request 1
Tue Jun 3 03:45:27 2008 : Debug: modsingle[preacct]: returned from
preprocess (rlm_preprocess) for request 1
Tue Jun 3 03:45:27 2008 : Debug: modcall[preacct]: module
"preprocess" returns noop for request 1
Tue Jun 3 03:45:27 2008 : Debug: modcall: leaving group preacct
(returns noop) for request 1
Tue Jun 3 03:45:27 2008 : Debug: Processing the accounting section
of radiusd.conf
Tue Jun 3 03:45:27 2008 : Debug: modcall: entering group accounting
for request 1
Tue Jun 3 03:45:27 2008 : Debug: modsingle[accounting]: calling
acct_unique (rlm_acct_unique) for request 1
Tue Jun 3 03:45:27 2008 : Debug: rlm_acct_unique: Hashing 'NAS-Port =
0,Client-IP-Address = 127.0.0.1,NAS-IP-Address = 127.0.0.1,Acct-
Session-Id = "484494270D3300",User-Name = "qwe"'
Tue Jun 3 03:45:27 2008 : Debug: rlm_acct_unique: Acct-Unique-Session-
ID = "06c9d395f27246ac".
Tue Jun 3 03:45:27 2008 : Debug: modsingle[accounting]: returned
from acct_unique (rlm_acct_unique) for request 1
Tue Jun 3 03:45:27 2008 : Debug: modcall[accounting]: module
"acct_unique" returns ok for request 1
Tue Jun 3 03:45:27 2008 : Debug: modsingle[accounting]: calling
cake_sql (rlm_sql) for request 1
Tue Jun 3 03:45:27 2008 : Debug: radius_xlat: 'qwe'
Tue Jun 3 03:45:27 2008 : Debug: rlm_sql (cake_sql): sql_set_user
escaped user --> 'qwe'
Tue Jun 3 03:45:27 2008 : Debug: radius_xlat: 'select
start_session('06c9d395f27246ac','qwe')'
Tue Jun 3 03:45:27 2008 : Debug: radius_xlat: '/var/log/freeradius/
sqltrace.sql'
Tue Jun 3 03:45:27 2008 : Debug: rlm_sql (cake_sql): Reserving sql
socket id: 28
Tue Jun 3 03:45:27 2008 : Debug: rlm_sql_postgresql: query: select
start_session('06c9d395f27246ac','qwe')
Tue Jun 3 03:45:27 2008 : Debug: rlm_sql_postgresql: Status:
PGRES_TUPLES_OKTue Jun 3 03:45:27 2008 : Debug: rlm_sql_postgresql:
affected rows =
Tue Jun 3 03:45:27 2008 : Debug: rlm_sql (cake_sql): Released sql
socket id: 28
Tue Jun 3 03:45:27 2008 : Debug: modsingle[accounting]: returned
from cake_sql (rlm_sql) for request 1
Tue Jun 3 03:45:27 2008 : Debug: modcall[accounting]: module
"cake_sql" returns ok for request 1
Tue Jun 3 03:45:27 2008 : Debug: modcall: leaving group accounting
(returns ok) for request 1
Sending Accounting-Response of id 176 to 127.0.0.1 port 1030
Tue Jun 3 03:45:27 2008 : Debug: Finished request 1
Tue Jun 3 03:45:27 2008 : Debug: Going to the next request
Tue Jun 3 03:45:27 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 03:45:27 2008 : Debug: Waking up in 5 seconds...
Tue Jun 3 03:45:32 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 03:45:32 2008 : Debug: Cleaning up request 0 ID 175 with
timestamp 48449426
Tue Jun 3 03:45:32 2008 : Debug: Waking up in 1 seconds...
Tue Jun 3 03:45:33 2008 : Debug: --- Walking the entire request list
---
Tue Jun 3 03:45:33 2008 : Debug: Cleaning up request 1 ID 176 with
timestamp 48449427
Tue Jun 3 03:45:33 2008 : Debug: Nothing to do. Sleeping until we
see a request.
Anatoly Shipitsin
May 27, 2008, 9:28:45 AM5/27/08
to cakeb...@googlegroups.com
27 мая 2008 г. 18:47 пользователь JasonX <Jas...@tut.by> написал:
!!! Работает !!!
В /etc/freeradius/clients.conf неправильный secret был !!!
Извините за беспокойство :)
Вы прежде чем что-то постить внимательно прочитайте логи и документацию.
В 90% случаев вопросы решаются именно так :)
В 90% случаев вопросы решаются именно так :)
jesem
May 27, 2008, 12:33:23 PM5/27/08
to cakeb...@googlegroups.com
Дорогие друзья, переставайте в конце концов постить длинные и бессмысленные логи, иначе буду жестоко банить.
JasonX
May 27, 2008, 2:25:48 PM5/27/08
to cakebilling
А как отобразить поведение программы тогда? Если кинуть только ошибку,
разработчик может не понять что к ней привело...
разработчик может не понять что к ней привело...
Reply all
Reply to author
Forward
0 new messages