Excessive LDAP log messages

[gig13]

Expected behavior
Suppress LDAP log messages that are not fatal when the log level is set to 4 (Fatal only). Report fatal errors with useful audit information so we can determine which user(s) are having issues.

Actual behavior
The log displays an excessive amount of bind failed:19: Constraint violation messages. These messages appear to be coming mostly from Windows Sync client users who's password's have recently changed, or are incorrect, or during network hiccups and the Windows sync client attempts to reconnect multiple times a second which locks their LDAP account. (An anti-DoS setting in LDAP server)

Steps to reproduce

1. Set the log level to 4 (Fatal only)
2. Setup a sync client for an LDAP user
3. Change password's for the LDAP user several times - observe the logs

Server Configuration
OS: RHEL6.6 x86_64
DB: MySQL 5.1.73-3.el6_5
PHP: php x86_64 5.3.3-38.el6 (Red Hat back ports security patches)

Log messages:

Oct 16 09:59:55 ldrive ownCloud[14461]: {user_ldap} Bind failed: 19: Constraint violation
Oct 16 09:59:55 ldrive ownCloud[14461]: {user_ldap} Bind failed: 19: Constraint violation
Oct 16 09:59:55 ldrive ownCloud[14809]: {user_ldap} Bind failed: 19: Constraint violation
Oct 16 09:59:56 ldrive ownCloud[14809]: {user_ldap} Bind failed: 19: Constraint violation
Oct 16 09:59:56 ldrive ownCloud[9618]: {user_ldap} Bind failed: 19: Constraint violation
Oct 16 09:59:56 ldrive ownCloud[9618]: {user_ldap} Bind failed: 19: Constraint violation
Oct 16 09:59:56 ldrive ownCloud[18988]: {user_ldap} Bind failed: 19: Constraint violation 

[karlitschek]

@blizzz

[blizzz]

The message is already level 3. Messages written to the log file are always at least level 3. I don't know the motiviation behind this, but most likely is to have errors available if something happens, which is valid IMHO.

cc @DeepDiver1975

[PVince81]

"Contraint violation" already seems like something bad.
Is there a way to prevent that message in the first place, if it's expected ?

[blizzz]

It actually is a bit bizarre that the servers replies with 19, since it actually is meant to be thrown in other use cases (writing to LDAP) which we do not do. 49 is usually the case when credentials are wrong, but that might be different on locked users on AD. We could catch this.

[cdamken]

I think is the same problem and scenario like: #9383

Instead 19 appears 49, but the same behavior. ..

The solution: I'll better make a cron to erase all lines.

[blizzz]

The problem is rather that the client does not ask for a new password, but retries again and again, see owncloud/client#2186

[gig13]

@MorrisJobke

[MorrisJobke]

@blizzz @dragotin Wasn't there also a issue that the client doesn't know if the LDAP server has gone, the password has changed or the password is correct and something other happened?

[MorrisJobke]

owncloud/client#2615 Is this related?

[MorrisJobke]

@blizzz The solution here is to catch erro 19 as well and don't log it?

[blizzz]

Honestly, I do not see a point to prevent it from being logged. Because next time, there will be a reporter complaining that user x cannot login and no information about the cause is written to the log file.

I can offer to move this from ERROR to WARN level, if that helps?

[cdamken]

@blizzz That was my wish list in #9383 😄

[MorrisJobke]

Fix is here: #13848