Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[defect]: rlm_python: Fatal Python error: drop_gil: drop_gil: GIL is not locked #5111

Open
sirmax123 opened this issue Jul 18, 2023 · 6 comments
Open

[defect]: rlm_python: Fatal Python error: drop_gil: drop_gil: GIL is not locked #5111

sirmax123 opened this issue Jul 18, 2023 · 6 comments
Assignees
@jpereira
Labels
defect category: a defect or misbehaviour v3.2.x meta: relates to the v3.2.x branch
Milestone
4.0.0 release

Comments

@sirmax123
Copy link

What type of defect/bug is this?

Crash or memory corruption (segv, abort, etc...)

How can the issue be reproduced?

I'd like to have 2 instances of Python code (using rlm_python) in order to split my code into 2 scripts

e.g smx like this
ipaddr.py:

...
  for AVPair in p['request']:
    if (AVPair[0] == "User-Name"):
      if (is_ip_addr(AVPair[1]):
      ...
        config = ( ('Cleartext-Password', 'hello'), ('Auth-Type', 'PYTHON-IPADDR') )
        return radiusd.RLM_MODULE_OK, reply, config
     else:
       return radiusd.RLM_MODULE_NOOP

service.py:
and the second script returns something like

        config = ( ('Cleartext-Password', 'hello'), ('Auth-Type', 'PYTHON-NOT-IPADDR') )
        return radiusd.RLM_MODULE_OK, reply, config

The idia is to handle in different scripts for different kinds of usernames,
I need it for Cisco ISG, where I have users with User-Name = IP ADDRESS and Service where User-Name is name of service

So I'm trying to do it in the following way:

    authorize {
        python3_ipaddress_username # <--- name of module instance  where module=ipaddr.py defined
        python3_service_username # <--- name of module instance  where module=service.py defined
  }

    authenticate {
        Auth-Type PYTHON-IPADDR {
            python3_ipaddress_username
        }

        Auth-Type PYTHON-NOT-IPADDR {
            python3_service_username
        }
}

There is no real code in scripts, just 2 copies of example.py from distribution.

And I got:

Fatal Python error: drop_gil: drop_gil: GIL is not locked

One script works OK, so as workaround I can put all code into one file, it possible.

Log output from the FreeRADIUS daemon

root@radius:/usr/local/freeradius/sbin# ./radiusd -XXXX
Tue Jul 18 14:30:26 2023 : Debug: Server was built with:
Tue Jul 18 14:30:26 2023 : Debug:   accounting                : yes
Tue Jul 18 14:30:26 2023 : Debug:   authentication            : yes
Tue Jul 18 14:30:26 2023 : Debug:   ascend-binary-attributes  : yes
Tue Jul 18 14:30:26 2023 : Debug:   coa                       : yes
Tue Jul 18 14:30:26 2023 : Debug:   recv-coa-from-home-server : no
Tue Jul 18 14:30:26 2023 : Debug:   control-socket            : yes
Tue Jul 18 14:30:26 2023 : Debug:   detail                    : yes
Tue Jul 18 14:30:26 2023 : Debug:   dhcp                      : yes
Tue Jul 18 14:30:26 2023 : Debug:   dynamic-clients           : yes
Tue Jul 18 14:30:26 2023 : Debug:   osfc2                     : no
Tue Jul 18 14:30:26 2023 : Debug:   proxy                     : yes
Tue Jul 18 14:30:26 2023 : Debug:   regex-pcre                : no
Tue Jul 18 14:30:26 2023 : Debug:   regex-posix               : yes
Tue Jul 18 14:30:26 2023 : Debug:   regex-posix-extended      : yes
Tue Jul 18 14:30:26 2023 : Debug:   session-management        : yes
Tue Jul 18 14:30:26 2023 : Debug:   stats                     : yes
Tue Jul 18 14:30:26 2023 : Debug:   systemd                   : no
Tue Jul 18 14:30:26 2023 : Debug:   tcp                       : yes
Tue Jul 18 14:30:26 2023 : Debug:   threads                   : yes
Tue Jul 18 14:30:26 2023 : Debug:   tls                       : yes
Tue Jul 18 14:30:26 2023 : Debug:   unlang                    : yes
Tue Jul 18 14:30:26 2023 : Debug:   vmps                      : yes
Tue Jul 18 14:30:26 2023 : Debug:   developer                 : yes
Tue Jul 18 14:30:26 2023 : Debug: Server core libs:
Tue Jul 18 14:30:26 2023 : Debug:   freeradius-server         : 3.2.4
Tue Jul 18 14:30:26 2023 : Debug:   talloc                    : 2.3.*
Tue Jul 18 14:30:26 2023 : Debug:   ssl                       : 3.0.0b dev
Tue Jul 18 14:30:26 2023 : Debug: Endianness:
Tue Jul 18 14:30:26 2023 : Debug:   little
Tue Jul 18 14:30:26 2023 : Debug: Compilation flags:
Tue Jul 18 14:30:26 2023 : Debug:   cppflags :
Tue Jul 18 14:30:26 2023 : Debug:   cflags   : -I. -Isrc -include src/freeradius-devel/autoconf.h -include src/freeradius-devel/build.h -include src/freeradius-devel/features.h -include src/freeradius-devel/radpaths.h -fno-strict-aliasing -Wno-date-time -g3 -Wall -std=c99 -D_GNU_SOURCE -D_REENTRANT -D_POSIX_PTHREAD_SEMANTICS -DOPENSSL_NO_KRB5 -Wshadow -Wpointer-arith -Wcast-qual -Wcast-align -Wwrite-strings -Wstrict-prototypes -Wmissing-prototypes -Wmissing-declarations -Wnested-externs -W -Wredundant-decls -Wundef -Wformat-y2k -Wno-format-extra-args -Wno-format-zero-length -Wno-cast-align -Wformat-nonliteral -Wformat-security -Wformat=2 -DWITH_VERIFY_PTR=1 -DIS_MODULE=1
Tue Jul 18 14:30:26 2023 : Debug:   ldflags  :
Tue Jul 18 14:30:26 2023 : Debug:   libs     : -lcrypto -lssl -ltalloc -latomic -lnsl -lresolv -ldl -lpthread
Tue Jul 18 14:30:26 2023 : Debug:
Tue Jul 18 14:30:26 2023 : Info: FreeRADIUS Version 3.2.4
Tue Jul 18 14:30:26 2023 : Info: Copyright (C) 1999-2022 The FreeRADIUS server project and contributors
Tue Jul 18 14:30:26 2023 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Tue Jul 18 14:30:26 2023 : Info: PARTICULAR PURPOSE
Tue Jul 18 14:30:26 2023 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Tue Jul 18 14:30:26 2023 : Info: GNU General Public License
Tue Jul 18 14:30:26 2023 : Info: For more information about these matters, see the file named COPYRIGHT
Tue Jul 18 14:30:26 2023 : Info: Starting - reading configuration files ...
Tue Jul 18 14:30:26 2023 : Debug: including dictionary file /usr/local/freeradius/share/freeradius/dictionary
Tue Jul 18 14:30:26 2023 : Debug: including dictionary file /usr/local/freeradius/share/freeradius/dictionary.dhcp
Tue Jul 18 14:30:26 2023 : Debug: including dictionary file /usr/local/freeradius/share/freeradius/dictionary.vqp
Tue Jul 18 14:30:26 2023 : Debug: including dictionary file /usr/local/freeradius/etc/raddb/dictionary
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/radiusd.conf
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/clients.conf
Tue Jul 18 14:30:26 2023 : Debug: including files in directory /usr/local/freeradius/etc/raddb/mods-enabled/
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/preprocess
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/digest
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/chap
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/python3_ipaddress_username
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/echo
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/python3_service_username
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/pap
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/files
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/expr
Tue Jul 18 14:30:26 2023 : Debug: including files in directory /usr/local/freeradius/etc/raddb/policy.d/
Tue Jul 18 14:30:26 2023 : Debug: including files in directory /usr/local/freeradius/etc/raddb/sites-enabled/
Tue Jul 18 14:30:26 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/sites-enabled/default
Tue Jul 18 14:30:26 2023 : Debug: main {
Tue Jul 18 14:30:26 2023 : Debug:  security {
Tue Jul 18 14:30:26 2023 : Debug:  	user = "freerad"
Tue Jul 18 14:30:26 2023 : Debug:  	group = "freerad"
Tue Jul 18 14:30:26 2023 : Debug:  	allow_core_dumps = yes
Tue Jul 18 14:30:26 2023 : Debug:  }
Tue Jul 18 14:30:26 2023 : Debug: 	name = "freeradius"
Tue Jul 18 14:30:26 2023 : Debug: 	prefix = "/usr/local/freeradius"
Tue Jul 18 14:30:26 2023 : Debug: 	localstatedir = "/usr/local/freeradius/var"
Tue Jul 18 14:30:26 2023 : Debug: 	logdir = "/usr/local/freeradius/var/log/radius"
Tue Jul 18 14:30:26 2023 : Debug: 	run_dir = "/usr/local/freeradius/var/run/freeradius"
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[7]: The item 'raddbdir' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[8]: The item 'radacctdir' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[20]: The item 'libdir' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[21]: The item 'pidfile' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[23]: The item 'correct_escapes' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[25]: The item 'max_request_time' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[26]: The item 'cleanup_delay' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[27]: The item 'max_requests' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[28]: The item 'hostname_lookups' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[43]: The item 'checkrad' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[56]: The item 'proxy_requests' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Debug: }
Tue Jul 18 14:30:26 2023 : Info: Core dumps are enabled
Tue Jul 18 14:30:26 2023 : Debug: main {
Tue Jul 18 14:30:26 2023 : Debug: 	name = "freeradius"
Tue Jul 18 14:30:26 2023 : Debug: 	prefix = "/usr/local/freeradius"
Tue Jul 18 14:30:26 2023 : Debug: 	localstatedir = "/usr/local/freeradius/var"
Tue Jul 18 14:30:26 2023 : Debug: 	sbindir = "/usr/local/freeradius/sbin"
Tue Jul 18 14:30:26 2023 : Debug: 	logdir = "/usr/local/freeradius/var/log/radius"
Tue Jul 18 14:30:26 2023 : Debug: 	run_dir = "/usr/local/freeradius/var/run/freeradius"
Tue Jul 18 14:30:26 2023 : Debug: 	libdir = "/usr/local/freeradius/lib"
Tue Jul 18 14:30:26 2023 : Debug: 	radacctdir = "/usr/local/freeradius/var/log/radius/radacct"
Tue Jul 18 14:30:26 2023 : Debug: 	hostname_lookups = no
Tue Jul 18 14:30:26 2023 : Debug: 	max_request_time = 30
Tue Jul 18 14:30:26 2023 : Debug: 	cleanup_delay = 5
Tue Jul 18 14:30:26 2023 : Debug: 	max_requests = 16384
Tue Jul 18 14:30:26 2023 : Debug: 	postauth_client_lost = no
Tue Jul 18 14:30:26 2023 : Debug: 	pidfile = "/usr/local/freeradius/var/run/freeradius/freeradius.pid"
Tue Jul 18 14:30:26 2023 : Debug: 	checkrad = "/usr/local/freeradius/sbin/checkrad"
Tue Jul 18 14:30:26 2023 : Debug: 	debug_level = 0
Tue Jul 18 14:30:26 2023 : Debug: 	proxy_requests = no
Tue Jul 18 14:30:26 2023 : Debug:  log {
Tue Jul 18 14:30:26 2023 : Debug:  	stripped_names = no
Tue Jul 18 14:30:26 2023 : Debug:  	auth = yes
Tue Jul 18 14:30:26 2023 : Debug:  	auth_badpass = yes
Tue Jul 18 14:30:26 2023 : Debug:  	auth_goodpass = yes
Tue Jul 18 14:30:26 2023 : Debug:  	colourise = yes
Tue Jul 18 14:30:26 2023 : Debug:  	msg_denied = "You are already logged in - access denied"
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[31]: The item 'destination' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[33]: The item 'file' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Debug:  }
Tue Jul 18 14:30:26 2023 : Debug:  resources {
Tue Jul 18 14:30:26 2023 : Debug:  }
Tue Jul 18 14:30:26 2023 : Debug:  security {
Tue Jul 18 14:30:26 2023 : Debug:  	max_attributes = 0
Tue Jul 18 14:30:26 2023 : Debug:  	reject_delay = 0.000000
Tue Jul 18 14:30:26 2023 : Debug:  	status_server = no
Tue Jul 18 14:30:26 2023 : Debug:  	allow_vulnerable_openssl = "no"
Tue Jul 18 14:30:26 2023 : Debug:  }
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[7]: The item 'raddbdir' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[23]: The item 'correct_escapes' is defined, but is unused by the configuration
Tue Jul 18 14:30:26 2023 : Debug: }
Tue Jul 18 14:30:26 2023 : Debug: radiusd: #### Loading Realms and Home Servers ####
Tue Jul 18 14:30:26 2023 : Debug: radiusd: #### Loading Clients ####
Tue Jul 18 14:30:26 2023 : Debug:  client localhost {
Tue Jul 18 14:30:26 2023 : Debug:  	ipaddr = 127.0.0.1
Tue Jul 18 14:30:26 2023 : Debug:  	require_message_authenticator = no
Tue Jul 18 14:30:26 2023 : Debug:  	secret = "testing123"
Tue Jul 18 14:30:26 2023 : Debug:  	nas_type = "other"
Tue Jul 18 14:30:26 2023 : Debug:  	proto = "*"
Tue Jul 18 14:30:26 2023 : Debug:   limit {
Tue Jul 18 14:30:26 2023 : Debug:   	max_connections = 16
Tue Jul 18 14:30:26 2023 : Debug:   	lifetime = 0
Tue Jul 18 14:30:26 2023 : Debug:   	idle_timeout = 30
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:  }
Tue Jul 18 14:30:26 2023 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32
Tue Jul 18 14:30:26 2023 : Debug:  client localhost_ipv6 {
Tue Jul 18 14:30:26 2023 : Debug:  	ipv6addr = ::1
Tue Jul 18 14:30:26 2023 : Debug:  	require_message_authenticator = no
Tue Jul 18 14:30:26 2023 : Debug:  	secret = "testing123"
Tue Jul 18 14:30:26 2023 : Debug:   limit {
Tue Jul 18 14:30:26 2023 : Debug:   	max_connections = 16
Tue Jul 18 14:30:26 2023 : Debug:   	lifetime = 0
Tue Jul 18 14:30:26 2023 : Debug:   	idle_timeout = 30
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:  }
Tue Jul 18 14:30:26 2023 : Debug: Adding client ::1/128 (::1) to prefix tree 128
Tue Jul 18 14:30:26 2023 : Info: Debugger not attached
Tue Jul 18 14:30:26 2023 : Debug:  # Creating Auth-Type = PYTHON_IPADRESS
Tue Jul 18 14:30:26 2023 : Debug:  # Creating Auth-Type = PYTHON_SERVICE
Tue Jul 18 14:30:26 2023 : Debug: radiusd: #### Instantiating modules ####
Tue Jul 18 14:30:26 2023 : Debug:  modules {
Tue Jul 18 14:30:26 2023 : Debug: Loading rlm_preprocess with path: /usr/local/freeradius/lib/rlm_preprocess.so
Tue Jul 18 14:30:26 2023 : Debug: Loaded rlm_preprocess, checking if it's valid
Tue Jul 18 14:30:26 2023 : Debug:   # Loaded module rlm_preprocess
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "preprocess" from file /usr/local/freeradius/etc/raddb/mods-enabled/preprocess
Tue Jul 18 14:30:26 2023 : Debug:   preprocess {
Tue Jul 18 14:30:26 2023 : Debug:   	huntgroups = "/usr/local/freeradius/etc/raddb/mods-config/preprocess/huntgroups"
Tue Jul 18 14:30:26 2023 : Debug:   	hints = "/usr/local/freeradius/etc/raddb/mods-config/preprocess/hints"
Tue Jul 18 14:30:26 2023 : Debug:   	with_ascend_hack = no
Tue Jul 18 14:30:26 2023 : Debug:   	ascend_channels_per_line = 23
Tue Jul 18 14:30:26 2023 : Debug:   	with_ntdomain_hack = no
Tue Jul 18 14:30:26 2023 : Debug:   	with_specialix_jetstream_hack = no
Tue Jul 18 14:30:26 2023 : Debug:   	with_cisco_vsa_hack = no
Tue Jul 18 14:30:26 2023 : Debug:   	with_alvarion_vsa_hack = no
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug: Loading rlm_digest with path: /usr/local/freeradius/lib/rlm_digest.so
Tue Jul 18 14:30:26 2023 : Debug: Loaded rlm_digest, checking if it's valid
Tue Jul 18 14:30:26 2023 : Debug:   # Loaded module rlm_digest
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "digest" from file /usr/local/freeradius/etc/raddb/mods-enabled/digest
Tue Jul 18 14:30:26 2023 : Debug: Loading rlm_chap with path: /usr/local/freeradius/lib/rlm_chap.so
Tue Jul 18 14:30:26 2023 : Debug: Loaded rlm_chap, checking if it's valid
Tue Jul 18 14:30:26 2023 : Debug:   # Loaded module rlm_chap
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "chap" from file /usr/local/freeradius/etc/raddb/mods-enabled/chap
Tue Jul 18 14:30:26 2023 : Debug: Loading rlm_python3 with path: /usr/local/freeradius/lib/rlm_python3.so
Tue Jul 18 14:30:26 2023 : Debug: Loaded rlm_python3, checking if it's valid
Tue Jul 18 14:30:26 2023 : Debug:   # Loaded module rlm_python3
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "python3_ipaddress_username" from file /usr/local/freeradius/etc/raddb/mods-enabled/python3_ipaddress_username
Tue Jul 18 14:30:26 2023 : Debug:   python3 python3_ipaddress_username {
Tue Jul 18 14:30:26 2023 : Debug:   	mod_instantiate = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_instantiate = "instantiate"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_authorize = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_authorize = "authorize"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_authenticate = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_authenticate = "authenticate"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_preacct = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_preacct = "preacct"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_accounting = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_accounting = "accounting"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_checksimul = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_checksimul = "checksimul"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_pre_proxy = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_pre_proxy = "pre_proxy"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_post_proxy = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_post_proxy = "post_proxy"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_post_auth = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_post_auth = "post_auth"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_recv_coa = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_recv_coa = "recv_coa"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_send_coa = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_send_coa = "send_coa"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_detach = "ipaddress_username"
Tue Jul 18 14:30:26 2023 : Debug:   	func_detach = "detach"
Tue Jul 18 14:30:26 2023 : Debug:   	python_path = ":/usr/local/freeradius/etc/raddb/mods-config/python3"
Tue Jul 18 14:30:26 2023 : Debug:   	cext_compat = yes
Tue Jul 18 14:30:26 2023 : Debug:   	pass_all_vps = no
Tue Jul 18 14:30:26 2023 : Debug:   	pass_all_vps_dict = yes
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug: Loading rlm_exec with path: /usr/local/freeradius/lib/rlm_exec.so
Tue Jul 18 14:30:26 2023 : Debug: Loaded rlm_exec, checking if it's valid
Tue Jul 18 14:30:26 2023 : Debug:   # Loaded module rlm_exec
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "echo" from file /usr/local/freeradius/etc/raddb/mods-enabled/echo
Tue Jul 18 14:30:26 2023 : Debug:   exec echo {
Tue Jul 18 14:30:26 2023 : Debug:   	wait = yes
Tue Jul 18 14:30:26 2023 : Debug:   	program = "/bin/echo %{User-Name}"
Tue Jul 18 14:30:26 2023 : Debug:   	input_pairs = "request"
Tue Jul 18 14:30:26 2023 : Debug:   	output_pairs = "reply"
Tue Jul 18 14:30:26 2023 : Debug:   	shell_escape = yes
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "python3_service_username" from file /usr/local/freeradius/etc/raddb/mods-enabled/python3_service_username
Tue Jul 18 14:30:26 2023 : Debug:   python3 python3_service_username {
Tue Jul 18 14:30:26 2023 : Debug:   	mod_instantiate = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_instantiate = "instantiate"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_authorize = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_authorize = "authorize"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_authenticate = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_authenticate = "authenticate"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_preacct = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_preacct = "preacct"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_accounting = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_accounting = "accounting"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_checksimul = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_checksimul = "checksimul"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_pre_proxy = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_pre_proxy = "pre_proxy"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_post_proxy = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_post_proxy = "post_proxy"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_post_auth = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_post_auth = "post_auth"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_recv_coa = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_recv_coa = "recv_coa"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_send_coa = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_send_coa = "send_coa"
Tue Jul 18 14:30:26 2023 : Debug:   	mod_detach = "example"
Tue Jul 18 14:30:26 2023 : Debug:   	func_detach = "detach"
Tue Jul 18 14:30:26 2023 : Debug:   	python_path = ":/usr/local/freeradius/etc/raddb/mods-config/python3"
Tue Jul 18 14:30:26 2023 : Debug:   	cext_compat = yes
Tue Jul 18 14:30:26 2023 : Debug:   	pass_all_vps = no
Tue Jul 18 14:30:26 2023 : Debug:   	pass_all_vps_dict = yes
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug: Loading rlm_pap with path: /usr/local/freeradius/lib/rlm_pap.so
Tue Jul 18 14:30:26 2023 : Debug: Loaded rlm_pap, checking if it's valid
Tue Jul 18 14:30:26 2023 : Debug:   # Loaded module rlm_pap
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "pap" from file /usr/local/freeradius/etc/raddb/mods-enabled/pap
Tue Jul 18 14:30:26 2023 : Debug:   pap {
Tue Jul 18 14:30:26 2023 : Debug:   	normalise = yes
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "module_pap_1" from file /usr/local/freeradius/etc/raddb/mods-enabled/pap
Tue Jul 18 14:30:26 2023 : Debug:   pap module_pap_1 {
Tue Jul 18 14:30:26 2023 : Debug:   	normalise = yes
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "module_pap_2" from file /usr/local/freeradius/etc/raddb/mods-enabled/pap
Tue Jul 18 14:30:26 2023 : Debug:   pap module_pap_2 {
Tue Jul 18 14:30:26 2023 : Debug:   	normalise = yes
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug: Loading rlm_files with path: /usr/local/freeradius/lib/rlm_files.so
Tue Jul 18 14:30:26 2023 : Debug: Loaded rlm_files, checking if it's valid
Tue Jul 18 14:30:26 2023 : Debug:   # Loaded module rlm_files
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "module_files_1" from file /usr/local/freeradius/etc/raddb/mods-enabled/files
Tue Jul 18 14:30:26 2023 : Debug:   files module_files_1 {
Tue Jul 18 14:30:26 2023 : Debug:   	filename = "/usr/local/freeradius/etc/raddb/mods-config/module_files_1/authorize"
Tue Jul 18 14:30:26 2023 : Debug:   	usersfile = "/usr/local/freeradius/etc/raddb/mods-config/module_files_1/authorize"
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "module_files_2" from file /usr/local/freeradius/etc/raddb/mods-enabled/files
Tue Jul 18 14:30:26 2023 : Debug:   files module_files_2 {
Tue Jul 18 14:30:26 2023 : Debug:   	filename = "/usr/local/freeradius/etc/raddb/mods-config/module_files_2/authorize"
Tue Jul 18 14:30:26 2023 : Debug:   	usersfile = "/usr/local/freeradius/etc/raddb/mods-config/module_files_2/authorize"
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug: Loading rlm_realm with path: /usr/local/freeradius/lib/rlm_realm.so
Tue Jul 18 14:30:26 2023 : Debug: Loaded rlm_realm, checking if it's valid
Tue Jul 18 14:30:26 2023 : Debug:   # Loaded module rlm_realm
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "IPASS" from file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:30:26 2023 : Debug:   realm IPASS {
Tue Jul 18 14:30:26 2023 : Debug:   	format = "prefix"
Tue Jul 18 14:30:26 2023 : Debug:   	delimiter = "/"
Tue Jul 18 14:30:26 2023 : Debug:   	ignore_default = no
Tue Jul 18 14:30:26 2023 : Debug:   	ignore_null = no
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "suffix" from file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:30:26 2023 : Debug:   realm suffix {
Tue Jul 18 14:30:26 2023 : Debug:   	format = "suffix"
Tue Jul 18 14:30:26 2023 : Debug:   	delimiter = "@"
Tue Jul 18 14:30:26 2023 : Debug:   	ignore_default = no
Tue Jul 18 14:30:26 2023 : Debug:   	ignore_null = no
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "bangpath" from file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:30:26 2023 : Debug:   realm bangpath {
Tue Jul 18 14:30:26 2023 : Debug:   	format = "prefix"
Tue Jul 18 14:30:26 2023 : Debug:   	delimiter = "!"
Tue Jul 18 14:30:26 2023 : Debug:   	ignore_default = no
Tue Jul 18 14:30:26 2023 : Debug:   	ignore_null = no
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "realmpercent" from file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:30:26 2023 : Debug:   realm realmpercent {
Tue Jul 18 14:30:26 2023 : Debug:   	format = "suffix"
Tue Jul 18 14:30:26 2023 : Debug:   	delimiter = "%"
Tue Jul 18 14:30:26 2023 : Debug:   	ignore_default = no
Tue Jul 18 14:30:26 2023 : Debug:   	ignore_null = no
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "ntdomain" from file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:30:26 2023 : Debug:   realm ntdomain {
Tue Jul 18 14:30:26 2023 : Debug:   	format = "prefix"
Tue Jul 18 14:30:26 2023 : Debug:   	delimiter = "\\"
Tue Jul 18 14:30:26 2023 : Debug:   	ignore_default = no
Tue Jul 18 14:30:26 2023 : Debug:   	ignore_null = no
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug: Loading rlm_expr with path: /usr/local/freeradius/lib/rlm_expr.so
Tue Jul 18 14:30:26 2023 : Debug: Loaded rlm_expr, checking if it's valid
Tue Jul 18 14:30:26 2023 : Debug:   # Loaded module rlm_expr
Tue Jul 18 14:30:26 2023 : Debug:   # Loading module "expr" from file /usr/local/freeradius/etc/raddb/mods-enabled/expr
Tue Jul 18 14:30:26 2023 : Debug:   expr {
Tue Jul 18 14:30:26 2023 : Debug:   	safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:   instantiate {
Tue Jul 18 14:30:26 2023 : Debug:   }
Tue Jul 18 14:30:26 2023 : Debug:   # Instantiating module "preprocess" from file /usr/local/freeradius/etc/raddb/mods-enabled/preprocess
Tue Jul 18 14:30:26 2023 : Debug: reading pairlist file /usr/local/freeradius/etc/raddb/mods-config/preprocess/huntgroups
Tue Jul 18 14:30:26 2023 : Debug: reading pairlist file /usr/local/freeradius/etc/raddb/mods-config/preprocess/hints
Tue Jul 18 14:30:26 2023 : Debug:   # Instantiating module "python3_ipaddress_username" from file /usr/local/freeradius/etc/raddb/mods-enabled/python3_ipaddress_username
Tue Jul 18 14:30:26 2023 : Info: Python version: 3.10.6 (main, May 29 2023, 11:10:38) [GCC 11.3.0]
*** instantiate ***
{'request': None, 'reply': None, 'config': None, 'session-state': None, 'proxy-request': None, 'proxy-reply': None}
<pymysql.connections.Connection object at 0x7f6af93cfc10>
[{'id': 12117, 'uid': 5872, 'ip': 3232269124, 'hostname': 'len10', 'network': 0, 'mac': '90:94:e4:ed:ad:f5', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': datetime.date(2030, 1, 1), 'seen': 0, 'comments': '', 'vid': 3299, 'nas': 123638406563423, 'option_82': 0, 'ports': '15', 'boot_file': '', 'changed': datetime.datetime(2023, 2, 4, 12, 21, 1)}, {'id': 11594, 'uid': 5543, 'ip': 3232268844, 'hostname': 'sp7ak51', 'network': 0, 'mac': 'e8:48:b8:99:87:eb', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': datetime.date(2030, 1, 1), 'seen': 0, 'comments': '', 'vid': 3051, 'nas': 123638407509972, 'option_82': 0, 'ports': '3', 'boot_file': '', 'changed': datetime.datetime(2022, 3, 1, 11, 40, 43)}, {'id': 10623, 'uid': 5107, 'ip': 3232271011, 'hostname': 'en2k30', 'network': 0, 'mac': '50:d4:f7:af:db:23', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 2002, 'nas': 123638407276559, 'option_82': 0, 'ports': '10', 'boot_file': '', 'changed': datetime.datetime(2020, 2, 4, 16, 32, 35)}, {'id': 9368, 'uid': 4569, 'ip': 3232269914, 'hostname': 'sasha7', 'network': 0, 'mac': 'e8:94:f6:8f:28:03', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3096, 'nas': 80796821719, 'option_82': 0, 'ports': '12', 'boot_file': '', 'changed': datetime.datetime(2017, 1, 26, 11, 22, 49)}, {'id': 4716, 'uid': 78, 'ip': 3232269515, 'hostname': 'milana', 'network': 0, 'mac': '00:1a:92:97:72:2f', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3063, 'nas': 80796805856, 'option_82': 0, 'ports': '1', 'boot_file': '', 'changed': datetime.datetime(2012, 4, 28, 16, 21, 20)}, {'id': 9793, 'uid': 1407, 'ip': 3232271064, 'hostname': 'doshenko', 'network': 0, 'mac': '3c:84:6a:00:d6:89', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3002, 'nas': 123638406465897, 'option_82': 0, 'ports': '11', 'boot_file': '', 'changed': datetime.datetime(2018, 3, 21, 14, 28, 21)}, {'id': 11222, 'uid': 3454, 'ip': 3232268895, 'hostname': 'len_1', 'network': 0, 'mac': 'a0:f3:c1:ee:7f:e9', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3253, 'nas': 190154839202432, 'option_82': 0, 'ports': '14', 'boot_file': '', 'changed': datetime.datetime(2021, 2, 23, 13, 14, 35)}, {'id': 4712, 'uid': 88, 'ip': 3232268412, 'hostname': 'aspera', 'network': 0, 'mac': '34:60:f9:6b:b5:ee', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3063, 'nas': 80796805856, 'option_82': 0, 'ports': '1', 'boot_file': '', 'changed': datetime.datetime(2012, 4, 28, 15, 47, 19)}, {'id': 11209, 'uid': 2211, 'ip': 3232270497, 'hostname': 'zlata', 'network': 0, 'mac': '64:70:02:be:c7:4f', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3074, 'nas': 123638407500547, 'option_82': 0, 'ports': '1', 'boot_file': '', 'changed': datetime.datetime(2021, 2, 17, 17, 31, 52)}, {'id': 7103, 'uid': 1238, 'ip': 3232270609, 'hostname': 'loki', 'network': 0, 'mac': 'f4:f2:6d:4c:2a:93', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3077, 'nas': 123638408947744, 'option_82': 0, 'ports': '18', 'boot_file': '', 'changed': datetime.datetime(2014, 1, 18, 15, 3)}]
****************
Tue Jul 18 14:30:26 2023 : Debug:   # Instantiating module "python3_service_username" from file /usr/local/freeradius/etc/raddb/mods-enabled/python3_service_username
Fatal Python error: drop_gil: drop_gil: GIL is not locked
Python runtime state: initialized

Current thread 0x00007f6af9fc6740 (most recent call first):
  <no Python frame>

Extension modules: radiusd, _cffi_backend (total: 2)
Aborted (core dumped)

Relevant log output from client utilities

rlm_python

Backtrace from LLDB or GDB

root@radius:/usr/local/freeradius/sbin# gdb --args ./radiusd -XXXX
GNU gdb (Ubuntu 12.1-0ubuntu1~22.04) 12.1
Copyright (C) 2022 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from ./radiusd...
(gdb) run
Starting program: /usr/local/freeradius/sbin/radiusd -XXXX
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Tue Jul 18 14:34:33 2023 : Debug: Server was built with:
Tue Jul 18 14:34:33 2023 : Debug:   accounting                : yes
Tue Jul 18 14:34:33 2023 : Debug:   authentication            : yes
Tue Jul 18 14:34:33 2023 : Debug:   ascend-binary-attributes  : yes
Tue Jul 18 14:34:33 2023 : Debug:   coa                       : yes
Tue Jul 18 14:34:33 2023 : Debug:   recv-coa-from-home-server : no
Tue Jul 18 14:34:33 2023 : Debug:   control-socket            : yes
Tue Jul 18 14:34:33 2023 : Debug:   detail                    : yes
Tue Jul 18 14:34:33 2023 : Debug:   dhcp                      : yes
Tue Jul 18 14:34:33 2023 : Debug:   dynamic-clients           : yes
Tue Jul 18 14:34:33 2023 : Debug:   osfc2                     : no
Tue Jul 18 14:34:33 2023 : Debug:   proxy                     : yes
Tue Jul 18 14:34:33 2023 : Debug:   regex-pcre                : no
Tue Jul 18 14:34:33 2023 : Debug:   regex-posix               : yes
Tue Jul 18 14:34:33 2023 : Debug:   regex-posix-extended      : yes
Tue Jul 18 14:34:33 2023 : Debug:   session-management        : yes
Tue Jul 18 14:34:33 2023 : Debug:   stats                     : yes
Tue Jul 18 14:34:33 2023 : Debug:   systemd                   : no
Tue Jul 18 14:34:33 2023 : Debug:   tcp                       : yes
Tue Jul 18 14:34:33 2023 : Debug:   threads                   : yes
Tue Jul 18 14:34:33 2023 : Debug:   tls                       : yes
Tue Jul 18 14:34:33 2023 : Debug:   unlang                    : yes
Tue Jul 18 14:34:33 2023 : Debug:   vmps                      : yes
Tue Jul 18 14:34:33 2023 : Debug:   developer                 : yes
Tue Jul 18 14:34:33 2023 : Debug: Server core libs:
Tue Jul 18 14:34:33 2023 : Debug:   freeradius-server         : 3.2.4
Tue Jul 18 14:34:33 2023 : Debug:   talloc                    : 2.3.*
Tue Jul 18 14:34:33 2023 : Debug:   ssl                       : 3.0.0b dev
Tue Jul 18 14:34:33 2023 : Debug: Endianness:
Tue Jul 18 14:34:33 2023 : Debug:   little
Tue Jul 18 14:34:33 2023 : Debug: Compilation flags:
Tue Jul 18 14:34:33 2023 : Debug:   cppflags :
Tue Jul 18 14:34:33 2023 : Debug:   cflags   : -I. -Isrc -include src/freeradius-devel/autoconf.h -include src/freeradius-devel/build.h -include src/freeradius-devel/features.h -include src/freeradius-devel/radpaths.h -fno-strict-aliasing -Wno-date-time -g3 -Wall -std=c99 -D_GNU_SOURCE -D_REENTRANT -D_POSIX_PTHREAD_SEMANTICS -DOPENSSL_NO_KRB5 -Wshadow -Wpointer-arith -Wcast-qual -Wcast-align -Wwrite-strings -Wstrict-prototypes -Wmissing-prototypes -Wmissing-declarations -Wnested-externs -W -Wredundant-decls -Wundef -Wformat-y2k -Wno-format-extra-args -Wno-format-zero-length -Wno-cast-align -Wformat-nonliteral -Wformat-security -Wformat=2 -DWITH_VERIFY_PTR=1 -DIS_MODULE=1
Tue Jul 18 14:34:33 2023 : Debug:   ldflags  :
Tue Jul 18 14:34:33 2023 : Debug:   libs     : -lcrypto -lssl -ltalloc -latomic -lnsl -lresolv -ldl -lpthread
Tue Jul 18 14:34:33 2023 : Debug:
Tue Jul 18 14:34:33 2023 : Info: FreeRADIUS Version 3.2.4
Tue Jul 18 14:34:33 2023 : Info: Copyright (C) 1999-2022 The FreeRADIUS server project and contributors
Tue Jul 18 14:34:33 2023 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A
Tue Jul 18 14:34:33 2023 : Info: PARTICULAR PURPOSE
Tue Jul 18 14:34:33 2023 : Info: You may redistribute copies of FreeRADIUS under the terms of the
Tue Jul 18 14:34:33 2023 : Info: GNU General Public License
Tue Jul 18 14:34:33 2023 : Info: For more information about these matters, see the file named COPYRIGHT
[Detaching after fork from child process 223655]
Tue Jul 18 14:34:33 2023 : Info: Starting - reading configuration files ...
Tue Jul 18 14:34:33 2023 : Debug: including dictionary file /usr/local/freeradius/share/freeradius/dictionary
Tue Jul 18 14:34:33 2023 : Debug: including dictionary file /usr/local/freeradius/share/freeradius/dictionary.dhcp
Tue Jul 18 14:34:33 2023 : Debug: including dictionary file /usr/local/freeradius/share/freeradius/dictionary.vqp
Tue Jul 18 14:34:33 2023 : Debug: including dictionary file /usr/local/freeradius/etc/raddb/dictionary
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/radiusd.conf
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/clients.conf
Tue Jul 18 14:34:33 2023 : Debug: including files in directory /usr/local/freeradius/etc/raddb/mods-enabled/
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/preprocess
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/digest
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/chap
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/python3_ipaddress_username
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/echo
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/python3_service_username
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/pap
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/files
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/mods-enabled/expr
Tue Jul 18 14:34:33 2023 : Debug: including files in directory /usr/local/freeradius/etc/raddb/policy.d/
Tue Jul 18 14:34:33 2023 : Debug: including files in directory /usr/local/freeradius/etc/raddb/sites-enabled/
Tue Jul 18 14:34:33 2023 : Debug: including configuration file /usr/local/freeradius/etc/raddb/sites-enabled/default
Tue Jul 18 14:34:33 2023 : Debug: main {
Tue Jul 18 14:34:33 2023 : Debug:  security {
Tue Jul 18 14:34:33 2023 : Debug:  	user = "freerad"
Tue Jul 18 14:34:33 2023 : Debug:  	group = "freerad"
Tue Jul 18 14:34:33 2023 : Debug:  	allow_core_dumps = yes
Tue Jul 18 14:34:33 2023 : Debug:  }
Tue Jul 18 14:34:33 2023 : Debug: 	name = "freeradius"
Tue Jul 18 14:34:33 2023 : Debug: 	prefix = "/usr/local/freeradius"
Tue Jul 18 14:34:33 2023 : Debug: 	localstatedir = "/usr/local/freeradius/var"
Tue Jul 18 14:34:33 2023 : Debug: 	logdir = "/usr/local/freeradius/var/log/radius"
Tue Jul 18 14:34:33 2023 : Debug: 	run_dir = "/usr/local/freeradius/var/run/freeradius"
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[7]: The item 'raddbdir' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[8]: The item 'radacctdir' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[20]: The item 'libdir' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[21]: The item 'pidfile' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[23]: The item 'correct_escapes' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[25]: The item 'max_request_time' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[26]: The item 'cleanup_delay' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[27]: The item 'max_requests' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[28]: The item 'hostname_lookups' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[43]: The item 'checkrad' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[56]: The item 'proxy_requests' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Debug: }
Tue Jul 18 14:34:33 2023 : Info: Core dumps are enabled
Tue Jul 18 14:34:33 2023 : Debug: main {
Tue Jul 18 14:34:33 2023 : Debug: 	name = "freeradius"
Tue Jul 18 14:34:33 2023 : Debug: 	prefix = "/usr/local/freeradius"
Tue Jul 18 14:34:33 2023 : Debug: 	localstatedir = "/usr/local/freeradius/var"
Tue Jul 18 14:34:33 2023 : Debug: 	sbindir = "/usr/local/freeradius/sbin"
Tue Jul 18 14:34:33 2023 : Debug: 	logdir = "/usr/local/freeradius/var/log/radius"
Tue Jul 18 14:34:33 2023 : Debug: 	run_dir = "/usr/local/freeradius/var/run/freeradius"
Tue Jul 18 14:34:33 2023 : Debug: 	libdir = "/usr/local/freeradius/lib"
Tue Jul 18 14:34:33 2023 : Debug: 	radacctdir = "/usr/local/freeradius/var/log/radius/radacct"
Tue Jul 18 14:34:33 2023 : Debug: 	hostname_lookups = no
Tue Jul 18 14:34:33 2023 : Debug: 	max_request_time = 30
Tue Jul 18 14:34:33 2023 : Debug: 	cleanup_delay = 5
Tue Jul 18 14:34:33 2023 : Debug: 	max_requests = 16384
Tue Jul 18 14:34:33 2023 : Debug: 	postauth_client_lost = no
Tue Jul 18 14:34:33 2023 : Debug: 	pidfile = "/usr/local/freeradius/var/run/freeradius/freeradius.pid"
Tue Jul 18 14:34:33 2023 : Debug: 	checkrad = "/usr/local/freeradius/sbin/checkrad"
Tue Jul 18 14:34:33 2023 : Debug: 	debug_level = 0
Tue Jul 18 14:34:33 2023 : Debug: 	proxy_requests = no
Tue Jul 18 14:34:33 2023 : Debug:  log {
Tue Jul 18 14:34:33 2023 : Debug:  	stripped_names = no
Tue Jul 18 14:34:33 2023 : Debug:  	auth = yes
Tue Jul 18 14:34:33 2023 : Debug:  	auth_badpass = yes
Tue Jul 18 14:34:33 2023 : Debug:  	auth_goodpass = yes
Tue Jul 18 14:34:33 2023 : Debug:  	colourise = yes
Tue Jul 18 14:34:33 2023 : Debug:  	msg_denied = "You are already logged in - access denied"
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[31]: The item 'destination' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[33]: The item 'file' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Debug:  }
Tue Jul 18 14:34:33 2023 : Debug:  resources {
Tue Jul 18 14:34:33 2023 : Debug:  }
Tue Jul 18 14:34:33 2023 : Debug:  security {
Tue Jul 18 14:34:33 2023 : Debug:  	max_attributes = 0
Tue Jul 18 14:34:33 2023 : Debug:  	reject_delay = 0.000000
Tue Jul 18 14:34:33 2023 : Debug:  	status_server = no
Tue Jul 18 14:34:33 2023 : Debug:  	allow_vulnerable_openssl = "no"
Tue Jul 18 14:34:33 2023 : Debug:  }
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[7]: The item 'raddbdir' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Warning: /usr/local/freeradius/etc/raddb/radiusd.conf[23]: The item 'correct_escapes' is defined, but is unused by the configuration
Tue Jul 18 14:34:33 2023 : Debug: }
Tue Jul 18 14:34:33 2023 : Debug: radiusd: #### Loading Realms and Home Servers ####
Tue Jul 18 14:34:33 2023 : Debug: radiusd: #### Loading Clients ####
Tue Jul 18 14:34:33 2023 : Debug:  client localhost {
Tue Jul 18 14:34:33 2023 : Debug:  	ipaddr = 127.0.0.1
Tue Jul 18 14:34:33 2023 : Debug:  	require_message_authenticator = no
Tue Jul 18 14:34:33 2023 : Debug:  	secret = "testing123"
Tue Jul 18 14:34:33 2023 : Debug:  	nas_type = "other"
Tue Jul 18 14:34:33 2023 : Debug:  	proto = "*"
Tue Jul 18 14:34:33 2023 : Debug:   limit {
Tue Jul 18 14:34:33 2023 : Debug:   	max_connections = 16
Tue Jul 18 14:34:33 2023 : Debug:   	lifetime = 0
Tue Jul 18 14:34:33 2023 : Debug:   	idle_timeout = 30
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:  }
Tue Jul 18 14:34:33 2023 : Debug: Adding client 127.0.0.1/32 (127.0.0.1) to prefix tree 32
Tue Jul 18 14:34:33 2023 : Debug:  client localhost_ipv6 {
Tue Jul 18 14:34:33 2023 : Debug:  	ipv6addr = ::1
Tue Jul 18 14:34:33 2023 : Debug:  	require_message_authenticator = no
Tue Jul 18 14:34:33 2023 : Debug:  	secret = "testing123"
Tue Jul 18 14:34:33 2023 : Debug:   limit {
Tue Jul 18 14:34:33 2023 : Debug:   	max_connections = 16
Tue Jul 18 14:34:33 2023 : Debug:   	lifetime = 0
Tue Jul 18 14:34:33 2023 : Debug:   	idle_timeout = 30
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:  }
Tue Jul 18 14:34:33 2023 : Debug: Adding client ::1/128 (::1) to prefix tree 128
Tue Jul 18 14:34:33 2023 : Info: Found debugger attached
Tue Jul 18 14:34:33 2023 : Debug:  # Creating Auth-Type = PYTHON_IPADRESS
Tue Jul 18 14:34:33 2023 : Debug:  # Creating Auth-Type = PYTHON_SERVICE
Tue Jul 18 14:34:33 2023 : Debug: radiusd: #### Instantiating modules ####
Tue Jul 18 14:34:33 2023 : Debug:  modules {
Tue Jul 18 14:34:33 2023 : Debug: Loading rlm_preprocess with path: /usr/local/freeradius/lib/rlm_preprocess.so
Tue Jul 18 14:34:33 2023 : Debug: Loaded rlm_preprocess, checking if it's valid
Tue Jul 18 14:34:33 2023 : Debug:   # Loaded module rlm_preprocess
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "preprocess" from file /usr/local/freeradius/etc/raddb/mods-enabled/preprocess
Tue Jul 18 14:34:33 2023 : Debug:   preprocess {
Tue Jul 18 14:34:33 2023 : Debug:   	huntgroups = "/usr/local/freeradius/etc/raddb/mods-config/preprocess/huntgroups"
Tue Jul 18 14:34:33 2023 : Debug:   	hints = "/usr/local/freeradius/etc/raddb/mods-config/preprocess/hints"
Tue Jul 18 14:34:33 2023 : Debug:   	with_ascend_hack = no
Tue Jul 18 14:34:33 2023 : Debug:   	ascend_channels_per_line = 23
Tue Jul 18 14:34:33 2023 : Debug:   	with_ntdomain_hack = no
Tue Jul 18 14:34:33 2023 : Debug:   	with_specialix_jetstream_hack = no
Tue Jul 18 14:34:33 2023 : Debug:   	with_cisco_vsa_hack = no
Tue Jul 18 14:34:33 2023 : Debug:   	with_alvarion_vsa_hack = no
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug: Loading rlm_digest with path: /usr/local/freeradius/lib/rlm_digest.so
Tue Jul 18 14:34:33 2023 : Debug: Loaded rlm_digest, checking if it's valid
Tue Jul 18 14:34:33 2023 : Debug:   # Loaded module rlm_digest
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "digest" from file /usr/local/freeradius/etc/raddb/mods-enabled/digest
Tue Jul 18 14:34:33 2023 : Debug: Loading rlm_chap with path: /usr/local/freeradius/lib/rlm_chap.so
Tue Jul 18 14:34:33 2023 : Debug: Loaded rlm_chap, checking if it's valid
Tue Jul 18 14:34:33 2023 : Debug:   # Loaded module rlm_chap
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "chap" from file /usr/local/freeradius/etc/raddb/mods-enabled/chap
Tue Jul 18 14:34:33 2023 : Debug: Loading rlm_python3 with path: /usr/local/freeradius/lib/rlm_python3.so
Tue Jul 18 14:34:33 2023 : Debug: Loaded rlm_python3, checking if it's valid
Tue Jul 18 14:34:33 2023 : Debug:   # Loaded module rlm_python3
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "python3_ipaddress_username" from file /usr/local/freeradius/etc/raddb/mods-enabled/python3_ipaddress_username
Tue Jul 18 14:34:33 2023 : Debug:   python3 python3_ipaddress_username {
Tue Jul 18 14:34:33 2023 : Debug:   	mod_instantiate = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_instantiate = "instantiate"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_authorize = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_authorize = "authorize"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_authenticate = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_authenticate = "authenticate"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_preacct = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_preacct = "preacct"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_accounting = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_accounting = "accounting"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_checksimul = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_checksimul = "checksimul"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_pre_proxy = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_pre_proxy = "pre_proxy"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_post_proxy = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_post_proxy = "post_proxy"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_post_auth = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_post_auth = "post_auth"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_recv_coa = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_recv_coa = "recv_coa"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_send_coa = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_send_coa = "send_coa"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_detach = "ipaddress_username"
Tue Jul 18 14:34:33 2023 : Debug:   	func_detach = "detach"
Tue Jul 18 14:34:33 2023 : Debug:   	python_path = ":/usr/local/freeradius/etc/raddb/mods-config/python3"
Tue Jul 18 14:34:33 2023 : Debug:   	cext_compat = yes
Tue Jul 18 14:34:33 2023 : Debug:   	pass_all_vps = no
Tue Jul 18 14:34:33 2023 : Debug:   	pass_all_vps_dict = yes
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug: Loading rlm_exec with path: /usr/local/freeradius/lib/rlm_exec.so
Tue Jul 18 14:34:33 2023 : Debug: Loaded rlm_exec, checking if it's valid
Tue Jul 18 14:34:33 2023 : Debug:   # Loaded module rlm_exec
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "echo" from file /usr/local/freeradius/etc/raddb/mods-enabled/echo
Tue Jul 18 14:34:33 2023 : Debug:   exec echo {
Tue Jul 18 14:34:33 2023 : Debug:   	wait = yes
Tue Jul 18 14:34:33 2023 : Debug:   	program = "/bin/echo %{User-Name}"
Tue Jul 18 14:34:33 2023 : Debug:   	input_pairs = "request"
Tue Jul 18 14:34:33 2023 : Debug:   	output_pairs = "reply"
Tue Jul 18 14:34:33 2023 : Debug:   	shell_escape = yes
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "python3_service_username" from file /usr/local/freeradius/etc/raddb/mods-enabled/python3_service_username
Tue Jul 18 14:34:33 2023 : Debug:   python3 python3_service_username {
Tue Jul 18 14:34:33 2023 : Debug:   	mod_instantiate = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_instantiate = "instantiate"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_authorize = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_authorize = "authorize"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_authenticate = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_authenticate = "authenticate"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_preacct = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_preacct = "preacct"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_accounting = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_accounting = "accounting"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_checksimul = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_checksimul = "checksimul"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_pre_proxy = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_pre_proxy = "pre_proxy"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_post_proxy = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_post_proxy = "post_proxy"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_post_auth = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_post_auth = "post_auth"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_recv_coa = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_recv_coa = "recv_coa"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_send_coa = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_send_coa = "send_coa"
Tue Jul 18 14:34:33 2023 : Debug:   	mod_detach = "example"
Tue Jul 18 14:34:33 2023 : Debug:   	func_detach = "detach"
Tue Jul 18 14:34:33 2023 : Debug:   	python_path = ":/usr/local/freeradius/etc/raddb/mods-config/python3"
Tue Jul 18 14:34:33 2023 : Debug:   	cext_compat = yes
Tue Jul 18 14:34:33 2023 : Debug:   	pass_all_vps = no
Tue Jul 18 14:34:33 2023 : Debug:   	pass_all_vps_dict = yes
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug: Loading rlm_pap with path: /usr/local/freeradius/lib/rlm_pap.so
Tue Jul 18 14:34:33 2023 : Debug: Loaded rlm_pap, checking if it's valid
Tue Jul 18 14:34:33 2023 : Debug:   # Loaded module rlm_pap
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "pap" from file /usr/local/freeradius/etc/raddb/mods-enabled/pap
Tue Jul 18 14:34:33 2023 : Debug:   pap {
Tue Jul 18 14:34:33 2023 : Debug:   	normalise = yes
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "module_pap_1" from file /usr/local/freeradius/etc/raddb/mods-enabled/pap
Tue Jul 18 14:34:33 2023 : Debug:   pap module_pap_1 {
Tue Jul 18 14:34:33 2023 : Debug:   	normalise = yes
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "module_pap_2" from file /usr/local/freeradius/etc/raddb/mods-enabled/pap
Tue Jul 18 14:34:33 2023 : Debug:   pap module_pap_2 {
Tue Jul 18 14:34:33 2023 : Debug:   	normalise = yes
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug: Loading rlm_files with path: /usr/local/freeradius/lib/rlm_files.so
Tue Jul 18 14:34:33 2023 : Debug: Loaded rlm_files, checking if it's valid
Tue Jul 18 14:34:33 2023 : Debug:   # Loaded module rlm_files
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "module_files_1" from file /usr/local/freeradius/etc/raddb/mods-enabled/files
Tue Jul 18 14:34:33 2023 : Debug:   files module_files_1 {
Tue Jul 18 14:34:33 2023 : Debug:   	filename = "/usr/local/freeradius/etc/raddb/mods-config/module_files_1/authorize"
Tue Jul 18 14:34:33 2023 : Debug:   	usersfile = "/usr/local/freeradius/etc/raddb/mods-config/module_files_1/authorize"
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "module_files_2" from file /usr/local/freeradius/etc/raddb/mods-enabled/files
Tue Jul 18 14:34:33 2023 : Debug:   files module_files_2 {
Tue Jul 18 14:34:33 2023 : Debug:   	filename = "/usr/local/freeradius/etc/raddb/mods-config/module_files_2/authorize"
Tue Jul 18 14:34:33 2023 : Debug:   	usersfile = "/usr/local/freeradius/etc/raddb/mods-config/module_files_2/authorize"
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug: Loading rlm_realm with path: /usr/local/freeradius/lib/rlm_realm.so
Tue Jul 18 14:34:33 2023 : Debug: Loaded rlm_realm, checking if it's valid
Tue Jul 18 14:34:33 2023 : Debug:   # Loaded module rlm_realm
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "IPASS" from file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:34:33 2023 : Debug:   realm IPASS {
Tue Jul 18 14:34:33 2023 : Debug:   	format = "prefix"
Tue Jul 18 14:34:33 2023 : Debug:   	delimiter = "/"
Tue Jul 18 14:34:33 2023 : Debug:   	ignore_default = no
Tue Jul 18 14:34:33 2023 : Debug:   	ignore_null = no
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "suffix" from file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:34:33 2023 : Debug:   realm suffix {
Tue Jul 18 14:34:33 2023 : Debug:   	format = "suffix"
Tue Jul 18 14:34:33 2023 : Debug:   	delimiter = "@"
Tue Jul 18 14:34:33 2023 : Debug:   	ignore_default = no
Tue Jul 18 14:34:33 2023 : Debug:   	ignore_null = no
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "bangpath" from file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:34:33 2023 : Debug:   realm bangpath {
Tue Jul 18 14:34:33 2023 : Debug:   	format = "prefix"
Tue Jul 18 14:34:33 2023 : Debug:   	delimiter = "!"
Tue Jul 18 14:34:33 2023 : Debug:   	ignore_default = no
Tue Jul 18 14:34:33 2023 : Debug:   	ignore_null = no
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "realmpercent" from file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:34:33 2023 : Debug:   realm realmpercent {
Tue Jul 18 14:34:33 2023 : Debug:   	format = "suffix"
Tue Jul 18 14:34:33 2023 : Debug:   	delimiter = "%"
Tue Jul 18 14:34:33 2023 : Debug:   	ignore_default = no
Tue Jul 18 14:34:33 2023 : Debug:   	ignore_null = no
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "ntdomain" from file /usr/local/freeradius/etc/raddb/mods-enabled/realm
Tue Jul 18 14:34:33 2023 : Debug:   realm ntdomain {
Tue Jul 18 14:34:33 2023 : Debug:   	format = "prefix"
Tue Jul 18 14:34:33 2023 : Debug:   	delimiter = "\\"
Tue Jul 18 14:34:33 2023 : Debug:   	ignore_default = no
Tue Jul 18 14:34:33 2023 : Debug:   	ignore_null = no
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug: Loading rlm_expr with path: /usr/local/freeradius/lib/rlm_expr.so
Tue Jul 18 14:34:33 2023 : Debug: Loaded rlm_expr, checking if it's valid
Tue Jul 18 14:34:33 2023 : Debug:   # Loaded module rlm_expr
Tue Jul 18 14:34:33 2023 : Debug:   # Loading module "expr" from file /usr/local/freeradius/etc/raddb/mods-enabled/expr
Tue Jul 18 14:34:33 2023 : Debug:   expr {
Tue Jul 18 14:34:33 2023 : Debug:   	safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /äéöüàâæçèéêëîïôœùûüaÿÄÉÖÜßÀÂÆÇÈÉÊËÎÏÔŒÙÛÜŸ"
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:   instantiate {
Tue Jul 18 14:34:33 2023 : Debug:   }
Tue Jul 18 14:34:33 2023 : Debug:   # Instantiating module "preprocess" from file /usr/local/freeradius/etc/raddb/mods-enabled/preprocess
Tue Jul 18 14:34:33 2023 : Debug: reading pairlist file /usr/local/freeradius/etc/raddb/mods-config/preprocess/huntgroups
Tue Jul 18 14:34:33 2023 : Debug: reading pairlist file /usr/local/freeradius/etc/raddb/mods-config/preprocess/hints
Tue Jul 18 14:34:33 2023 : Debug:   # Instantiating module "python3_ipaddress_username" from file /usr/local/freeradius/etc/raddb/mods-enabled/python3_ipaddress_username
Tue Jul 18 14:34:33 2023 : Info: Python version: 3.10.6 (main, May 29 2023, 11:10:38) [GCC 11.3.0]
*** instantiate ***
{'request': None, 'reply': None, 'config': None, 'session-state': None, 'proxy-request': None, 'proxy-reply': None}
<pymysql.connections.Connection object at 0x7ffff6bcbc10>
[{'id': 12117, 'uid': 5872, 'ip': 3232269124, 'hostname': 'len10', 'network': 0, 'mac': '90:94:e4:ed:ad:f5', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': datetime.date(2030, 1, 1), 'seen': 0, 'comments': '', 'vid': 3299, 'nas': 123638406563423, 'option_82': 0, 'ports': '15', 'boot_file': '', 'changed': datetime.datetime(2023, 2, 4, 12, 21, 1)}, {'id': 11594, 'uid': 5543, 'ip': 3232268844, 'hostname': 'sp7ak51', 'network': 0, 'mac': 'e8:48:b8:99:87:eb', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': datetime.date(2030, 1, 1), 'seen': 0, 'comments': '', 'vid': 3051, 'nas': 123638407509972, 'option_82': 0, 'ports': '3', 'boot_file': '', 'changed': datetime.datetime(2022, 3, 1, 11, 40, 43)}, {'id': 10623, 'uid': 5107, 'ip': 3232271011, 'hostname': 'en2k30', 'network': 0, 'mac': '50:d4:f7:af:db:23', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 2002, 'nas': 123638407276559, 'option_82': 0, 'ports': '10', 'boot_file': '', 'changed': datetime.datetime(2020, 2, 4, 16, 32, 35)}, {'id': 9368, 'uid': 4569, 'ip': 3232269914, 'hostname': 'sasha7', 'network': 0, 'mac': 'e8:94:f6:8f:28:03', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3096, 'nas': 80796821719, 'option_82': 0, 'ports': '12', 'boot_file': '', 'changed': datetime.datetime(2017, 1, 26, 11, 22, 49)}, {'id': 4716, 'uid': 78, 'ip': 3232269515, 'hostname': 'milana', 'network': 0, 'mac': '00:1a:92:97:72:2f', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3063, 'nas': 80796805856, 'option_82': 0, 'ports': '1', 'boot_file': '', 'changed': datetime.datetime(2012, 4, 28, 16, 21, 20)}, {'id': 9793, 'uid': 1407, 'ip': 3232271064, 'hostname': 'doshenko', 'network': 0, 'mac': '3c:84:6a:00:d6:89', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3002, 'nas': 123638406465897, 'option_82': 0, 'ports': '11', 'boot_file': '', 'changed': datetime.datetime(2018, 3, 21, 14, 28, 21)}, {'id': 11222, 'uid': 3454, 'ip': 3232268895, 'hostname': 'len_1', 'network': 0, 'mac': 'a0:f3:c1:ee:7f:e9', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3253, 'nas': 190154839202432, 'option_82': 0, 'ports': '14', 'boot_file': '', 'changed': datetime.datetime(2021, 2, 23, 13, 14, 35)}, {'id': 4712, 'uid': 88, 'ip': 3232268412, 'hostname': 'aspera', 'network': 0, 'mac': '34:60:f9:6b:b5:ee', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3063, 'nas': 80796805856, 'option_82': 0, 'ports': '1', 'boot_file': '', 'changed': datetime.datetime(2012, 4, 28, 15, 47, 19)}, {'id': 11209, 'uid': 2211, 'ip': 3232270497, 'hostname': 'zlata', 'network': 0, 'mac': '64:70:02:be:c7:4f', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3074, 'nas': 123638407500547, 'option_82': 0, 'ports': '1', 'boot_file': '', 'changed': datetime.datetime(2021, 2, 17, 17, 31, 52)}, {'id': 7103, 'uid': 1238, 'ip': 3232270609, 'hostname': 'loki', 'network': 0, 'mac': 'f4:f2:6d:4c:2a:93', 'disable': 0, 'forced': 0, 'blocktime': 0, 'expire': '0000-00-00', 'seen': 0, 'comments': '', 'vid': 3077, 'nas': 123638408947744, 'option_82': 0, 'ports': '18', 'boot_file': '', 'changed': datetime.datetime(2014, 1, 18, 15, 3)}]
****************
Tue Jul 18 14:34:33 2023 : Debug:   # Instantiating module "python3_service_username" from file /usr/local/freeradius/etc/raddb/mods-enabled/python3_service_username
Fatal Python error: drop_gil: drop_gil: GIL is not locked
Python runtime state: initialized

Current thread 0x00007ffff77c2740 (most recent call first):
  <no Python frame>

Extension modules: radiusd, _cffi_backend (total: 2)

Program received signal SIGABRT, Aborted.
__pthread_kill_implementation (no_tid=0, signo=6, threadid=140737345496896) at ./nptl/pthread_kill.c:44
44	./nptl/pthread_kill.c: No such file or directory.
@sirmax123 sirmax123 added the defect category: a defect or misbehaviour label Jul 18, 2023
@sirmax123
Copy link
Author

tested on

./radiusd -v
radiusd: FreeRADIUS Version 3.2.4 (git #892334968), for host x86_64-pc-linux-gnu, built on Jul 18 2023 at 12:20:50
FreeRADIUS Version 3.2.4
Copyright (C) 1999-2022 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
For more information about these matters, see the file named COPYRIGHT

freeradius -v
radiusd: FreeRADIUS Version 3.0.26, for host x86_64-pc-linux-gnu, built on Jan  4 2023 at 03:23:09
FreeRADIUS Version 3.0.26
Copyright (C) 1999-2021 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
For more information about these matters, see the file named COPYRIGHT

with same result

@arr2036
Copy link
Member

arr2036 commented Jul 18, 2023

Please submit a PR with a testcase which reproduces this and we'll try to develop a fix. I'd also be interested to see if you still get the crash with master (v4) as that code is substantially different.

@sirmax123
Copy link
Author

sirmax123 commented Jul 18, 2023 •
edited

do not know how to create PR, could you please provide me with an example?

Steps to reproduce:

Build:

  1. git clone https://github.com/FreeRADIUS/freeradius-server.git
  2. git checkout remotes/origin/v3.2.x
  3. ./configure; make; make install

Configure:

  1. Prepere radiusd.conf (no includes! all you need is in file!)
    /usr/local/freeradius/etc/raddb/radiusd.conf (path depends on your OS i guess, it is from Ubuntu 22.04)

prefix = /usr/local/freeradius
exec_prefix = ${prefix}
sysconfdir = ${prefix}/etc
localstatedir = ${prefix}/var
sbindir = ${exec_prefix}/sbin
logdir = ${localstatedir}/log/radius
raddbdir = ${sysconfdir}/raddb
radacctdir = ${logdir}/radacct
name = freeradius
modconfdir = ${confdir}/mods-config
#certdir = ${confdir}/certs
#cadir   = ${confdir}/certs
run_dir = ${localstatedir}/run/${name}
libdir = ${exec_prefix}/lib
pidfile = ${run_dir}/${name}.pid
correct_escapes = true
max_request_time = 30
cleanup_delay = 5
max_requests = 16384
hostname_lookups = no

log {
    destination = files
    colourise = yes
    file = ${logdir}/radius.log
    stripped_names = no
    auth = yes
    auth_badpass = yes
    auth_goodpass = yes
    msg_denied = "You are already logged in - access denied"
}
checkrad = ${sbindir}/checkrad
security {
    user = freerad
    group = freerad
    allow_core_dumps = yes
}
proxy_requests  = no

client 100.100.100.254 {
   secret = radius
   shortname = ASR1001
   nastype = other
}

client localhost {
    ipaddr = 127.0.0.1
    proto = *
    secret = secret
    require_message_authenticator = no
}
thread pool {
    start_servers = 5
    max_servers = 32
    min_spare_servers = 3
    max_spare_servers = 10
    max_requests_per_server = 0
    auto_limit_acct = no
}

modules {
    python3 python3_ipaddress_username {
        python_path =":${modconfdir}/${.:name}"
        module = ipaddress_username
        pass_all_vps_dict = yes
        mod_instantiate = ${.module}
        func_instantiate = instantiate
        mod_detach = ${.module}
        func_detach = detach
        mod_authorize = ${.module}
        func_authorize = authorize
        mod_authenticate = ${.module}
        func_authenticate = authenticate
        mod_preacct = ${.module}
        func_preacct = preacct
        mod_accounting = ${.module}
        func_accounting = accounting
        mod_checksimul = ${.module}
        func_checksimul = checksimul
        mod_pre_proxy = ${.module}
        func_pre_proxy = pre_proxy
        mod_post_proxy = ${.module}
        func_post_proxy = post_proxy
        mod_post_auth = ${.module}
        func_post_auth = post_auth
        mod_recv_coa = ${.module}
        func_recv_coa = recv_coa
        mod_send_coa = ${.module}
        func_send_coa = send_coa
    }

    python3 python3_service_username {
        python_path =":${modconfdir}/${.:name}"
        module = service_username
        pass_all_vps_dict = yes
        mod_instantiate = ${.module}
        func_instantiate = instantiate
        mod_detach = ${.module}
        func_detach = detach
        mod_authorize = ${.module}
        func_authorize = authorize
        mod_authenticate = ${.module}
        func_authenticate = authenticate
        mod_preacct = ${.module}
        func_preacct = preacct
        mod_accounting = ${.module}
        func_accounting = accounting
        mod_checksimul = ${.module}
        func_checksimul = checksimul
        mod_pre_proxy = ${.module}
        func_pre_proxy = pre_proxy
        mod_post_proxy = ${.module}
        func_post_proxy = post_proxy
        mod_post_auth = ${.module}
        func_post_auth = post_auth
        mod_recv_coa = ${.module}
        func_recv_coa = recv_coa
        mod_send_coa = ${.module}
        func_send_coa = send_coa
    }
}

instantiate {
}

policy {
}

server default {
    listen {
        type = auth
        ipv4addr = *
        port = 1812
        limit {
            max_connections = 16
            lifetime = 0
            idle_timeout = 30
        }
    }

    listen {
        ipv4addr = *
        port = 1813
        type = acct
    }
    instantiate {
    }
    authorize {
        python3_ipaddress_username
        python3_service_username
    }

    authenticate {
        Auth-Type PYTHON_IPADRESS {
            python3_ipaddress_username
        }
        Auth-Type PYTHON_SERVICE {
            python3_service_username
        }
    }
}
  1. Fix example.py (from distribution): add 2 methods, just simple placeholders doing nothing:
def authenticate(p):
  print("*** authenticate ***")
  radiusd.radlog(radiusd.L_INFO, '*** radlog call in authenticate ***')
  print()
  print(p)
  print()
  print(radiusd.config)
  return radiusd.RLM_MODULE_OK


def checksimul(p):
  print("*** checksimul ***")
  radiusd.radlog(radiusd.L_INFO, '*** radlog call in checksimul ***')
  print()
  print(p)
  print()
  print(radiusd.config)
  return radiusd.RLM_MODULE_OK

  1. Copy example.py to /usr/local/freeradius/etc/raddb/mods-config/python3/ipaddress_username.py and to /usr/local/freeradius/etc/raddb/mods-config/python3/service_username.py
    (path also depends on your system!)

  2. Executer radiusd with command: cd /usr/local/freeradius/sbin && ./radiusd -XXXX

  3. Got an error:

*** instantiate ***
{'request': None, 'reply': None, 'config': None, 'session-state': None, 'proxy-request': None, 'proxy-reply': None}
Tue Jul 18 15:41:36 2023 : Debug:   # Instantiating module "python3_service_username" from file /usr/local/freeradius/etc/raddb/radiusd.conf
Fatal Python error: drop_gil: drop_gil: GIL is not locked
Python runtime state: initialized

Current thread 0x00007f4164b2a740 (most recent call first):

Also I tried to build v4 but configuration is different and I still working on making simple working configuration (will update if I will be able to run rlm_python on v4)

@jpereira jpereira self-assigned this Jul 20, 2023
@jpereira jpereira added the v3.2.x meta: relates to the v3.2.x branch label Jul 20, 2023
jpereira added a commit to jpereira/freeradius-server that referenced this issue Jul 24, 2023
@jpereira
Fix rlm_python3 dead-lock in GIL. ref FreeRADIUS#5111
eafaff9 
... Limiting to have more than one instance
@jpereira
Copy link
Member

@sirmax123 Could you please perform your tests against the branch v32/fix-5111 in https://github.com/jpereira/freeradius-server/ ?

jpereira added a commit to jpereira/freeradius-server that referenced this issue Jul 24, 2023
@jpereira
Fix rlm_python3 dead-lock in GIL. ref FreeRADIUS#5111
d5b1f36 
... Limiting to have more than one instance
@sirmax123
Copy link
Author

@sirmax123 Could you please perform your tests against the branch v32/fix-5111 in https://github.com/jpereira/freeradius-server/ ?

Just built and tested, looks good to me:

git clone https://github.com/jpereira/freeradius-server.git
git switch v32/fix-5111
./configure  --prefix=/usr/local/freeradius
make
make install

 /usr/local/freeradius/sbin/radiusd -v
radiusd: FreeRADIUS Version 3.2.4 (git #d5b1f3644), for host x86_64-pc-linux-gnu, built on Jul 25 2023 at 15:00:40
FreeRADIUS Version 3.2.4
Copyright (C) 1999-2022 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
For more information about these matters, see the file named COPYRIGHT

Tue Jul 25 15:24:22 2023 : Debug: (0) python3_ipaddress_username: Initialised new thread state 0x561d2b669a30
Tue Jul 25 15:24:22 2023 : Debug: (0) python3_ipaddress_username: Using thread state 0x561d2b669a30
*** authorize ***
Tue Jul 25 15:24:22 2023 : Info: *** radlog call in authorize ***

{'request': (('User-Name', 'SERVICE_IN_4120_OUT_4120'), ('User-Password', 'hello'), ('NAS-IP-Address', '10.90.1.213'), ('NAS-Port', '0'), ('Message-Authenticator', '0x44e06cbda100b814fca8f03a653870ff')), 'reply': None, 'config': None, 'session-state': None, 'proxy-request': None, 'proxy-reply': None}

{}
Tue Jul 25 15:24:22 2023 : Debug: (0)     modsingle[authorize]: returned from python3_ipaddress_username (rlm_python3)
Tue Jul 25 15:24:22 2023 : Debug: (0)     [python3_ipaddress_username] = ok
Tue Jul 25 15:24:22 2023 : Debug: (0)     modsingle[authorize]: calling python3_service_username (rlm_python3)
Tue Jul 25 15:24:22 2023 : Debug: (0) python3_service_username: Initialised new thread state 0x561d2b669c60
Tue Jul 25 15:24:22 2023 : Debug: (0) python3_service_username: Using thread state 0x561d2b669c60
*** authorize ***
Tue Jul 25 15:24:22 2023 : Info: *** radlog call in authorize ***

{'request': (('User-Name', 'SERVICE_IN_4120_OUT_4120'), ('User-Password', 'hello'), ('NAS-IP-Address', '10.90.1.213'), ('NAS-Port', '0'), ('Message-Authenticator', '0x44e06cbda100b814fca8f03a653870ff')), 'reply': None, 'config': None, 'session-state': None, 'proxy-request': None, 'proxy-reply': None}

{}
Tue Jul 25 15:24:22 2023 : Debug: (0)     modsingle[authorize]: returned from python3_service_username (rlm_python3)
Tue Jul 25 15:24:22 2023 : Debug: (0)     [python3_service_username] = ok
Tue Jul 25 15:24:22 2023 : Debug: (0)   } # authorize = ok
Tue Jul 25 15:24:22 2023 : ERROR: (0) No Auth-Type found: rejecting the user via Post-Auth-Type = Reject
Tue Jul 25 15:24:22 2023 : Debug: (0) Failed to authenticate the user
Tue Jul 25 15:24:22 2023 : Debug: (0) Using Post-Auth-Type Reject
Tue Jul 25 15:24:22 2023 : Debug: (0) Post-Auth-Type sub-section not found.  Ignoring.

(tested with radtest SERVICE_IN_4120_OUT_4120 hello localhost 0 secret command)

So, I think this issue can be marked as fixed when your patch is merged.

Thank you!

@jpereira
Copy link
Member

Thank you @sirmax123 for the feedback.

@sirmax123 Could you please perform your tests against the branch v32/fix-5111 in https://github.com/jpereira/freeradius-server/ ?

Just built and tested, looks good to me:

jpereira added a commit to jpereira/freeradius-server that referenced this issue Jul 28, 2023
@jpereira
Fix rlm_python3 dead-lock in GIL. ref FreeRADIUS#5111
144088d 
... Limiting to have more than one instance
alandekok added a commit that referenced this issue Aug 25, 2023
@alandekok
initialize local variables. May help with #5111
6dc5a84 
main_interprerter is checked, but there are code paths by which
the variable is used without being initialized.
@alandekok alandekok added this to the 4.0.0 release milestone Aug 25, 2023
alandekok added a commit that referenced this issue Aug 25, 2023
@alandekok
acquire lock. Helps with #5111
ecd3d04
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@jpereira jpereira

Labels
defect category: a defect or misbehaviour v3.2.x meta: relates to the v3.2.x branch
Projects
None yet
Milestone
4.0.0 release
Development

No branches or pull requests
4 participants
@alandekok @jpereira @arr2036 @sirmax123