Re: Problem with proxy-radius function

11 Apr 2008

      Hello 
Debug is difficult because of Segmentation Fault. 
I will try to rebuild radius (in the night) with last patch , that you already provide.
Is It something wrong whth my configuration? 
I decide to disable all nonused modules. Maybe I disable something major?

root@aaa# radiusd -X
FreeRADIUS Version 2.0.4, for host i686-pc-linux-gnu, built on Apr  7 2008 at 10:36:05
Copyright (C) 1999-2008 The FreeRADIUS server project and contributors. 
There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A 
PARTICULAR PURPOSE. 
You may redistribute copies of FreeRADIUS under the terms of the 
GNU General Public License. 
Starting - reading configuration files ...
including configuration file /etc/raddb/radiusd.conf
including configuration file /etc/raddb/proxy.conf
including configuration file /etc/raddb/clients.conf
including configuration file /etc/raddb/sql.conf
including configuration file /etc/raddb/sql/postgresql/dialup.conf
including files in directory /etc/raddb/sites-enabled/
including configuration file /etc/raddb/sites-enabled/default
including dictionary file /etc/raddb/dictionary
main {
        prefix = "/usr"
        localstatedir = "/var"
        logdir = "/var/log/radius"
        libdir = "/usr/lib"
        radacctdir = "/var/log/radius/radacct"
        hostname_lookups = no
        max_request_time = 30
        cleanup_delay = 5
        max_requests = 8192
        allow_core_dumps = no
        pidfile = "/var/run/radiusd/radiusd.pid"
        checkrad = "/usr/sbin/checkrad"
        debug_level = 0
        proxy_requests = yes
 security {
        max_attributes = 200
        reject_delay = 1
        status_server = no
 }
}
 client MAIN_NAS {
        ipaddr = 192.168.101.1
        netmask = 32
        require_message_authenticator = no
        secret = "key"
        shortname = "nas1"
        nastype = "other"
 }
 client jds {
        ipaddr = 192.168.0.1
        require_message_authenticator = no
        secret = "superkey"
        shortname = "jds"
        nastype = "other"
 }
 client jds2 {
        ipaddr = 192.168.0.2
        require_message_authenticator = no
        secret = "superkey"
        shortname = "jds2"
        nastype = "other"
 }
radiusd: #### Loading Realms and Home Servers ####
 proxy server {
        retry_delay = 5
        retry_count = 3
        default_fallback = no
        dead_time = 120
        wake_all_if_all_dead = no
 }
 home_server jds1 {
        ipaddr = 192.168.0.1
        port = 1646
        type = "acct"
        secret = "superkey"
        response_window = 30
        max_outstanding = 65536
        zombie_period = 40
        status_check = "request"
        ping_check = "none"
        ping_interval = 30
        check_interval = 30
        num_answers_to_alive = 3
        num_pings_to_alive = 3
        revive_interval = 300
        status_check_timeout = 4
 }
 home_server jds2 {
        ipaddr = 192.168.0.2
        port = 1646
        type = "acct"
        secret = "superkey"
        response_window = 30
        max_outstanding = 65536
        zombie_period = 40
        status_check = "request"
        ping_check = "none"
        ping_interval = 30
        check_interval = 30
        num_answers_to_alive = 3
        num_pings_to_alive = 3
        revive_interval = 300
        status_check_timeout = 4
 }
 home_server_pool jds {
        type = fail-over
        home_server = jds1
        home_server = jds2
 }
 realm domain.com {
        acct_pool = jds
        nostrip
 }
radiusd: #### Instantiating modules ####
 instantiate {
 }
