LCB_CNTL_SEND_HELLO setting not getting passed

Hi,

I’m currently setting up an application that needs to send to an old couchbase server that I do not manage. I am running libcouchbase 2.8.4 and I need to connect to a 2.5.1 couchbase server. After much searching and googling I found that the newer libraries send the HELLO before doing auth and that it can cause older servers to disconnect. So after reading documentation, I saw that it was possible to set LCB_CNTL_SEND_HELLO to false so that it wouldn’t pass the HELLO statement but it does not seem to work at all.

Can someone point me into the right direction?

I set my environmental settings as follows:

set|grep LCB
LCB_CNTL_DETAILED_ERRCODES=1
LCB_CNTL_SEND_HELLO=false
LCB_LOGLEVEL=5
LCB_OPTIONS=detailed_errcodes=1,send_hello=false

I also tried passing it via the connection string:

server = "couchbase://192.168.146.244:8091/pools?send_hello=false"

Here is the detailed output of the connection attempt:

1840ms [I4] {10064} [INFO] (instance - L:144) DNS SRV lookup failed: DNS/Hostname lookup failed. Ignore this if not relying on DNS SRV records
1840ms [I4] {10064} [DEBUG] (instance - L:83) Adding host 192.168.146.244:8091 to initial HTTP bootstrap list
1840ms [I4] {10064} [DEBUG] (instance - L:83) Adding host 192.168.146.244:11210 to initial CCCP bootstrap list
1840ms [I4] {10064} [TRACE] (instance - L:124) Bootstrap hosts loaded (cccp:1, http:1)
1840ms [I4] {10064} [DEBUG] (confmon - L:85) Preparing providers (this may be called multiple times)
1840ms [I4] {10064} [DEBUG] (confmon - L:92) Provider CCCP is ENABLED
1840ms [I4] {10064} [DEBUG] (confmon - L:92) Provider HTTP is ENABLED
1840ms [I4] {10064} [TRACE] (confmon - L:272) Refreshing current cluster map
1840ms [I4] {10064} [TRACE] (confmon - L:259) Attempting to retrieve cluster map via CCCP
1840ms [I4] {10064} [INFO] (cccp - L:151) Requesting connection to node 192.168.146.244:11210 for CCCP configuration
1840ms [I4] {10064} [DEBUG] (lcbio_mgr - L:443) <192.168.146.244:11210> (HE=0x55aec6f7cd70) Creating new connection because none are available in the pool
1840ms [I4] {10064} [TRACE] (lcbio_mgr - L:354) <192.168.146.244:11210> (HE=0x55aec6f7cd70) New pool entry: I=0x55aec6f7dff0
1840ms [I4] {10064} [INFO] (connection - L:467) <192.168.146.244:11210> (SOCK=0x55aec6f7e1b0) Starting. Timeout=2000000us
1840ms [I4] {10064} [DEBUG] (connection - L:232) <192.168.146.244:11210> (SOCK=0x55aec6f7e1b0) Created new socket with FD=7
1840ms [I4] {10064} [TRACE] (connection - L:333) <192.168.146.244:11210> (SOCK=0x55aec6f7e1b0) Scheduling I/O watcher for asynchronous connection completion.
1908ms [I4] {10064} [INFO] (connection - L:141) <192.168.146.244:11210> (SOCK=0x55aec6f7e1b0) Connected established
1908ms [I4] {10064} [DEBUG] (connection - L:100) <192.168.146.244:11210> (SOCK=0x55aec6f7e1b0) Successfully set TCP_NODELAY
1908ms [I4] {10064} [DEBUG] (connection - L:100) <192.168.146.244:11210> (SOCK=0x55aec6f7e1b0) Successfully set TCP_KEEPALIVE
1908ms [I4] {10064} [DEBUG] (lcbio_mgr - L:313) <192.168.146.244:11210> (HE=0x55aec6f7cd70) Received result for I=0x55aec6f7dff0,C=(nil); E=0x0
1908ms [I4] {10064} [DEBUG] (lcbio_mgr - L:273) <192.168.146.244:11210> (HE=0x55aec6f7cd70) Assigning R=0x55aec6f7df50 SOCKET=0x55aec6f7e1b0
1908ms [I4] {10064} [DEBUG] (ioctx - L:101) <192.168.146.244:11210> (CTX=0x55aec6f7e980,unknown) Pairing with SOCK=0x55aec6f7e1b0
1908ms [I4] {10064} [DEBUG] (negotiation - L:393) <192.168.146.244:11210> (CTX=0x55aec6f7e980,sasl,SASLREQ=0x55aec6f7e7a0) HELLO identificator: "libcouchbase/2.8.4 (Linux-4.14.5-300.fc27.x86_64; x86_64; GNU 4.8.5)"
1908ms [I4] {10064} [DEBUG] (negotiation - L:397) <192.168.146.244:11210> (CTX=0x55aec6f7e980,sasl,SASLREQ=0x55aec6f7e7a0) Request feature: 0x2 (TLS)
1908ms [I4] {10064} [DEBUG] (negotiation - L:397) <192.168.146.244:11210> (CTX=0x55aec6f7e980,sasl,SASLREQ=0x55aec6f7e7a0) Request feature: 0x6 (XATTR)
1908ms [I4] {10064} [DEBUG] (negotiation - L:397) <192.168.146.244:11210> (CTX=0x55aec6f7e980,sasl,SASLREQ=0x55aec6f7e7a0) Request feature: 0x8 (Select bucket)
1908ms [I4] {10064} [DEBUG] (negotiation - L:397) <192.168.146.244:11210> (CTX=0x55aec6f7e980,sasl,SASLREQ=0x55aec6f7e7a0) Request feature: 0x7 (XERROR)
1908ms [I4] {10064} [DEBUG] (negotiation - L:397) <192.168.146.244:11210> (CTX=0x55aec6f7e980,sasl,SASLREQ=0x55aec6f7e7a0) Request feature: 0x3 (TCP nodelay)
1976ms [I4] {10064} [ERROR] (negotiation - L:152) <192.168.146.244:11210> (CTX=0x55aec6f7e980,sasl,SASLREQ=0x55aec6f7e7a0) Error: 0x2d, IO Error
1976ms [I4] {10064} [ERROR] (cccp - L:165) <NOHOST:NOPORT> (CTX=(nil),) Could not get configuration: LCB_ESOCKSHUTDOWN (0x2D)
1976ms [I4] {10064} [INFO] (confmon - L:182) Provider 'CCCP' failed

