rlm_couchbase skipping attribute with no map entry
Mike Lopes
mlopes at teksavvy.ca
Tue Dec 19 19:18:48 CET 2017
Hi,
I am trying to set up a new freeradius server (v3.0.15) so that it will send directly to a couchbase server instead of my current old radius server setup that is sending accounting via a radius-proxy server.
Any help would be appreciated in trying to figure this out.
I have enabled the following environment settings:
LCB_OPTIONS="detailed_errcodes=1" && export LCB_OPTIONS
LCB_CNTL_DETAILED_ERRCODES=1 && export LCB_CNTL_DETAILED_ERRCODES
LCB_LOGLEVEL=5 && export LCB_LOGLEVEL
Here is the trimmed output from radius -X:
(0) Received Accounting-Request Id 65 from 127.0.0.1:55005 to 127.0.0.1:1813 length 715
(0) User-Name = "noneexistent123 at domain.com"
(0) Acct-Status-Type = Interim-Update
(0) Acct-Session-Id = "25466609"
(0) Acct-Input-Octets = 211016095
(0) Acct-Output-Octets = 3081069646
(0) Acct-Session-Time = 2047177
(0) Acct-Input-Packets = 179269685
(0) Acct-Output-Packets = 322301129
(0) Service-Type = Framed-User
(0) Framed-Protocol = PPP
(0) Filter-Id = "IPV4-ingress:dsl-default-in-si-1/1/0.1073813193-in"
(0) Filter-Id = "IPV4-egress:dsl-default-out-si-1/1/0.1073813193-out"
(0) Attr-26.4874.177 = 0x506f72742053706565643a2031303030303030306b
(0) Tunnel-Type:0 = L2TP
(0) Tunnel-Medium-Type:0 = IPv4
(0) Tunnel-Client-Endpoint:0 = "192.168.242.189"
(0) Tunnel-Server-Endpoint:0 = "192.168.80.106"
(0) Tunnel-Assignment-Id:0 = "57524"
(0) Tunnel-Client-Auth-Id:0 = "AR09"
(0) Tunnel-Server-Auth-Id:0 = "company"
(0) Acct-Tunnel-Connection = "0002758216"
(0) Acct-Authentic = RADIUS
(0) Acct-Delay-Time = 0
(0) Calling-Station-Id = "GigabitEthernet 1/0.12502026:1250-2026#587204111###pppoe 4c:9e:ff:27:41:4c#"
(0) ERX-Dhcp-Mac-Addr = "0000.0000.0000"
(0) Event-Timestamp = "Dec 12 2017 11:35:30 EST"
(0) Framed-IP-Address = 192.168.225.42
(0) Framed-IP-Netmask = 255.255.254.0
(0) ERX-Input-Gigapkts = 0
(0) Acct-Input-Gigawords = 4
(0) NAS-Identifier = "lns01"
(0) NAS-Port = 268439551
(0) NAS-Port-Id = "Ip:192.168.80.106:192.168.242.189:57524:10046:22601:33289:2758216"
(0) NAS-Port-Type = Virtual
(0) ERX-Output-Gigapkts = 0
(0) Acct-Output-Gigawords = 103
(0) ERX-IPv6-Acct-Input-Octets = 0
(0) ERX-IPv6-Acct-Output-Octets = 0
(0) ERX-IPv6-Acct-Input-Packets = 0
(0) ERX-IPv6-Acct-Output-Packets = 0
(0) ERX-IPv6-Acct-Input-Gigawords = 0
(0) ERX-IPv6-Acct-Output-Gigawords = 0
(0) ERX-Tx-Connect-Speed = 13277755
(0) Attr-26.4874.163 = 0x000000
(0) ERX-Pppoe-Description = "pppoe 00:00:00:00:00:00"
(0) NAS-IP-Address = 192.168.191.4
(0) # Executing section preacct from file /etc/raddb/sites-enabled/company
(0) preacct {
(0) policy username_lower_domain {
(0) update request {
(0) EXPAND %{tolower:%{User-Name}}
(0) --> noneexistent123 at company.com
(0) Stripped-User-Name := noneexistent123 at company.com
(0) } # update request = noop
(0) if (User-Name =~ /^([^@]*)(@([-[:alnum:]]+\\.[-[:alnum:].]+))?$/){
(0) if (User-Name =~ /^([^@]*)(@([-[:alnum:]]+\\.[-[:alnum:].]+))?$/) -> FALSE
(0) else {
(0) [noop] = noop
(0) } # else = noop
(0) } # policy username_lower_domain = noop
(0) policy acct_counters64_preacct {
(0) update request {
(0) EXPAND %{expr:(%{%{Acct-Input-Gigawords}:-0} * 4294967296) + %{%{Acct-Input-Octets}:-0}}
(0) --> 17390885279
(0) Acct-Input-Octets64 = 17390885279
(0) EXPAND %{expr:(%{%{Acct-Output-Gigawords}:-0} * 4294967296) + %{%{Acct-Output-Octets}:-0}}
(0) --> 445462701134
(0) Acct-Output-Octets64 = 445462701134
(0) } # update request = noop
(0) } # policy acct_counters64_preacct = noop
(0) policy acct_unique {
(0) update request {
(0) EXPAND %{md5:%{Stripped-User-Name},%{Acct-Session-ID},%{NAS-IP-Address}}
(0) --> 51dc686492632c94c03d1346eb471bf5
(0) Acct-Unique-Session-Id := 51dc686492632c94c03d1346eb471bf5
(0) } # update request = noop
(0) } # policy acct_unique = noop
(0) if (NAS-Port-Id =~ /:([0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}):([0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}):/) {
(0) if (NAS-Port-Id =~ /:([0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}):([0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}):/) -> TRUE
(0) if (NAS-Port-Id =~ /:([0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}):([0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}):/) {
(0) update request {
(0) EXPAND %{1}
(0) --> 192.168.80.106
(0) NAS-Port-Id := 192.168.80.106
(0) EXPAND %{2}
(0) --> 192.168.242.189
(0) NAS-Identifier := 192.168.242.189
(0) } # update request = noop
(0) } # if (NAS-Port-Id =~ /:([0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}):([0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}\.[0-9]{1,3}):/) = noop
(0) } # preacct = noop
(0) # Executing section accounting from file /etc/raddb/sites-enabled/company
(0) accounting {
rlm_couchbase (couchtsi): Reserved connection (0)
(0) couchtsi: EXPAND radacct_%{%{Acct-Unique-Session-Id}:-%{Acct-Session-Id}}
(0) couchtsi: --> radacct_51dc686492632c94c03d1346eb471bf5
32450ms [I0] {32348} [INFO] (lcbio_mgr - L:410) <10.0.2.207:11210> (HE=0x5652b23dde40) Found ready connection in pool. Reusing socket and not creating new connection
32450ms [I0] {32348} [TRACE] (bootstrap - L:143) Background-polling for new configuration
32450ms [I0] {32348} [TRACE] (confmon - L:272) Refreshing current cluster map
32450ms [I0] {32348} [DEBUG] (lcbio_mgr - L:247) <10.0.2.207:11210> (HE=0x5652b23dde40) Assigning R=0x5652b2445930 SOCKET=0x5652b23df380
32450ms [I0] {32348} [DEBUG] (ioctx - L:99) <10.0.2.207:11210> (CTX=0x5652b26410d0,unknown) Pairing with SOCK=0x5652b23df380
32450ms [I0] {32348} [TRACE] (confmon - L:259) Attempting to retrieve cluster map via CCCP
32450ms [I0] {32348} [TRACE] (cccp - L:144) Re-Issuing CCCP Command on server struct 0x5652b23ebaf0 (10.0.2.207:11210)
rlm_couchbase: (get_callback) got 93 bytes
32451ms [I0] {32348} [TRACE] (confmon - L:150) Not applying configuration received via CCCP. No changes detected. A.rev=25, B.rev=25
rlm_couchbase: skipping attribute with no map entry - User-Name
rlm_couchbase: skipping attribute with no map entry - Acct-Status-Type
rlm_couchbase: skipping attribute with no map entry - Acct-Session-Id
rlm_couchbase: skipping attribute with no map entry - Acct-Input-Octets
rlm_couchbase: skipping attribute with no map entry - Acct-Output-Octets
rlm_couchbase: skipping attribute with no map entry - Acct-Session-Time
rlm_couchbase: skipping attribute with no map entry - Acct-Input-Packets
rlm_couchbase: skipping attribute with no map entry - Acct-Output-Packets
rlm_couchbase: skipping attribute with no map entry - Service-Type
rlm_couchbase: skipping attribute with no map entry - Framed-Protocol
rlm_couchbase: skipping attribute with no map entry - Filter-Id
rlm_couchbase: skipping attribute with no map entry - Filter-Id
rlm_couchbase: skipping attribute with no map entry - Attr-26.4874.177
rlm_couchbase: skipping attribute with no map entry - Tunnel-Type
rlm_couchbase: skipping attribute with no map entry - Tunnel-Medium-Type
rlm_couchbase: skipping attribute with no map entry - Tunnel-Client-Endpoint
rlm_couchbase: skipping attribute with no map entry - Tunnel-Server-Endpoint
rlm_couchbase: skipping attribute with no map entry - Tunnel-Assignment-Id
rlm_couchbase: skipping attribute with no map entry - Tunnel-Client-Auth-Id
rlm_couchbase: skipping attribute with no map entry - Tunnel-Server-Auth-Id
rlm_couchbase: skipping attribute with no map entry - Acct-Tunnel-Connection
rlm_couchbase: skipping attribute with no map entry - Acct-Authentic
rlm_couchbase: skipping attribute with no map entry - Acct-Delay-Time
rlm_couchbase: skipping attribute with no map entry - Calling-Station-Id
rlm_couchbase: skipping attribute with no map entry - ERX-Dhcp-Mac-Addr
rlm_couchbase: skipping attribute with no map entry - Event-Timestamp
rlm_couchbase: skipping attribute with no map entry - Framed-IP-Address
rlm_couchbase: skipping attribute with no map entry - Framed-IP-Netmask
rlm_couchbase: skipping attribute with no map entry - ERX-Input-Gigapkts
rlm_couchbase: skipping attribute with no map entry - Acct-Input-Gigawords
rlm_couchbase: skipping attribute with no map entry - NAS-Identifier
rlm_couchbase: skipping attribute with no map entry - NAS-Port
rlm_couchbase: skipping attribute with no map entry - NAS-Port-Id
rlm_couchbase: skipping attribute with no map entry - NAS-Port-Type
rlm_couchbase: skipping attribute with no map entry - ERX-Output-Gigapkts
rlm_couchbase: skipping attribute with no map entry - Acct-Output-Gigawords
rlm_couchbase: skipping attribute with no map entry - ERX-IPv6-Acct-Input-Octets
rlm_couchbase: skipping attribute with no map entry - ERX-IPv6-Acct-Output-Octets
rlm_couchbase: skipping attribute with no map entry - ERX-IPv6-Acct-Input-Packets
rlm_couchbase: skipping attribute with no map entry - ERX-IPv6-Acct-Output-Packets
rlm_couchbase: skipping attribute with no map entry - ERX-IPv6-Acct-Input-Gigawords
rlm_couchbase: skipping attribute with no map entry - ERX-IPv6-Acct-Output-Gigawords
rlm_couchbase: skipping attribute with no map entry - ERX-Tx-Connect-Speed
rlm_couchbase: skipping attribute with no map entry - Attr-26.4874.163
rlm_couchbase: skipping attribute with no map entry - ERX-Pppoe-Description
rlm_couchbase: skipping attribute with no map entry - NAS-IP-Address
rlm_couchbase: skipping attribute with no map entry - Stripped-User-Name
rlm_couchbase: skipping attribute with no map entry - Acct-Input-Octets64
rlm_couchbase: skipping attribute with no map entry - Acct-Output-Octets64
rlm_couchbase: skipping attribute with no map entry - Acct-Unique-Session-Id
rlm_couchbase (couchtsi): Released connection (0)
Need 10 more connections to reach 15 spares
rlm_couchbase (couchtsi): Opening additional connection (5), 1 of 15 pending slots used
32452ms [I15] {32348} [INFO] (instance - L:423) Version=2.8.3, Changeset=8ce52f9294cfef59b9ff44f3cfc18cc3ca8c2860
32452ms [I15] {32348} [INFO] (instance - L:424) Effective connection string: couchbase+explicit://10.0.2.207,/radius?. Bucket=radius
32452ms [I15] {32348} [DEBUG] (instance - L:284) Applying initial cntl detailed_errcodes=1
32566ms [I15] {32348} [INFO] (instance - L:137) DNS SRV lookup failed: DNS/Hostname lookup failed. Ignore this if not relying on DNS SRV records
32566ms [I15] {32348} [DEBUG] (instance - L:77) Adding host 10.0.2.207:8091 to initial HTTP bootstrap list
32566ms [I15] {32348} [DEBUG] (instance - L:77) Adding host 10.0.2.207:11210 to initial CCCP bootstrap list
32566ms [I15] {32348} [TRACE] (instance - L:117) Bootstrap hosts loaded (cccp:1, http:1)
32566ms [I15] {32348} [DEBUG] (confmon - L:85) Preparing providers (this may be called multiple times)
32566ms [I15] {32348} [DEBUG] (confmon - L:92) Provider CCCP is ENABLED
32566ms [I15] {32348} [DEBUG] (confmon - L:92) Provider HTTP is ENABLED
32566ms [I15] {32348} [TRACE] (confmon - L:272) Refreshing current cluster map
32566ms [I15] {32348} [TRACE] (confmon - L:259) Attempting to retrieve cluster map via CCCP
32566ms [I15] {32348} [INFO] (cccp - L:151) Requesting connection to node 10.0.2.207:11210 for CCCP configuration
32566ms [I15] {32348} [DEBUG] (lcbio_mgr - L:417) <10.0.2.207:11210> (HE=0x5652b2657c70) Creating new connection because none are available in the pool
32566ms [I15] {32348} [TRACE] (lcbio_mgr - L:328) <10.0.2.207:11210> (HE=0x5652b2657c70) New pool entry: I=0x5652b2658ed0
32566ms [I15] {32348} [INFO] (connection - L:467) <10.0.2.207:11210> (SOCK=0x5652b2659070) Starting. Timeout=2000000us
32566ms [I15] {32348} [DEBUG] (connection - L:232) <10.0.2.207:11210> (SOCK=0x5652b2659070) Created new socket with FD=25
32566ms [I15] {32348} [TRACE] (connection - L:333) <10.0.2.207:11210> (SOCK=0x5652b2659070) Scheduling I/O watcher for asynchronous connection completion.
32567ms [I15] {32348} [INFO] (connection - L:141) <10.0.2.207:11210> (SOCK=0x5652b2659070) Connected established
32567ms [I15] {32348} [DEBUG] (connection - L:100) <10.0.2.207:11210> (SOCK=0x5652b2659070) Successfully set TCP_NODELAY
32567ms [I15] {32348} [DEBUG] (connection - L:100) <10.0.2.207:11210> (SOCK=0x5652b2659070) Successfully set TCP_KEEPALIVE
32567ms [I15] {32348} [DEBUG] (lcbio_mgr - L:287) <10.0.2.207:11210> (HE=0x5652b2657c70) Received result for I=0x5652b2658ed0,C=(nil); E=0x0
32567ms [I15] {32348} [DEBUG] (lcbio_mgr - L:247) <10.0.2.207:11210> (HE=0x5652b2657c70) Assigning R=0x5652b2657d20 SOCKET=0x5652b2659070
32567ms [I15] {32348} [DEBUG] (ioctx - L:99) <10.0.2.207:11210> (CTX=0x5652b2659870,unknown) Pairing with SOCK=0x5652b2659070
32567ms [I15] {32348} [DEBUG] (negotiation - L:390) <10.0.2.207:11210> (CTX=0x5652b2659870,sasl,SASLREQ=0x5652b2659690) HELLO identificator: "libcouchbase/2.8.3"
32567ms [I15] {32348} [DEBUG] (negotiation - L:394) <10.0.2.207:11210> (CTX=0x5652b2659870,sasl,SASLREQ=0x5652b2659690) Request feature: 0x2 (TLS)
32567ms [I15] {32348} [DEBUG] (negotiation - L:394) <10.0.2.207:11210> (CTX=0x5652b2659870,sasl,SASLREQ=0x5652b2659690) Request feature: 0x6 (XATTR)
32567ms [I15] {32348} [DEBUG] (negotiation - L:394) <10.0.2.207:11210> (CTX=0x5652b2659870,sasl,SASLREQ=0x5652b2659690) Request feature: 0x8 (Select Bucket)
32567ms [I15] {32348} [DEBUG] (negotiation - L:394) <10.0.2.207:11210> (CTX=0x5652b2659870,sasl,SASLREQ=0x5652b2659690) Request feature: 0x7 (Error Map)
32567ms [I15] {32348} [DEBUG] (negotiation - L:394) <10.0.2.207:11210> (CTX=0x5652b2659870,sasl,SASLREQ=0x5652b2659690) Request feature: 0x3 (TCP NODELAY)
32567ms [I15] {32348} [DEBUG] (negotiation - L:420) <10.0.2.207:11210> (CTX=0x5652b2659870,sasl,SASLREQ=0x5652b2659690) Server supports feature: 0x3 (TCP NODELAY)
32567ms [I15] {32348} [TRACE] (negotiation - L:565) <10.0.2.207:11210> (CTX=0x5652b2659870,sasl,SASLREQ=0x5652b2659690) GET_ERRORMAP unsupported/disabled
32568ms [I15] {32348} [DEBUG] (ioctx - L:149) <10.0.2.207:11210> (CTX=0x5652b2659870,sasl) Destroying context. Pending Writes=0, Entered=true, Socket Refcount=1
32568ms [I15] {32348} [DEBUG] (ioctx - L:99) <10.0.2.207:11210> (CTX=0x5652b2661d80,unknown) Pairing with SOCK=0x5652b2659070
32568ms [I15] {32348} [DEBUG] (ioctx - L:149) <10.0.2.207:11210> (CTX=0x5652b2661d80,bc_cccp) Destroying context. Pending Writes=0, Entered=true, Socket Refcount=1
32568ms [I15] {32348} [INFO] (lcbio_mgr - L:467) <10.0.2.207:11210> (HE=0x5652b2657c70) Placing socket back into the pool. I=0x5652b2658ed0,C=0x5652b2659070
32569ms [I15] {32348} [INFO] (confmon - L:158) Setting new configuration. Received via CCCP
32569ms [I15] {32348} [DEBUG] (bootstrap - L:56) Instance configured
32569ms [I15] {32348} [DEBUG] (confmon - L:85) Preparing providers (this may be called multiple times)
32569ms [I15] {32348} [DEBUG] (confmon - L:92) Provider CCCP is ENABLED
(0) [couchtsi] = ok
(0) [ok] = ok
(0) } # accounting = ok
(0) Sent Accounting-Response Id 65 from 127.0.0.1:1813 to 127.0.0.1:55005 length 0
(0) Finished request
(0) Cleaning up request packet ID 65 with timestamp +31
Ready to process requests
**************************************************
cat /etc/raddb/mods-enabled/couchbase
couchbase {
server = "http://10.0.2.207:8091/pools"
bucket = "radius"
password = "PasswordString"
acct_key = "radacct_%{%{Acct-Unique-Session-Id}:-%{Acct-Session-Id}}"
doctype = "radacct"
expire = 2592000
update {
sessionId = 'Acct-Session-Id'
uniqueId = 'Acct-Unique-Session-Id'
lastStatus = 'Acct-Status-Type'
userName = 'User-Name'
lowercaseUser = 'Stripped-User-Name'
userDomain = 'Stripped-User-Domain'
nasIpAddress = 'NAS-IP-Address'
nasIdentifier = 'NAS-Identifier'
nasPort = 'NAS-Port-Id'
calledStationId = 'Called-Station-Id'
callingStationId = 'Calling-Station-Id'
framedIpAddress = 'Framed-IP-Address'
framedRoute = 'Framed-Route'
framedIpv6Address = 'Framed-IPv6-Prefix'
framedIpv6Id = 'Framed-Interface-Id'
framedV6Route = 'Delegated-IPv6-Prefix'
multiSessionId = 'Acct-Multi-Session-Id'
multiSessionCount = 'Acct-Link-Count'
TerminateCause = 'Acct-Terminate-Cause'
sessionTime = 'Acct-Session-Time'
lastUpdated = 'Event-Timestamp'
}
usage {
lastStatus = 'Acct-Status-Type'
timeStamp = 'Event-Timestamp'
download = 'Acct-Output-Octets64'
upload = 'Acct-Input-Octets64'
}
user_key = "raduser_%{md5:%{tolower:%{%{Stripped-User-Name}:-%{User-Name}}}}"
pool {
start = 5
min = 5
max = 20
spare = 15
uses = 0
lifetime = 0
idle_timeout = 1200
}
}
Thanks.
-Mike
More information about the Freeradius-Users
mailing list