3.0.0 detail: suppress now works, but found a SEGV elsewhere
Stefan Winter
stefan.winter at restena.lu
Wed Jan 8 08:24:42 CET 2014
Hi,
got a gdb bt below. This time for another request, which took a
different path in the config, crash happened after linelog this time.
So I think that whatever SEGVs here is not directly related to your fix
to suppress...
As per your reminder yesterday, I'll open a ticket for this.
(0) # Executing section post-auth from file /usr/local/freeradius/config/raddb/sites-enabled/staff
(0) post-auth {
(0) restena_log_policy restena_log_policy {
(0) reply_log : expand: "/var/log/radius/radacct/%Y%m%d/%{RESTENA-Service-Type}-service/reply-detail" -> '/var/log/radius/radacct/20140108/Staff-AAI-service/reply-detail'
(0) reply_log : /var/log/radius/radacct/%Y%m%d/%{RESTENA-Service-Type}-service/reply-detail expands to /var/log/radius/radacct/20140108/Staff-AAI-service/reply-detail
(0) reply_log : expand: "%t" -> 'Wed Jan 8 08:19:21 2014'
(0) [reply_log] = ok
(0) linelog : expand: "%{%{Acct-Status-Type}:-%{%{reply:Packet-Type}:-format}}" -> 'Access-Accept'
(0) linelog : expand: "/var/log/radius/activity.log" -> '/var/log/radius/activity.log'
(0) linelog : expand: "[%S] [AUTH OK ] '%{User-Name}' (%{RESTENA-Service-Type}:%{client:shortname})" -> '[2014-01-08 08:19:21] [AUTH OK ] 'swinter' (Staff-AAI:restmir-dns-lu-v4)'
(0) [linelog] = ok
Program received signal SIGSEGV, Segmentation fault.
0x00007ffff4415e47 in mod_post_auth (instance=0x9854e0, request=0x9d8410) at <command-line>:1452
1452 <command-line>: No such file or directory.
(gdb) bt
#0 0x00007ffff4415e47 in mod_post_auth (instance=0x9854e0, request=0x9d8410) at <command-line>:1452
#1 0x000000000041ecde in call_modsingle (sp=<optimized out>, request=0x9d8410, component=RLM_COMPONENT_POST_AUTH) at <command-line>:310
#2 modcall_recurse (request=request at entry=0x9d8410, component=component at entry=RLM_COMPONENT_POST_AUTH, depth=depth at entry=2, entry=entry at entry=0x7fffffffdc40) at <command-line>:576
#3 0x000000000041e2f2 in modcall_child (request=0x9d8410, component=RLM_COMPONENT_POST_AUTH, depth=2, entry=0x7fffffffdc28, c=0x9b7730, result=0x7fffffffd2bc) at <command-line>:413
#4 0x000000000041e4c4 in modcall_recurse (request=request at entry=0x9d8410, component=component at entry=RLM_COMPONENT_POST_AUTH, depth=depth at entry=1, entry=entry at entry=0x7fffffffdc28) at <command-line>:779
#5 0x000000000041e2f2 in modcall_child (request=0x9d8410, component=RLM_COMPONENT_POST_AUTH, depth=1, entry=0x7fffffffdc10, c=0x9b76b0, result=0x7fffffffd7bc) at <command-line>:413
#6 0x000000000041e4c4 in modcall_recurse (request=request at entry=0x9d8410, component=component at entry=RLM_COMPONENT_POST_AUTH, depth=depth at entry=0, entry=entry at entry=0x7fffffffdc10) at <command-line>:779
#7 0x000000000041f78d in modcall (component=component at entry=RLM_COMPONENT_POST_AUTH, c=c at entry=0x9b7900, request=request at entry=0x9d8410) at <command-line>:1035
#8 0x000000000041d249 in indexed_modcall (comp=comp at entry=RLM_COMPONENT_POST_AUTH, idx=idx at entry=0, request=request at entry=0x9d8410) at <command-line>:746
#9 0x000000000041dd5f in process_post_auth (postauth_type=postauth_type at entry=0, request=request at entry=0x9d8410) at <command-line>:1726
#10 0x000000000040ee84 in rad_postauth (request=request at entry=0x9d8410) at <command-line>:300
#11 0x000000000042b6cc in request_finish (action=<optimized out>, request=0x9d8410) at <command-line>:1137
#12 request_running (request=0x9d8410, action=<optimized out>) at <command-line>:1261
#13 0x000000000042c153 in request_virtual_server (request=0x9d8410, action=<optimized out>) at <command-line>:2160
#14 0x000000000042979e in request_queue_or_run (request=request at entry=0x9d8410, process=process at entry=0x42c0c0 <request_virtual_server>) at <command-line>:850
#15 0x0000000000429895 in request_proxy (request=request at entry=0x9d8410, retransmit=retransmit at entry=0) at <command-line>:2439
#16 0x000000000042bde0 in request_running (request=request at entry=0x9d8410, action=action at entry=1) at <command-line>:1243
#17 0x000000000042979e in request_queue_or_run (request=0x9d8410, process=process at entry=0x42b300 <request_running>) at <command-line>:850
#18 0x0000000000429c74 in request_receive (listener=listener at entry=0x9d6fe0, packet=0x9d8270, client=client at entry=0x8ff5a0, fun=fun at entry=0x40eed0 <rad_authenticate>) at <command-line>:1429
#19 0x000000000041900c in auth_socket_recv (listener=0x9d6fe0) at <command-line>:1522
#20 0x0000000000426fef in event_socket_handler (xel=<optimized out>, fd=<optimized out>, ctx=0x9d6fe0) at <command-line>:3514
#21 0x00007ffff79acecc in fr_event_loop (el=0x9c0da0) at <command-line>:416
#22 0x000000000042c7a1 in radius_event_process () at <command-line>:4231
#23 0x000000000040e515 in main (argc=<optimized out>, argv=<optimized out>) at <command-line>:478
(gdb)
Stefan
On 07.01.2014 12:52, Arran Cudbard-Bell wrote:
>
> On 7 Jan 2014, at 11:16, Arran Cudbard-Bell <a.cudbardb at freeradius.org> wrote:
>
>>
>> On 7 Jan 2014, at 07:51, Stefan Winter <stefan.winter at restena.lu> wrote:
>>
>>> Hi,
>>>
>>>>>> And the log files do contain the User-Password attribute.
>>>>>
>>>>> That shouldn't happen
>>>>
>>>> Fixed.
>>>
>>> Umm. In a way, yes. With current SVN (v3.0.x from a few minutes ago),
>>> the logs don't contain the User-Password.
>>>
>>> Unfortunately, shortly after detail is done (it logs the packet,
>>> omits the User-Password), the server crashes with a SEGV.
>>>
>>> Here's the -X log of the moment:
>>>
>>> (0) auth_log_silent : /var/log/radius/radacct/%Y%m%d/%{RESTENA-Service-Type}-service/auth-detail expands to /var/log/radius/radacct/20140107/Staff-IMAP-service/auth-detail
>>> (0) auth_log_silent : expand: "%t" -> 'Tue Jan 7 08:43:27 2014'
>>> (0) [auth_log_silent] = ok
>>> (0) ? if ( "%{RESTENA-Service-Type}" == "Staff-IMAP" && "%{strlen:%{User-Password}}" == "96" )
>>> (0) expand: "Staff-IMAP" -> 'Staff-IMAP'
>>> (0) expand: "%{RESTENA-Service-Type}" -> 'Staff-IMAP'
>>> (0) expand: "96" -> '96'
>>> (0) expand: "%{strlen:%{User-Password}}" -> '96'
>>> (0) ? if ( "%{RESTENA-Service-Type}" == "Staff-IMAP" && "%{strlen:%{User-Password}}" == "96" ) -> TRUE
>>> (0) if ( "%{RESTENA-Service-Type}" == "Staff-IMAP" && "%{strlen:%{User-Password}}" == "96" ) {
>>> Segmentation fault
>>>
>>> My config for this states:
>>>
>>> auth_log_silent
>>> if ( "%{RESTENA-Service-Type}" == "Staff-IMAP" && "%{strlen:%{User-Password}}" == "96" ) {
>>> sql-webmailsso
>>> }
>>>
>>> So it crashed before invoking an sql instance? The same worked on 3.0.0.
>>
>> Yes that doesn't exactly mean much it being C.
>>
>> I can't reproduce it by calling strlen, could you maybe provide a backtrace?
>>
>> (1) # Executing section authorize from file /usr/local/freeradius/etc/raddb/sites-enabled/default
>> (1) authorize {
>> (1) detail : expand: "/usr/local/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" -> '/usr/local/freeradius/var/log/radius/radacct/127.0.0.1/detail-20140107'
>> (1) detail : /usr/local/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /usr/local/freeradius/var/log/radius/radacct/127.0.0.1/detail-20140107
>> (1) detail : expand: "%t" -> 'Tue Jan 7 11:14:32 2014'
>> (1) [detail] = ok
>> (1) update control {
>> (1) expand: "%{strlen:%{User-Password}}" -> '3'
>> (1) Tmp-Integer-0 := 3
>> (1) } # update control = noop
>> (1) ? if ("%{strlen:%{User-Password}}" == "3")
>> (1) expand: "3" -> '3'
>> (1) expand: "%{strlen:%{User-Password}}" -> '3'
>> (1) ? if ("%{strlen:%{User-Password}}" == "3") -> TRUE
>> (1) if ("%{strlen:%{User-Password}}" == "3") {
>> (1) [reject] = reject
>> (1) } # if ("%{strlen:%{User-Password}}" == "3") = reject
>> (1) } # authorize = reject
>> (1) Using Post-Auth-Type Reject
>
> (1) # Executing section authorize from file /usr/local/freeradius/etc/raddb/sites-enabled/default
> (1) authorize {
> (1) detail : expand: "/usr/local/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" -> '/usr/local/freeradius/var/log/radius/radacct/127.0.0.1/detail-20140107'
> (1) detail : /usr/local/freeradius/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /usr/local/freeradius/var/log/radius/radacct/127.0.0.1/detail-20140107
> (1) detail : expand: "%t" -> 'Tue Jan 7 11:51:32 2014'
> (1) [detail] = ok
> (1) update control {
> (1) expand: "%{strlen:%{User-Password}}" -> '3'
> (1) Tmp-Integer-0 := 3
> (1) } # update control = noop
> (1) ? if ("%{strlen:%{User-Password}}" == "3")
> (1) expand: "3" -> '3'
> (1) expand: "%{strlen:%{User-Password}}" -> '3'
> (1) ? if ("%{strlen:%{User-Password}}" == "3") -> TRUE
> (1) if ("%{strlen:%{User-Password}}" == "3") {
> (1) sql : expand: "%{User-Name}" -> 'foo'
> (1) sql : SQL-User-Name set to 'foo'
> rlm_sql (sql): Reserved connection (4)
> (1) sql : expand: "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id" -> 'SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'foo' ORDER BY id'
> rlm_sql (sql): Executing query: 'SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'foo' ORDER BY id'
> (1) sql : expand: "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" -> 'SELECT groupname FROM radusergroup WHERE username = 'foo' ORDER BY priority'
> rlm_sql (sql): Executing query: 'SELECT groupname FROM radusergroup WHERE username = 'foo' ORDER BY priority'
> rlm_sql (sql): Released connection (4)
> rlm_sql (sql): Closing connection (1): Too many free connections (4 > 3)
> rlm_sql_sqlite: Socket destructor called, closing socket
> (1) [sql] = notfound
>
> Still can't reproduce it...
>
> Arran Cudbard-Bell <a.cudbardb at freeradius.org>
> FreeRADIUS Development Team
>
> FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
>
>
>
> -
> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
>
--
Stefan WINTER
Ingenieur de Recherche
Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche
6, rue Richard Coudenhove-Kalergi
L-1359 Luxembourg
Tel: +352 424409 1
Fax: +352 422473
PGP key updated to 4096 Bit RSA - I will encrypt all mails if the recipient's key is known to me
http://pgp.mit.edu:11371/pks/lookup?op=get&search=0xC0DE6A358A39DC66
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 0x8A39DC66.asc
Type: application/pgp-keys
Size: 3243 bytes
Desc: not available
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20140108/05197da0/attachment.key>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 901 bytes
Desc: OpenPGP digital signature
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20140108/05197da0/attachment.pgp>
More information about the Freeradius-Users
mailing list