Any help would be greatly appreciated.

-Mike

  1. The library does not recognize these environment variables:

     LCB_CNTL_DETAILED_ERRCODES=1
     LCB_CNTL_SEND_HELLO=false
    

    Where did you find that it should use them?

  2. You should use LCB_CNTL_SEND_HELLO control option. For example like this:

    lcb_error_t rc;
    int enabled = 0;
    
    rc = lcb_cntl(instance, LCB_CNTL_SET, LCB_CNTL_SEND_HELLO, &enabled);
    if (rc != LCB_SUCCESS) {
        fprintf(stderr, "failed to change option, rc=0x%02x (%s)", rc, lcb_strerror(instance, rc));
        exit(1);
    }
    

Hi,

Thanks for getting back to me. I have since downgraded my library to 2.7.1 from 2.8.4 to get it to work.

To answer your questions, I read through this forum post “Unable to connect to server since client 2.7.3” and I also consulted the documentation on the libcouchbase (http://docs.couchbase.com/sdk-api/couchbase-c-client-2.8.4/group__lcb-cntl-settings.html#gacfc8f5ad1e4d1f07eb6975cbb7b9989b) and I used google to try and figure out how to get the most debug output in order to pinpoint where the connection was failing.

It wasn’t very clear, at least to me, how I could stop the library from sending the hello. I use the library with freeradius so that I can send accounting to my couchbase server. I am not to sure yet how to implement what you suggested into freeradius configuration files.

the setting was not available through connection string. But I can add it in 2.8.5.

Another option here is to upgrade your couchbase server, as 2.5.1 is ancient version, and does not receive any fixes or support anymore.

Unfortunately, I don’t have visibility into the couchbase server. I have advised the group that owns it that they are running outdated version but I cannot wait for them to bring that up to date so that I can decommission my own old servers.

If you could add it to 2.8.5, I would be willing to test it and let you know of the outcome.

Thank you for your time and help.

@MrMike, I’ve just checked, and in fact no changes required. Everything should work and send_hello=false is picked up by library.

$ LCB_OPTIONS=send_hello=false cbc cp -vvvvv foo 2>&1 | grep HELLO
71ms [I0] {6603} [INFO] (negotiation - L:670) <127.0.0.1:11207> (CTX=0x55d68491d5d0,sasl,SASLREQ=0x55d68491bb30) HELLO negotiation disabled by user

The problem with your environment variable, is that you have used comma as separator, while the syntax should be the same as for connection string. Compare the following invocations.

With comma:

$ LCB_OPTIONS='detailed_errcodes=1,send_hello=false' cbc cp -vvvvv foo 2>&1 | grep 'Applying\|HELLO'
1ms [I0] {10320} [DEBUG] (instance - L:311) Applying initial cntl detailed_errcodes=1,send_hello=false
79ms [I0] {10320} [DEBUG] (negotiation - L:393) <127.0.0.1:11207> (CTX=0x55d905435830,sasl,SASLREQ=0x55d905433d90) HELLO identificator: "libcouchbase/2.8.4 (Linux-4.13.16-202.fc26.x86_64; x86_64; GNU 7.2.1)"

With ampersand:

$ LCB_OPTIONS='detailed_errcodes=1&send_hello=false' cbc cp -vvvvv foo 2>&1 | grep 'Applying\|HELLO'
1ms [I0] {10244} [DEBUG] (instance - L:311) Applying initial cntl detailed_errcodes=1
1ms [I0] {10244} [DEBUG] (instance - L:311) Applying initial cntl send_hello=false
62ms [I0] {10244} [INFO] (negotiation - L:670) <127.0.0.1:11207> (CTX=0x5572f26915b0,sasl,SASLREQ=0x5572f268fb10) HELLO negotiation disabled by user

Hi Sergey,

Is there a way for me to accomplish this directly from the connection string to the couchbase server?

Since I’m using the freeradius couchbase module I don’t think I can implement the code you’re suggesting.

yes, it is possible, and my previous post demonstrates it. also it shows the error you had when trying to switch it off.

I must be doing something wrong then.

In my couchbase module configuration I use this string to connect and send accounting information to couchbase from freeradius:

server = "http://10.0.2.207:8091/pools?detailed_errcodes=1&send_hello=false"

It seems like it has no effects because the connection still fails due to the Hello still being sent.

I will try adding the environment setting to the freeradius couchbase module to see if it works.

thanks again for your assistance.

Could you show libcouchbase logs?

Here is my couchbase file for freeradius:

couchbase {
        server = "couchbase://10.0.2.207:8091/pools?send_hello=false"
        bucket = "radius"
        password = "MYPASSWORDSTRING"
        acct_key = "radacct_%{%{Acct-Unique-Session-Id}:-%{Acct-Session-Id}}"
        doctype = "radacct"
        expire = 2592000

        update {
                Acct-Session-Id         = 'sessionId'
                Acct-Unique-Session-Id  = 'uniqueId'
                Acct-Status-Type        = 'lastStatus'
                User-Name               = 'userName'
                Stripped-User-Name      = 'lowercaseUser'
                Stripped-User-Domain    = 'UserDomain'
                NAS-IP-Address          = 'nasIpAddress'
                NAS-Identifier          = 'nasIdentifier'
                NAS-Port-Id             = 'nasPort'
                Called-Station-Id       = 'calledStationId'
                Calling-Station-Id      = 'callingStationId'
                Framed-IP-Address       = 'framedIpAddress'
                Framed-Route            = 'framedRoute'
                Framed-IPv6-Prefix      = 'framedIpv6Address'
                Framed-Interface-Id     = 'framedIpv6Id'
                Delegated-IPv6-Prefix   = 'framedV6Route'
                Acct-Multi-Session-Id   = 'multiSessionId'
                Acct-Link-Count         = 'multiSessionCount'
                Acct-Terminate-Cause    = 'TerminateCause'
                Acct-Session-Time       = 'sessionTime'
                Event-Timestamp         = 'lastUpdated'
        }

        usage {
                Acct-Status-Type        = 'lastStatus'
                Event-Timestamp         = 'timeStamp'
                Acct-Output-Octets64    = 'download'
                Acct-Input-Octets64     = 'upload'
        }

        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
        }
}

