[horde] Random user not authorized messages from Registry.php

[Per olof Ljungmark]

On 2013-07-11 03:16, Luis Felipe Marzagao wrote:
> Em 10-07-2013 18:55, Per olof Ljungmark escreveu:
>> On 2013-07-10 23:43, Andy Dorman wrote:
>>> On 07/10/2013 04:38 PM, l.kiraly at madalbal.hu wrote:
>>>> Hi Luis,
>>>>
>>>>
>>>> The user has to relog after this message?
>>>>
>>>>
>>>> Idézet (Luis Felipe Marzagao <lfbm.andamentos at gmail.com>):
>>>>
>>>>> Hello:
>>>>>
>>>>> Horde 5.1.1.
>>>>>
>>>>> I´m getting random 'user not authorized' msgs in my logs, like these:
>>>>>
>>>>> Jul 10 14:34:16 mserver HORDE: User is not authorized for horde [pid
>>>>> 1612 on line 267 of "/usr/share/php/Horde/Registry.php"]
>>>>> Jul 10 14:34:18 mserver HORDE: User is not authorized for horde [pid
>>>>> 1311 on line 267 of "/usr/share/php/Horde/Registry.php"]
>>>>> Jul 10 15:42:01 mserver HORDE: User is not authorized for horde [pid
>>>>> 2263 on line 270 of "/usr/share/php/Horde/Registry.php"]
>>>>> Jul 10 16:42:04 mserver HORDE: User is not authorized for horde [pid
>>>>> 2268 on line 270 of "/usr/share/php/Horde/Registry.php"]
>>>>>
>>>>> Apparently, they are harmless, since everybody is using horde and all
>>>>> the modules just fine. But I´d like to further investigate this.
>>>>>
>>>>> I´ve inserted Horde::debug($GLOBALS['registry']->getAuth()); in
>>>>> /usr/share/php/Horde/Registry.php to see what users were causing the
>>>>> problem, but it returned a false boolean, like this:
>>>>>
>>>>> 2013-07-10T18:42:01+00:00 DEBUG: Variable information:
>>>>> bool(false)
>>>>>
>>>>> Backtrace:
>>>>> 1. Horde_Registry::appInit() /var/www/horde/rampage.php:54
>>>>> 2. Horde::debug() /usr/share/php/Horde/Registry.php:268
>>>>>
>>>>>
>>>>> How can I further debug this? Any directions?
>>>>>
>>>>> Thanks.
>>>>> Luis Felipe
>>>>> -- 
>>>>> Horde mailing list
>>>>> Frequently Asked Questions: http://horde.org/faq/
>>>>> To unsubscribe, mail: horde-unsubscribe at lists.horde.org
>>> In our case the user does NOT have to relog after this message...in fact
>>> we have not yet seen any impact on the user.
>>>
>> You're not alone:
>>
>> http://www.google.se/search?num=50&site=&source=hp&q=%22User+is+not+authorized+for+horde%22&oq=%22User+is+not+authorized+for+horde%22&gs_l=hp.3..0i22i30l3j0i22i10i30j0i22i30l2.1642.4633.0.5943.3.3.0.0.0.0.133.346.1j2.3.0....0...1c.1.19.hp.vi1mt3l4y7o
>>
>>
>> "Not A Bug"
> 
> I think I found out what this is about, and in fact it's not a bug.
> 
> I've inserted a Horde::debug($GLOBALS['browser']->getIPAddress()); at
> line 1515 of /usr/share/php/Horde/Registry.php in order to see if it was
> really my opened session (from my browser) who was issuing the error.
> 
> And I got this:
> 
> 2013-07-11T00:32:46+00:00 DEBUG: Variable information:
> string(13) "66.249.75.151"
> 
> Backtrace:
> 1. Horde_Registry::appInit() /var/www/horde/rampage.php:54
> 2. Horde_Registry->pushApp() /usr/share/php/Horde/Registry.php:257
> 3. Horde::debug() /usr/share/php/Horde/Registry.php:1515
> 
> As you can see here [1], this IP (66.29.75.151) "is provided by the ISP
> Google which is the access point crawl-66-249-75-151.googlebot.com"
> 
> So, it looks like a google crawler is trying to directly access the page
> http://mydomain.com/rampage.php located on my webserver, which correctly
> rises the error, since an unauthorized user does not have permission to
> run this php file directly.
> 
> This is why it is random and in fact it has nothing to do with horde.
> 
> Now I'll go figure out how to stop this annoying bot to crawl my website.
> 
> See if you guys get similar results.

OK, I'll check here what causes it in our end. We do not see any
problems at all when this error is logged so it is probably similar.

But why must it be logged at EMERG? NOTICE or possibly WARN perhaps.

//per