radiusd: #### Loading Virtual Servers ####
server {
 modules {
 Module: Checking preacct {...} for more modules to load
 Module: Linked to module rlm_realm
 Module: Instantiating suffix
  realm suffix {
        format = "suffix"
        delimiter = "@"
        ignore_default = no
        ignore_null = no
  }
 Module: Checking accounting {...} for more modules to load
 Module: Linked to module rlm_acct_unique
 Module: Instantiating acct_unique
  acct_unique {
        key = "Calling-Station-Id, Acct-Session-Id, 3GPP2-Correlation-Id"
  }
 Module: Linked to module rlm_sql
 Module: Instantiating sql
  sql {
        driver = "rlm_sql_postgresql"
        server = "localhost"
        port = ""
        login = "rad"
        password = "......"
        radius_db = "radius"
        read_groups = yes
        sqltrace = no
        sqltracefile = "/var/log/radius/sqltrace.sql"
        readclients = no
        deletestalesessions = yes
        num_sql_socks = 48
        sql_user_name = "%{User-Name}"
        default_user_profile = ""
        nas_query = "SELECT id,nasname,shortname,type,secret FROM nas"
        authorize_check_query = ""
        authorize_reply_query = ""
        authorize_group_check_query = ""
        authorize_group_reply_query = ""
        accounting_onoff_query = ""
        accounting_update_query = ""
        accounting_update_query_alt = ""
        accounting_start_query = "INSERT into radacct (AcctSessionId, AcctUniqueId, CallingStationId, AcctStartTime, AcctStopTime,   superkeyActiveTime, AcctInputOctets, 
AcctOutputOctets, FramedIPAddress, UserName,  ReleaseIndicator, superkeyBadPPPFrameCount, superkeyCorrelationId, AcctSessionTime, NASIPAddress) values('%{Acct-Session-Id}', '%{Acct-
Unique-Session-Id}', '%{Calling-Station-Id}', '%S', NULL,'0', '0', '0', '%{Framed-IP-Address}', trim('%{SQL-User-Name}'), '0', '0', '%{3GPP2-Correlation-Id}', '0', '%{NAS-IP-
Address}')"
        accounting_start_query_alt = ""
        accounting_stop_query = "UPDATE radacct SET AcctStopTime = '%S', AcctSessionTime = '%{Acct-Session-Time}', AcctInputOctets = '%{Acct-Input-Octets}', OutputPacket = '%
{Acct-Output-Packets}', InputPacket = '%{Acct-Input-Packets}', AcctOutputOctets = '%{Acct-Output-Octets}', ReleaseIndicator = '%{Acct-Terminate-Cause}', superkeyBadPPPFrameCount = 
'%{3GPP2-Bad-PPP-Frame-Count}', superkeyCorrelationId = '%{3GPP2-Correlation-Id}', superkeyActiveTime = '%{3GPP2-Active-Time}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'"
        accounting_stop_query_alt = ""
        connect_failure_retry_delay = 60
        simul_count_query = ""
        simul_verify_query = ""
        postauth_query = ""
        safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /"
  }
rlm_sql (sql): Driver rlm_sql_postgresql (module rlm_sql_postgresql) loaded and linked
rlm_sql (sql): Attempting to connect to radacc@localhost:/radius
rlm_sql (sql): starting 0
rlm_sql (sql): Attempting to connect rlm_sql_postgresql #0
rlm_sql (sql): Connected new DB handle, #0
.........
rlm_sql (sql): starting 47
rlm_sql (sql): Attempting to connect rlm_sql_postgresql #47
rlm_sql (sql): Connected new DB handle, #47
 Module: Checking pre-proxy {...} for more modules to load
 Module: Linked to module rlm_detail
 Module: Instantiating pre_proxy_log
  detail pre_proxy_log {
        detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d"
        header = "%t"
        detailperm = 384
        dirperm = 493
        locking = no
        log_packet_header = no
  }
 Module: Checking post-proxy {...} for more modules to load
 Module: Instantiating post_proxy_log
  detail post_proxy_log {
        detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d"
        header = "%t"
        detailperm = 384
        dirperm = 493
        locking = no
        log_packet_header = no
  }
 }
}
radiusd: #### Opening IP addresses and Ports ####
listen {
        type = "acct"
        ipaddr = *
        port = 0
}
Listening on accounting address * port 1813
Listening on proxy address * port 1222
Ready to process requests.
        Acct-Status-Type = Start
        User-Name = "test1@domain.com"
        Calling-Station-Id = "77734565"
        Framed-IP-Address = 192.168.50.19
        NAS-IP-Address = X.X.X.X
        Event-Timestamp = "Apr 10 2008 17:08:14 EEST"
        Acct-Session-Id = "0000000\000"
        NAS-Port-Type = Virtual
        NAS-Port = 1813
        Acct-Delay-Time = 0
        Service-Type = Framed-User
        Acct-Authentic = RADIUS
        3GPP2-ESN = "\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
        3GPP2-Attr-116 = 0x0000000000000000000000000000
        3GPP2-Correlation-Id = "09446618"
        3GPP2-Service-Reference-Id = 0x00000000
        3GPP2-Home-Agent-IP-Address = 0.0.0.0
        3GPP2-BSID = "2A2100021102"
        3GPP2-User-Id = 0
        3GPP2-Forward-FCH-Mux-Option = 0
        3GPP2-Reverse-FCH-Mux-Option = 0
        3GPP2-Service-Option = 59
        3GPP2-Forward-Traffic-Type = 0
        3GPP2-Reverse-Traffic-Type = 0
        3GPP2-FCH-Frame-Size = 0
        3GPP2-Forward-FCH-RC = 0
        3GPP2-Reverse-FCH-RC = 0
        3GPP2-IP-Technology = 1
        3GPP2-Compulsory-Tunnel-Indicator = 0
        3GPP2-DCCH-Frame-Size = 0
        3GPP2-Attr-78 = 0x00000000
        3GPP2-Forward-PDCH-RC = 0
        3GPP2-Forward-DCCH-Mux-Option = 0
        3GPP2-Reverse-DCCH-Mux-Option = 0
        3GPP2-Forward-DCCH-RC = 0
        3GPP2-Reverse-DHHC-RC = 0
        3GPP2-Attr-114 = 0x00000000
        3GPP2-IP-QoS = 10
        3GPP2-Airlink-Priority = 0