Here is the debug output for libcouchbase from radiusd when enabling LCB_LOGLEVEL=5

rlm_couchbase (couchbase): Opening additional connection (0), 1 of 20 pending slots used
0ms [I0] {20840} [INFO] (instance - L:450) Version=2.8.4, Changeset=c701796502dcabc846da5992964d828c426b264f
0ms [I0] {20840} [INFO] (instance - L:451) Effective connection string: couchbase+explicit://10.0.2.207,/radius?. Bucket=radius
127ms [I0] {20840} [INFO] (instance - L:144) DNS SRV lookup failed: DNS/Hostname lookup failed. Ignore this if not relying on DNS SRV records
127ms [I0] {20840} [DEBUG] (instance - L:83) Adding host 10.0.2.207:8091 to initial HTTP bootstrap list
127ms [I0] {20840} [DEBUG] (instance - L:83) Adding host 10.0.2.207:11210 to initial CCCP bootstrap list
127ms [I0] {20840} [TRACE] (instance - L:124) Bootstrap hosts loaded (cccp:1, http:1)
127ms [I0] {20840} [DEBUG] (confmon - L:85) Preparing providers (this may be called multiple times)
127ms [I0] {20840} [DEBUG] (confmon - L:92) Provider CCCP is ENABLED
127ms [I0] {20840} [DEBUG] (confmon - L:92) Provider HTTP is ENABLED
127ms [I0] {20840} [TRACE] (confmon - L:272) Refreshing current cluster map
127ms [I0] {20840} [TRACE] (confmon - L:259) Attempting to retrieve cluster map via CCCP
127ms [I0] {20840} [INFO] (cccp - L:151) Requesting connection to node 10.0.2.207:11210 for CCCP configuration
127ms [I0] {20840} [DEBUG] (lcbio_mgr - L:443) <10.0.2.207:11210> (HE=0x55671406ed90) Creating new connection because none are available in the pool
127ms [I0] {20840} [TRACE] (lcbio_mgr - L:354) <10.0.2.207:11210> (HE=0x55671406ed90) New pool entry: I=0x556714070080
127ms [I0] {20840} [INFO] (connection - L:467) <10.0.2.207:11210> (SOCK=0x556714070240) Starting. Timeout=2000000us
127ms [I0] {20840} [DEBUG] (connection - L:232) <10.0.2.207:11210> (SOCK=0x556714070240) Created new socket with FD=3
127ms [I0] {20840} [TRACE] (connection - L:333) <10.0.2.207:11210> (SOCK=0x556714070240) Scheduling I/O watcher for asynchronous connection completion.
178ms [I0] {20840} [INFO] (connection - L:141) <10.0.2.207:11210> (SOCK=0x556714070240) Connected established
178ms [I0] {20840} [DEBUG] (connection - L:100) <10.0.2.207:11210> (SOCK=0x556714070240) Successfully set TCP_NODELAY
178ms [I0] {20840} [DEBUG] (connection - L:100) <10.0.2.207:11210> (SOCK=0x556714070240) Successfully set TCP_KEEPALIVE
178ms [I0] {20840} [DEBUG] (lcbio_mgr - L:313) <10.0.2.207:11210> (HE=0x55671406ed90) Received result for I=0x556714070080,C=(nil); E=0x0
178ms [I0] {20840} [DEBUG] (lcbio_mgr - L:273) <10.0.2.207:11210> (HE=0x55671406ed90) Assigning R=0x55671406ee80 SOCKET=0x556714070240
178ms [I0] {20840} [DEBUG] (ioctx - L:101) <10.0.2.207:11210> (CTX=0x5567140709e0,unknown) Pairing with SOCK=0x556714070240
178ms [I0] {20840} [DEBUG] (negotiation - L:393) <10.0.2.207:11210> (CTX=0x5567140709e0,sasl,SASLREQ=0x556714070830) HELLO identificator: "libcouchbase/2.8.4 (Linux-4.14.5-300.fc27.x86_64; x86_64; GNU 4.8.5)"
178ms [I0] {20840} [DEBUG] (negotiation - L:397) <10.0.2.207:11210> (CTX=0x5567140709e0,sasl,SASLREQ=0x556714070830) Request feature: 0x2 (TLS)
178ms [I0] {20840} [DEBUG] (negotiation - L:397) <10.0.2.207:11210> (CTX=0x5567140709e0,sasl,SASLREQ=0x556714070830) Request feature: 0x6 (XATTR)
178ms [I0] {20840} [DEBUG] (negotiation - L:397) <10.0.2.207:11210> (CTX=0x5567140709e0,sasl,SASLREQ=0x556714070830) Request feature: 0x8 (Select bucket)
178ms [I0] {20840} [DEBUG] (negotiation - L:397) <10.0.2.207:11210> (CTX=0x5567140709e0,sasl,SASLREQ=0x556714070830) Request feature: 0x7 (XERROR)
178ms [I0] {20840} [DEBUG] (negotiation - L:397) <10.0.2.207:11210> (CTX=0x5567140709e0,sasl,SASLREQ=0x556714070830) Request feature: 0x3 (TCP nodelay)
228ms [I0] {20840} [INFO] (lcbio - L:112) Translating errno=0, lcb=0x2d to NETWORK_ERROR
228ms [I0] {20840} [ERROR] (negotiation - L:152) <10.0.2.207:11210> (CTX=0x5567140709e0,sasl,SASLREQ=0x556714070830) Error: 0x10, IO Error
228ms [I0] {20840} [ERROR] (cccp - L:165) <NOHOST:NOPORT> (CTX=(nil),) Could not get configuration: LCB_NETWORK_ERROR (0x10)
228ms [I0] {20840} [INFO] (confmon - L:182) Provider 'CCCP' failed
228ms [I0] {20840} [DEBUG] (confmon - L:223) Will try next provider in 0us
228ms [I0] {20840} [DEBUG] (ioctx - L:151) <10.0.2.207:11210> (CTX=0x5567140709e0,sasl) Destroying context. Pending Writes=0, Entered=false, Socket Refcount=1
228ms [I0] {20840} [TRACE] (confmon - L:259) Attempting to retrieve cluster map via HTTP
228ms [I0] {20840} [TRACE] (htconfig - L:346) Starting HTTP Configuration Provider 0x55671406dc30
228ms [I0] {20840} [INFO] (connection - L:467) <10.0.2.207:8091> (SOCK=0x55671406d110) Starting. Timeout=2000000us
228ms [I0] {20840} [DEBUG] (connection - L:232) <10.0.2.207:8091> (SOCK=0x55671406d110) Created new socket with FD=3
228ms [I0] {20840} [TRACE] (connection - L:333) <10.0.2.207:8091> (SOCK=0x55671406d110) Scheduling I/O watcher for asynchronous connection completion.
279ms [I0] {20840} [INFO] (connection - L:141) <10.0.2.207:8091> (SOCK=0x55671406d110) Connected established
279ms [I0] {20840} [DEBUG] (connection - L:100) <10.0.2.207:8091> (SOCK=0x55671406d110) Successfully set TCP_NODELAY
279ms [I0] {20840} [DEBUG] (connection - L:100) <10.0.2.207:8091> (SOCK=0x55671406d110) Successfully set TCP_KEEPALIVE
279ms [I0] {20840} [DEBUG] (htconfig - L:305) Successfuly connected to REST API 10.0.2.207:8091
279ms [I0] {20840} [DEBUG] (ioctx - L:101) <10.0.2.207:8091> (CTX=0x556714070170,unknown) Pairing with SOCK=0x55671406d110
329ms [I0] {20840} [TRACE] (htconfig - L:209) <10.0.2.207:8091> (CTX=0x556714070170,bc_http) Received 5992 bytes on HTTP stream
329ms [I0] {20840} [TRACE] (htconfig - L:209) <10.0.2.207:8091> (CTX=0x556714070170,bc_http) Received 1322 bytes on HTTP stream
330ms [I0] {20840} [DEBUG] (htconfig - L:224) <10.0.2.207:8091> (CTX=0x556714070170,bc_http) Generation 0 -> 1
330ms [I0] {20840} [INFO] (confmon - L:158) Setting new configuration. Received via HTTP
330ms [I0] {20840} [DEBUG] (bootstrap - L:56) Instance configured

