How can I catch the bug?
work vlpl
thework.vlpl at gmail.com
Mon Jul 23 20:42:29 CEST 2018
Hello,
I am watching a bug, that is repeated periodically, and I can not
easily reproduce it.
Usually the request processed without any errors, but seldom one of
requests may crash the server. Can someone give me hint how I can
catch and reproduce it?.
There is the part of log that show how bugs happens, sorry I have to
redact some information from it.
```
(34) Received Access-Request Id 119 from REDACTED.IP.ADDRESS.0:53127
to REDACTED.RADIUS.IP.ADDRESS length 438
(34) Framed-MTU = 1480
(34) NAS-IP-Address = REDATED-NAS-IP
(34) NAS-Identifier = "REDACTED-THE-NAS-ID"
(34) User-Name = "REDACTED-THE-USER-NAME"
(34) Service-Type = Framed-User
(34) Framed-Protocol = PPP
(34) NAS-Port = 6
(34) NAS-Port-Type = Ethernet
(34) NAS-Port-Id = "6"
(34) Called-Station-Id = "REDACTED-CALLED-STATION-ID"
(34) Calling-Station-Id = "REDACTED-CALLING-STATION-ID"
(34) Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex"
(34) Tunnel-Type:0 = VLAN
(34) Tunnel-Medium-Type:0 = IEEE-802
(34) Tunnel-Private-Group-Id:0 = "1050"
(34) State = 0x333753657373696f6e49443d4844514e4341435330332f3332303738393230342f3336303634383b
(34) EAP-Message = 0x02fa00060319
(34) Message-Authenticator = 0xa3358ee8a08bde95cc268cd2ae49cef4
(34) MS-RAS-Vendor = 11
(34) HP-Capability-Advert = 0x011a0000000b28
(34) HP-Capability-Advert = 0x011a0000000b2e
(34) HP-Capability-Advert = 0x011a0000000b30
(34) HP-Capability-Advert = 0x011a0000000b3d
(34) HP-Capability-Advert = 0x011a0000000b18
(34) HP-Capability-Advert = 0x011a0000000b19
(34) HP-Capability-Advert = 0x0138
(34) HP-Capability-Advert = 0x013a
(34) HP-Capability-Advert = 0x0140
(34) HP-Capability-Advert = 0x0141
(34) HP-Capability-Advert = 0x0151
(34) Restoring &session-state
(34) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/virtualsite
(34) authorize {
(34) [preprocess] = ok
(34) auth_log: EXPAND
/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d:%H
(34) auth_log: -->
/var/log/radius/radacct/REDACTED.IP.ADDRESS.0/auth-detail-20180721:09
(34) auth_log: /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d:%H
expands to /var/log/radius/radacct/REDACTED.IP.ADDRESS.0/auth-detail-20180721:09
(34) auth_log: EXPAND %t
(34) auth_log: --> Sat Jul 21 09:19:06 2018
(34) [auth_log] = ok
(34) update request {
(34) Supplicant-Radius-Ip := REDACTED.IP.ADDRESS.0
(34) Supplicant-Radius-Port := REDACTED-PORT
(34) Selected-EAP-Module := eap
(34) } # update request = noop
(34) [chap] = noop
(34) [mschap] = noop
*** authorize ***
***************
authorize - 'reply:Supplicant-Use-Remote' := 'yes'
authorize - 'reply:Supplicant-Proxy-Id' := 'REDACTED_PROXY_ID'
authorize - 'reply:Supplicant-User-Name' := 'REDACTED-THE-USER-NAME'
(34) [python_module_auth] = updated
(34) if (updated){
(34) if (updated) -> TRUE
(34) if (updated) {
(34) update control {
(34) No attributes updated
(34) } # update control = noop
(34) if (&reply:Supplicant-Use-Remote == 'yes') {
(34) if (&reply:Supplicant-Use-Remote == 'yes') -> TRUE
(34) if (&reply:Supplicant-Use-Remote == 'yes') {
(34) update control {
(34) Proxy-To-Realm := &reply:Supplicant-Proxy-Id ->
'REDACTED_PROXY_ID'
(34) Cleartext-Password !* ANY
(34) } # update control = noop
(34) } # if (&reply:Supplicant-Use-Remote == 'yes') = noop
(34) if (&reply:Supplicant-Use-Mac-Auth == 'yes') {
(34) ERROR: Failed retrieving values required to evaluate condition
(34) policy save_reply_to_session_state {
(34) update session-state {
ASSERT FAILED src/main/map.c[1112]: parent
CAUGHT SIGNAL: Aborted
Backtrace of last 24 frames:
/usr/local/lib/libfreeradius-radius.so(fr_fault+0x115)[0x7f9a4d7e4566]
/usr/local/lib/libfreeradius-server.so(rad_assert_fail+0x46)[0x7f9a4da43ff2]
/usr/local/lib/libfreeradius-server.so(map_to_request+0x5cb)[0x7f9a4da3d174]
/usr/local/sbin/radiusd[0x429867]
/usr/local/sbin/radiusd[0x42922a]
/usr/local/sbin/radiusd[0x42a14a]
/usr/local/sbin/radiusd[0x42922a]
/usr/local/sbin/radiusd[0x42a14a]
/usr/local/sbin/radiusd[0x42922a]
/usr/local/sbin/radiusd[0x42a14a]
/usr/local/sbin/radiusd(modcall+0xa2)[0x42ae8f]
/usr/local/sbin/radiusd(indexed_modcall+0x363)[0x42669f]
/usr/local/sbin/radiusd(process_authorize+0x22)[0x42893f]
/usr/local/sbin/radiusd(rad_authenticate+0x212)[0x410110]
/usr/local/sbin/radiusd[0x43de39]
/usr/local/sbin/radiusd[0x43ca8a]
/usr/local/sbin/radiusd(request_receive+0x7c2)[0x43e6d5]
/usr/local/sbin/radiusd[0x41882e]
/usr/local/sbin/radiusd[0x4455ce]
/usr/local/lib/libfreeradius-radius.so(fr_event_loop+0x5a8)[0x7f9a4d80bfe8]
/usr/local/sbin/radiusd(radius_event_process+0x26)[0x4473cd]
/usr/local/sbin/radiusd(main+0xc77)[0x431417]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7f9a4beb8445]
/usr/local/sbin/radiusd[0x40eeb9]
No panic action set
Aborted
```
And there is the policy `save_reply_to_session_state`
```
save_reply_to_session_state {
update session-state {
Supplicant-User-Name := User-Name
}
}
```
The attributes that starts with 'Supplicant', are custom attributes,
that I defined in dictionary.
`*** authorize ***` it is debug output from `python_module_auth`, just
to make it easier to find the right place in log.
--
Vladimir
More information about the Freeradius-Users
mailing list