+- entering group preacct
    rlm_realm: Looking up realm "domain.com" for User-Name = "test1@domain.com"
    rlm_realm: Found realm "domain.com"
    rlm_realm: Proxying request from user test1 to realm domain.com
    rlm_realm: Adding Realm = "domain.com"
    rlm_realm: Preparing to proxy accounting request to realm "domain.com" 
++[suffix] returns updated
+- entering group accounting
rlm_acct_unique: Hashing '3GPP2-Correlation-Id = "09446618",Acct-Session-Id = "0000000\000",Calling-Station-Id = "77734565"'
rlm_acct_unique: Acct-Unique-Session-ID = "e05fa4c07c65ca2b".
++[acct_unique] returns ok
        expand: %{User-Name} -> test1@domain.com
rlm_sql (sql): sql_set_user escaped user --> 'test1@domain.com'
        expand: INSERT into radacct (AcctSessionId, AcctUniqueId, CallingStationId, AcctStartTime, AcctStopTime,   superkeyActiveTime, AcctInputOctets, AcctOutputOctets, 
FramedIPAddress, UserName,  ReleaseIndicator, superkeyBadPPPFrameCount, superkeyCorrelationId, AcctSessionTime, NASIPAddress) values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', 
'%{Calling-Station-Id}', '%S', NULL,'0', '0', '0', '%{Framed-IP-Address}', trim('%{SQL-User-Name}'), '0', '0', '%{3GPP2-Correlation-Id}', '0', '%{NAS-IP-Address}') -> INSERT 
into radacct (AcctSessionId, AcctUniqueId, CallingStationId, AcctStartTime, AcctStopTime,   superkeyActiveTime, AcctInputOctets, AcctOutputOctets, FramedIPAddress, UserName,  
ReleaseIndicator, superkeyBadPPPFrameCount, superkeyCorrelationId, AcctSessionTime, NASIPAddress) values('0000000', 'e05fa4c07c65ca2b', '77734565', '2008-04-10 17:08:13', 
NULL,'0', '0', '0', '192.168.50.19', trim('test1@domain.com'), '0', '0', '09446618', '0', '192.168.101.1')
rlm_sql (sql): Reserving sql socket id: 24
rlm_sql_postgresql: Status: PGRES_COMMAND_OK
rlm_sql_postgresql: query affected rows = 1
rlm_sql (sql): Released sql socket id: 24
++[sql] returns ok
+- entering group pre-proxy
        expand: /var/log/radius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d -> /var/log/radius/radacct/192.168.101.1/pre-proxy-detail-20080410
rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/radius/radacct/192.168.101.1/pre-proxy-detail-20080410
        expand: %t -> Thu Apr 10 17:08:13 2008