I managed to get it to work by editing /etc/systemd/system/multi-user.target.wants/radiusd.service and adding this line in the Service section:

Environment=LCB_OPTIONS=send_hello=false

I consider this to be a workaround for now since I would prefer to have all configuration done via the couchbase module file in freeradius.

I don’t see that libcouchbase gets this environment variable. could you show log when send_hello=false specified in the connection string?

That log above is all I am getting. The connection string is also indicated above with
server = "couchbase://10.0.2.207:8091/pools?send_hello=false"

Seems to me like it’s ignored when sent to the server.

I might not have a choice but to set the environment in the radiusd systemd unit file. I will check with the freeradius devs to see if it is possible to add env settings for libcouchbase in their configuration file directly.

Do you use this module: rlm_couchbase (https://github.com/leprechau/rlm_couchbase)?

I found it uses old way to initialize the connection,

It might be related to systemd parser of the environment, could you try this one?

Environment=LCB_OPTIONS="send_hello=false"

or

Environment=LCB_OPTIONS='send_hello=false'

Hi,

That’s how I am currently able to get it to work. This is my radiusd service configuration:

cat /etc/systemd/system/multi-user.target.wants/radiusd.service

[Unit]
Description=FreeRADIUS high performance RADIUS server.
After=syslog.target network.target ipa.service dirsrv.target krb5kdc.service

[Service]
Environment=LCB_OPTIONS=send_hello=false
Environment=LCB_LOGLEVEL=5
Type=forking
PIDFile=/var/run/radiusd/radiusd.pid
ExecStartPre=-/bin/chown -R radiusd.radiusd /var/run/radiusd
ExecStartPre=/usr/sbin/radiusd -C
ExecStart=/usr/sbin/radiusd -d /etc/raddb
ExecReload=/usr/sbin/radiusd -C
ExecReload=/bin/kill -HUP $MAINPID

[Install]
WantedBy=multi-user.target

I was hoping to set everything I need in:

/etc/raddb/mods-available/couchbase

So what was the issue?

It was that I couldn’t pass it via the connection string with:

server = "couchbase://10.0.2.207:8091/pools?send_hello=false"

It took me a while to figure out that to get it to work I had to edit the radiusd.service systemd.

When looking at Unable to connect to server since client 2.7.3 thread, I was under the impression I could set the send_hello=false directly from there.

I hope that makes sense.