So, whilst rooting around on one of our servers’s /var/log/*, I noticed that nslcd was attempting to look up, as usernames, apparently just regular strings appearing in previous lines of a log file. This behavior isn’t limited to nslcd interacting with a specific daemon.

To the GOOGLES, then! At least one other person On The Internets has experienced this, but no solutions were present there: http://old.nabble.com/Bug-505926%3A-command-%22tail-syslog-%7C-ccze%22-triggers-errors-in-nslcd-td20530700.html

What gives? The logs look like this:

Aug 31 10:19:08 nyc-dhcp dhcp/commit: Answer:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;; ->>HEADER<<- opcode: UPDATE, status: NOERROR, id:  58056
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;; flags: qr; ZONE: 1, PREREQ: 0, UPDATE: 2, ADDITIONAL: 1
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;; ZONE SECTION:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;AD-DOMAIN.com.#011#011#011IN#011SOA
Aug 31 10:19:08 nyc-dhcp dhcp/commit:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;; UPDATE SECTION:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: HOST-NAME-153.AD-DOMAIN.com.#0110#011ANY#011A#011
Aug 31 10:19:08 nyc-dhcp dhcp/commit: HOST-NAME-153.AD-DOMAIN.com.#0111800#011IN#011A#0111.2.3.40
Aug 31 10:19:08 nyc-dhcp dhcp/commit:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;; TSIG PSEUDOSECTION:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: 3487017774.sig-HOST-AD-DC-000.AD-DOMAIN.com. 0 ANY TSIG gss-tsig. 1346422748 36000 37 TSIG_SIG_TSIG_SIG_TSIG_SIG_TSIG_SIG 58056 NOERROR 0
Aug 31 10:19:08 nyc-dhcp dhcp/commit:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: Answer:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;; ->>HEADER<<- opcode: UPDATE, status: NOERROR, id:  37071
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;; flags: qr; ZONE: 1, PREREQ: 0, UPDATE: 2, ADDITIONAL: 1
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;; ZONE SECTION:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;3.2.1.in-addr.arpa.#011IN#011SOA
Aug 31 10:19:08 nyc-dhcp dhcp/commit:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;; UPDATE SECTION:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: 40.3.2.1.in-addr.arpa. 0#011ANY#011PTR#011
Aug 31 10:19:08 nyc-dhcp dhcp/commit: 40.3.2.1.in-addr.arpa. 1800 IN#011PTR#011HOST-NAME-153.AD-DOMAIN.com.
Aug 31 10:19:08 nyc-dhcp dhcp/commit:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: ;; TSIG PSEUDOSECTION:
Aug 31 10:19:08 nyc-dhcp dhcp/commit: 2881735749.sig-HOST-AD-DC-000.AD-DOMAIN.com. 0 ANY TSIG gss-tsig. 1346422748 36000 37 TSIG_SIG_TSIG_SIG_TSIG_SIG_TSIG_SIG 37071 NOERROR 0
Aug 31 10:19:08 nyc-dhcp dhcp/commit:
Aug 31 10:19:08 nyc-dhcp nslcd[20167]: [a00487] nslcd_passwd_byname(;;): invalid user name
Aug 31 10:19:08 nyc-dhcp nslcd[20167]: [cb1b60] nslcd_passwd_byname(->>header<<-): invalid user name
Aug 31 10:19:08 nyc-dhcp dhcpd: DHCPREQUEST for 1.2.3.40 (1.2.3.241) from 12:34:54:67:89:AB (HOST-NAME-MON1) via 1.2.3.2
Aug 31 10:19:08 nyc-dhcp dhcpd: DHCPACK on 1.2.3.40 to 12:34:54:67:89:AB (HOST-NAME-MON1) via 1.2.3.2
Aug 31 10:19:08 nyc-dhcp nslcd[20167]: [59648f] nslcd_passwd_byname(AD-DOMAIN.com.#011#011#011in#011soa): invalid user name
Aug 31 10:19:08 nyc-dhcp nslcd[20167]: [df331d] nslcd_passwd_byname(HOST-NAME-153.AD-DOMAIN.com.#0110#011any#011a#011): invalid user name
Aug 31 10:19:08 nyc-dhcp nslcd[20167]: [08a9e4] nslcd_passwd_byname(HOST-NAME-153.AD-DOMAIN.com.#0111800#011in#011a#0111.2.3.40): invalid user name
Aug 31 10:19:08 nyc-dhcp nslcd[20167]: [167394] nslcd_passwd_byname(TSIG_SIG_TSIG_SIG_TSIG_SIG_TSIG_SIG): invalid user name
Aug 31 10:19:08 nyc-dhcp nslcd[20167]: [21145c] nslcd_passwd_byname(3.2.1.in-addr.arpa.#011in#011soa): invalid user name
Aug 31 10:19:08 nyc-dhcp nslcd[20167]: [34dfe8] nslcd_passwd_byname(0#011any#011ptr#011): invalid user name
Aug 31 10:19:08 nyc-dhcp nslcd[20167]: [d22b79] nslcd_passwd_byname(in#011ptr#011HOST-NAME-153.AD-DOMAIN.com): invalid user name
Aug 31 10:19:08 nyc-dhcp nslcd[20167]: [37975e] nslcd_passwd_byname(TSIG_SIG_TSIG_SIG_TSIG_SIG_TSIG_SIG): invalid user name`

On the off-chance it was rsyslog doing massive amounts of GetPWName() style calls, tried with syslog-ng. Nope, same behavior. Something else is causing this insanity. Upgrading to nss-pam-ldapd 0.8.10 (latest from source, CentOS uses 0.7.15), the errors start looking like this, instead:

`2012-08-31T13:50:54.587921-04:00 HOST-NAME-016 Synergy 1.4.9: INFO: switch from "HOST-NAME-P2" to "HOST-NAME-016.AD-DOMAIN.com" at 2081,5
2012-08-31T13:50:54.588105-04:00 HOST-NAME-016 Synergy 1.4.9: INFO: entering screen
2012-08-31T13:50:54.615333-04:00 HOST-NAME-016 nslcd[29418] [eebeea] <passwd="2081,5"> request denied by validnames option
2012-08-31T13:50:54.628272-04:00 HOST-NAME-016 nslcd[29418] [65eb66] <passwd="passwd="2081,5"> request denied by validnames option
2012-08-31T13:50:54.649388-04:00 HOST-NAME-016 nslcd[29418] [ae65de] <passwd="passwd="passwd="2081,5"> request denied by validnames option
2012-08-31T13:50:54.655346-04:00 HOST-NAME-016 nslcd[29418] [13d013] <passwd="passwd="passwd="passwd="2081,5"> request denied by validnames option
2012-08-31T13:50:54.661263-04:00 HOST-NAME-016 nslcd[29418] [e0986f] <passwd="passwd="passwd="passwd="passwd=> request denied by validnames option
2012-08-31T13:50:54.667272-04:00 HOST-NAME-016 nslcd[29418] [4614f7] <passwd="passwd="passwd="passwd="passwd=> request denied by validnames option

The ‘validnames’ option is a new thing. Here’s a snippet of the man page on nslcd.conf about it:

validnames REGEX
This option can be used to specify how user and group names are verified within the system. This pattern is used to check all user and group names that are requested and returned from LDAP.
The regular expression should be specified as a POSIX extended regular expression. The expression itself needs to be separated by slash (/) characters and the 'i' flag may be appended at the end to indicate that the match should be case-insensetive.
The default value is /^[a-z0-9.<em>@$][a-z0-9.</em>@$ \~-]*[a-z0-9._@$~-]$/i

In the end, it ended up being a tool with which I was looking at the syslogs – ccze. CCZE is a colorizer. Part of the decision as to what colour things should have is CCZE doing username (aka GetPWNam()) lookup, causing all these shenanigans.

Observe, the observer effect at work.