[horde] 160 per minute flood (was Re: Clarification of "User is not authorized for imp")

[Steffen]

On Tue, 30 Jul 2013, Michael M Slusarz wrote:

> Quoting Kareem Dana <kareem.dana at gmail.com>:
>
>> It is at the emergency level here and on my FreeBSD machine that also logs
>> to the system console which is quite annoying but I can change that with
>> syslog.
>> 
>> I believe, at least on my site, this will generate a lot of false positives
>> and it gives me no information that httpd-access.log doesn't give me
>> already since the log is generated right when a user connects to
>> "/horde/imp" before attempting to even login.
>
> Here's the problem... a user will NEVER go to /horde/imp by themselves if you 
> don't tell them to.  WHY would they go there?  We don't point anywhere there 
> in the code.  If a user is manually entering horde/imp, that sounds like an 
> issue to me.
>
> There's a login page.  That's what you should point your users to.  Yes, you 
> can't help users from bookmarking pages, but that is much less prevalent than 
> you think.

Today I was flooded with emergency messages on all windows, so that I 
couldn't actually do anything :-)

Apache access log:

10.20.146.41 - user [14/Feb/2014:13:51:28 +0100] "OPTIONS /horde/rpc.php/principals/ HTTP/1.1" 200 638 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:24.0) Gecko/20100101 Thunderbird/24.3.0 Lightning/2.6.4"

10.20.146.41 - user [14/Feb/2014:13:51:28 +0100] "PROPFIND /horde/rpc.php/principals/user/ HTTP/1.1" 200 638 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:24.0) Gecko/20100101 Thunderbird/24.3.0 Lightning/2.6.4"

Feb 14 13:51:00 mailsrv2 HORDE: [imp] Login success for user (Horde user user) [10.20.146.41] to {localhost:1143 [imap]} [pid 8237 on line 157 of "/var/www/horde/imp/lib/Auth.php"]
Feb 14 13:51:00 mailsrv2 HORDE: [imp] Login success for user (Horde user user) [10.20.146.41] to {localhost:1143 [imap]} [pid 8237 on line 157 of "/var/www/horde/imp/lib/Auth.php"]
Feb 14 13:51:00 mailsrv2 HORDE: [imp] Login success for user (Horde user user) [10.20.146.41] to {localhost:1143 [imap]} [pid 8237 on line 157 of "/var/www/horde/imp/lib/Auth.php"]
Feb 14 13:51:00 mailsrv2 HORDE: [horde] User is not authorized [pid 8237 on line 1547 of "/usr/share/php/Horde/Registry.php"]

There had been 160 errors per minute and those successful logins log 
entries before the "User is not ..." error, which does not contain the 
username. Er, sorry for the "Horde user user", I did replaced the real 
user with "user", because I was not able to reproduce the error and get 
some neutral log entries..

========

In order to avoid that flood on the console the next time, I've changed

class Horde_Exception_PushApp extends Horde_Exception_Wrapped
{
     public function __construct($message, $code, $app)
     {
         $this->application = $app;

         parent::__construct($message, $code);
 		$this->setLogLevel(3);		// make it ERROR priority
     }

}

It seems to do the trick, til next upgrade,
but I hope I haven't broken something else ;-)

Maybe, the default log level in "class Horde_Exception" should be 
customizable?

-- 
Steffen