++[pre_proxy_log] returns ok
        Acct-Status-Type = Start
        User-Name = "test1@domain.com"
        Calling-Station-Id = "77734565"
        Framed-IP-Address = 192.168.50.19
        NAS-IP-Address = 192.168.101.1
        Event-Timestamp = "Apr 10 2008 17:08:14 EEST"
        Acct-Session-Id = "0000000\000"
        NAS-Port-Type = Virtual
        NAS-Port = 1813
        Acct-Delay-Time = 0
        Service-Type = Framed-User
        Acct-Authentic = RADIUS
        3GPP2-ESN = "\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
        3GPP2-Attr-116 = 0x0000000000000000000000000000
        3GPP2-Correlation-Id = "09446618"
        3GPP2-Service-Reference-Id = 0x00000000
        3GPP2-Home-Agent-IP-Address = 0.0.0.0
        3GPP2-BSID = "2A2100021102"
        3GPP2-User-Id = 0
        3GPP2-Forward-FCH-Mux-Option = 0
        3GPP2-Reverse-FCH-Mux-Option = 0
        3GPP2-Service-Option = 59
        3GPP2-Forward-Traffic-Type = 0
        3GPP2-Reverse-Traffic-Type = 0
        3GPP2-FCH-Frame-Size = 0
        3GPP2-Forward-FCH-RC = 0
        3GPP2-Reverse-FCH-RC = 0
        3GPP2-IP-Technology = 1
        3GPP2-Compulsory-Tunnel-Indicator = 0
        3GPP2-DCCH-Frame-Size = 0
        3GPP2-Attr-78 = 0x00000000
        3GPP2-Forward-PDCH-RC = 0
        3GPP2-Forward-DCCH-Mux-Option = 0
        3GPP2-Reverse-DCCH-Mux-Option = 0
        3GPP2-Forward-DCCH-RC = 0
        3GPP2-Reverse-DHHC-RC = 0
        3GPP2-Attr-114 = 0x00000000
        3GPP2-IP-QoS = 10
        3GPP2-Airlink-Priority = 0
        Proxy-State = 0x3937
Proxying request 551 to home server 192.168.0.1 port 1646
        Acct-Status-Type = Start
        User-Name = "test1@domain.com"
        Calling-Station-Id = "77734565"
        Framed-IP-Address = 192.168.50.19
        NAS-IP-Address = 192.168.101.1
        Event-Timestamp = "Apr 10 2008 17:08:14 EEST"
        Acct-Session-Id = "0000000\000"
        NAS-Port-Type = Virtual
        NAS-Port = 1813
        Acct-Delay-Time = 0
        Service-Type = Framed-User
        Acct-Authentic = RADIUS
        3GPP2-ESN = "\000\000\000\000\000\000\000\000\000\000\000\000\000\000\000"
        3GPP2-Attr-116 = 0x0000000000000000000000000000
        3GPP2-Correlation-Id = "09446618"
        3GPP2-Service-Reference-Id = 0x00000000
        3GPP2-Home-Agent-IP-Address = 0.0.0.0
        3GPP2-BSID = "2A2100021102"
        3GPP2-User-Id = 0
        3GPP2-Forward-FCH-Mux-Option = 0
        3GPP2-Reverse-FCH-Mux-Option = 0
        3GPP2-Service-Option = 59
        3GPP2-Forward-Traffic-Type = 0
        3GPP2-Reverse-Traffic-Type = 0
        3GPP2-FCH-Frame-Size = 0
        3GPP2-Forward-FCH-RC = 0
        3GPP2-Reverse-FCH-RC = 0
        3GPP2-IP-Technology = 1
        3GPP2-Compulsory-Tunnel-Indicator = 0
        3GPP2-DCCH-Frame-Size = 0
        3GPP2-Attr-78 = 0x00000000
        3GPP2-Forward-PDCH-RC = 0
        3GPP2-Forward-DCCH-Mux-Option = 0
        3GPP2-Reverse-DCCH-Mux-Option = 0
        3GPP2-Forward-DCCH-RC = 0
        3GPP2-Reverse-DHHC-RC = 0
        3GPP2-Attr-114 = 0x00000000
        3GPP2-IP-QoS = 10
        3GPP2-Airlink-Priority = 0
        Proxy-State = 0x3937
Going to the next request
Waking up in 0.9 seconds.
Ignoring request from unknown home server 192.168.0.1 port 1646
.................
Rejecting request 593 due to lack of any response from home server 192.168.0.1 port 1646
Finished request 593.
Cleaning up request 593 ID 139 with timestamp +90
Cleaning up request 593 ID 362747136 with timestamp +90
Segmentation fault
root@aaa# exit

----- Original Message ----
From: Alan DeKok <aland@deployingradius.com>
To: FreeRadius users mailing list <freeradius-users@lists.freeradius.org>
Sent: Friday, April 11, 2008 12:59:26 PM
Subject: Re: Problem with proxy-radius function

Ivan Popov wrote:
...
What I can say ..
root@aaa:/var/log/radius <mailto:root@aaa:/var/log/radius># tcpdump -i
eth0 host X.X.X.X
<sigh>  While this is interesting, you were asked for debugging output.
...
Is It correct? I thing it should be between port 1813 and 1646 ...
The traffic looks OK.  There may be something else going wrong, and
the debug output may show it.

  Is it possible to run the server in debug mode?  If not, why?

  Alan DeKok.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

__________________________________________________
Do You Yahoo!?
Tired of spam?  Yahoo! Mail has the best spam protection around 
http://mail.yahoo.com