http://bugs.horde.org/ticket/12109

This has nothing to do with this ticket.  Please open a new ticket if 
you want to report.

Even with Horde_Core-2.4.3, the problem in some PHP installations is 
not fixed completely. Although the Addressbook now opens fine from the 
Horde portal, there still is an issue with messages that are being 
logged incorrectly.

Since the upgrade to Horde_Core-2.4.2, Horde is spamming my syslog 
with messages like

Mar 10 21:30:10 mail horde: [imp] Login success for arjen (Horde user 
arjen) [192.168.1.126] to {localhost:143 [imap]} [pid 3574 on line 183 
of "/srv/www/htdocs/horde/imp/lib/Auth.php"]

The above is from an ActiveSync client by the way and coincides with 
PING and SYNC messages in the webserver log.

I configured logging for level WARNING:

   $conf['log']['priority'] = 'WARNING';
   $conf['log']['ident'] = 'horde';
   $conf['log']['name'] = LOG_LOCAL7;
   $conf['log']['type'] = 'syslog';
   $conf['log']['enabled'] = true;

This message is logged with priority 'NOTICE' (I checked that), which 
is lower than the 'WARNING' threshold, so these messages should never 
have made it to the syslog.

The behaviour is as expected when downgrading to Horde_Core-2.4.1.

Mea culpa.  Was reading an incorrect/outdated version of the PHP manual.

Turns out that these error messages MUST fatally error out (which 
makes sense):

E_ERROR, E_PARSE, E_CORE_ERROR, E_CORE_WARNING, E_COMPILE_ERROR, 
E_COMPILE_WARNING

But these error messages don't trigger the user defined error handler 
anyway.  So that should not be an issue here.

As to the former - that is just an incorrect statement.  If hordeInit 
is non-empty, than injector MUST have been initialized.  Period.   
Anything else is a PHP bug.

And the latter is also an incorrect statement.  Absolutely no 
destruction goes on before a custom error handler is triggered.  If 
your custom error handler doesn't exit the script internally, PHP will 
continue to process the script.  Fatal errors are not fatal at the 
engine level; they are fatal at the error reporting level.

So let's call a spade a spade.  This fix is nothing more than a patch 
against broken PHP installations.  It has nothing to do with how we 
handle error reporting.

Yes, it does.

Hanns

Yes, it works for me again after that change to Horde.php.
Thanks!

Does that fix it?

Changes have been made in Git (master):

commit 7927bb3ef72f8acd48398737814a379f03c59229
Author: Jan Schneider <jan@horde.org>
Date:   Mon Mar 11 18:01:23 2013 +0100

     [jan] Fix error handler in some PHP versions (Bug #12103).

  framework/Core/package.xml |    4 ++--
  1 files changed, 2 insertions(+), 2 deletions(-)

http://git.horde.org/horde-git/-/commit/7927bb3ef72f8acd48398737814a379f03c59229

Changes have been made in Git (master):

commit ddb8342bb51c88af4cedce8b60857726c7671679
Author: Jan Schneider <jan@horde.org>
Date:   Mon Mar 11 17:59:17 2013 +0100

     Explicitly check if $injector exists (Bug #12103).

     Since this code is called directly from PHP as an error handler, 
we have no
     control when the code is called, and whether the injector has already been
     created or has already been destructed.

  framework/Core/lib/Horde.php |    3 ++-
  1 files changed, 2 insertions(+), 1 deletions(-)

http://git.horde.org/horde-git/-/commit/ddb8342bb51c88af4cedce8b60857726c7671679

Same error here on a Solaris server after pear upgrade today.
Server: Solaris 11.1, PHP 5.3.14 (Oracle Solaris php-53 package)

Packages upgraded:
upgrade ok: channel://pear.horde.org/Horde_Imap_Client-2.7.2
upgrade ok: channel://pear.horde.org/Horde_ActiveSync-2.3.2
upgrade ok: channel://pear.horde.org/Horde_Core-2.4.2

Error when accessing /turba/browse.php:

[Mon Mar 11 12:18:40 2013] [error] PHP Fatal error:  Call to a member 
function getInstance() on a non-object in /var/php/5.3/pear/Horde.php 
on line 76, referer: https://server.name/turba/
[Mon Mar 11 12:18:40 2013] [error] PHP Stack trace:, referer: 
https://server.name/turba/
[Mon Mar 11 12:18:40 2013] [error] PHP   1. 
Horde_ErrorHandler::errorHandler() 
/var/php/5.3/pear/Horde/ErrorHandler.php:0, referer: 
https://server.name/turba/
[Mon Mar 11 12:18:40 2013] [error] PHP   2. Horde::log() 
/var/php/5.3/pear/Horde/ErrorHandler.php:168, referer: 
https://server.name/turba/

All caches were cleared after the upgrade.

Never mind.  the script is correct.

Seeing as how autoloading might be an issue, might be a good idea to run the
horde-autoloader-cache-prune script (which should have been installed 
in the pear directory when Horde_Autoloader_Cache was installed).

Although looking at that script file - it won't correctly clear the 
cache if using local temp file caching.  That should be fixed.

If Horde_ErrorHandler can't be found, there is either a problem with 
your installation or a problem with your autoloader (i.e. a PHP issue).
FWIW, this is definitely not the log error from opening a turba 
addressbook.  This is a log error being generated by the portal page.

Except this is an incorrect statement.  Mike R has verified that at 
least two different versions of PHP 5.3 work fine.

Sure enough: as I predicted before, this IS a problem with people's 
PHP (because it is impossible under the PHP programming rules for this 
to occur).

Everyone needs to make sure they are NOT using an opcode cache (e.g. 
APC, xcache).  Bugs in that kind of software are exactly the kind of 
things that will cause these kind of unexplainable parsing errors.

I've attached the php.ini from CentOS's stock version of php. What can 
it  be wrong with it ? The only thing modified is the date.timezone 
variable.

According to phpinfo(), I have the following values:

     output_handler (no value)
     zlib.output_compression Off
     zlib.output_handler (no value)

The weird thing is, I have changed nothing in php.ini, yet PHP 5.3.22 
fails, but PHP 5.4.12 works.

I have to admit that I may be comparing apples with oranges here. The 
versions of PHP 5.3 (5.3.15 and 5.3.22) I was using so far came from a 
different repository than PHP 5.4.12, so there is a chance that they 
were built with different options.

This sounds like a configuration error in php.

Are you using output compression configured in php.ini or have some 
other value for output_handler() configured in your php.ini?

More accurately, it's about Horde code triggering a bug or 
misconfiguration in the php you are using.
FWIW, I use php 5.3.x from ubuntu and 5.3.x from MacPorts on my 
development machines. I am experiencing none of these problems.

I'm afraid this is indeed the case. I upgraded to PHP 5.4.12 too, 
which seems to work fine indeed.

While I agree that PHP 5.3.3 might be considered 'too old', PHP 5.3.22 
(which I was using so far) was only released a little over two weeks 
ago. I don't want to stand in the way of progress, but this would 
basically mean that PHP 5.4 would be a requirement from now on and PHP 
5.3 would no longer be supported.

I've managed  to make it work on a test system by upgrading the stock 
php 5.3.3 from CentOS (as I use CentOS on the production server) to 
5.4.12 from Remi's repository. So I  guess it's again about  the 
incompatibility between horde and php versions from different 
distributions.
No more errors  in apache logs, but only this in horde.log :

2013-03-10T13:59:54+02:00 WARN: HORDE [turba] PHP ERROR: Invalid 
argument supplied for foreach() [pid 8762 on line 314 of 
"/var/www/horde5/turba/lib/View/List.php"]
2013-03-10T13:59:54+02:00 WARN: HORDE [turba] PHP ERROR: Invalid 
argument supplied for foreach() [pid 8762 on line 314 of 
"/var/www/horde5/turba/lib/View/List.php"]

[trim]

The error messages on startup were caused by Xcache somehow. When 
enabled, it would only log these messages the first time after a 
server restart. Subsequent logins would not show this anymore. After 
disabling Xcache completely, there were no more of these messages. 
Until the original problem of this ticket is found, I'?l keep Xcache 
disabled.

These are still shown, although I doubt that the above stacktrace is 
really useful.

After installing php5-xdebug, I'm fanally getting somewhere. I see two 
different stacktraces popping up in the Apache logs.

When logging in, a whole bunch of minor variations of the following:

[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP Warning: 
  Invalid callback Horde_ErrorHandler::errorHandler, class 
'Horde_ErrorHandler' not found in /usr/share/php5/PEAR/PEAR/Config.php 
on line 650, referer: https://www.example.com/horde/login.php
[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP Stack 
trace:, referer: https://www.example.com/horde/login.php
[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP   1. 
{main}() /srv/www/htdocs/horde/services/portal/index.php:0, referer: 
https://www.example.com/horde/login.php
[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP   2. 
Horde_Registry::appInit() 
/srv/www/htdocs/horde/services/portal/index.php:15, referer: 
https://www.example.com/horde/login.php
[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP   3. 
Horde_Registry->pushApp() /usr/share/php5/PEAR/Horde/Registry.php:257, 
referer: https://www.example.com/horde/login.php
[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP   4. 
Horde_Core_LoginTasks->runTasks() 
/usr/share/php5/PEAR/Horde/Registry.php:1572, referer: 
https://www.example.com/horde/login.php
[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP   5. 
Horde_LoginTasks->runTasks() 
/usr/share/php5/PEAR/Horde/Core/LoginTasks.php:48, referer: 
https://www.example.com/horde/login.php
[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP   6. 
Horde_LoginTasks_Task_AdminCheck->execute() 
/usr/share/php5/PEAR/Horde/LoginTasks.php:211, referer: 
https://www.example.com/horde/login.php
[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP   7. 
Horde_Core_Db_Migration->__construct() 
/srv/www/htdocs/horde/lib/LoginTasks/Task/AdminCheck.php:61, referer: 
https://www.example.com/horde/login.php
[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP   8. 
Horde_Autoloader->loadClass() 
/usr/share/php5/PEAR/Horde/Autoloader.php:0, referer: 
https://www.example.com/horde/login.php
[Sun Mar 10 12:20:28 2013] [error] [client 192.168.1.121] PHP   9. 
Horde_Autoloader->_include() 
/usr/share/php5/PEAR/Horde/Autoloader.php:21, referer: 
https://www.example.com/horde/login.php

And when I open the addressbook, I get the following (much shorter) 
stacktrace:

[Sun Mar 10 12:21:07 2013] [error] [client 192.168.1.121] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/php5/PEAR/Horde.php on line 76, referer: 
https://www.example.com/horde/services/portal/index.php
[Sun Mar 10 12:21:07 2013] [error] [client 192.168.1.121] PHP Stack 
trace:, referer: https://www.example.com/horde/services/portal/index.php
[Sun Mar 10 12:21:07 2013] [error] [client 192.168.1.121] PHP   1. 
Horde_ErrorHandler::errorHandler() 
/usr/share/php5/PEAR/Horde/ErrorHandler.php:0, referer: 
https://www.example.com/horde/services/portal/index.php
[Sun Mar 10 12:21:07 2013] [error] [client 192.168.1.121] PHP   2. 
Horde::log() /usr/share/php5/PEAR/Horde/ErrorHandler.php:168, referer: 
https://www.example.com/horde/services/portal/index.php

I forgot to mention that if Horde::debug is uncommented, the following 
is logged in the Apache logs:

[Sun Mar 10 12:04:33 2013] [error] [client 192.168.1.121] PHP Fatal 
error:  ob_start(): Cannot use output buffering in output buffering 
display handlers in /usr/share/php5/PEAR/Horde.php on line 1524, 
referer: https://www.example.com/horde/services/portal/index.php

Of course, the page will be blank then.

I have no idea. But I really doubt that at least three different 
people have broken their PHP install in the same way.

I tried, but failed. The below is what is in my /usr/share/php5/PEAR/Horde.php

     73          /* Chicken/egg: we must wait until we have basic 
framework setup
     74           * before we can start logging. Otherwise, queue entries. */
     75          if (Horde_Core_Factory_Logger::available()) {
     76              if (empty($GLOBALS['injector'])) {
     77                  // Horde::debug('WTF???');
     78              } else {
     79                   
$GLOBALS['injector']->getInstance('Horde_Log_Logger')->log($event, 
$priority, $options);
     80              }
     81          } else {
     82              Horde_Core_Factory_Logger::queue($event, 
$priority, $options);
     83          }

If I uncomment the line with Horde::debug, it fails in the same way as 
the version from stock Horde_Core-2.4.2. I really have no idea how to 
force a backtrace here. It makes no difference if I use

     76              if (empty($GLOBALS['injector'])) {
or
     76              if (!is_object($GLOBALS['injector'])) {

In both cases a blank page is shown if I open the addressbook and 
leave the Horde::debug line uncommented.

I've alson tried that check and the same thing, horde_debug.txt is 
empty. /tmp directory is writeable by the httpd server, as the file is 
own by apache with 600 permissions.
Now it appears the following error in apache's log:

PHP Fatal error:  ob_start(): Cannot use output buffering in output 
buffering display handlers in /usr/share/pear/Horde.php on line 1522, 
referer: https://mail.autoadria.ro/services/portal/index.php

This truly makes zero sense.  Especially since no developer can reproduce.

Only one thing I can think of:
This is being called in a shutdown function so, for some reason, 
$GLOBALS['injector'] has already been destroyed.  But this doesn't 
make any sense because we Horde_Injector doesn't contain a 
__destruct() call.  And the global registry object still exists.

Somebody is going to have to provide some kind of backtrace for us to 
even begin to do anything else with this ticket.  Maybe injector is 
not empty?  So try replacing the empty($GLOBALS['injector']) check 
with a !is_object($GLOBALS['injector']) check.

     73          /* Chicken/egg: we must wait until we have basic 
framework setup
     74           * before we can start logging. Otherwise, queue entries. */
     75          if (Horde_Core_Factory_Logger::available()) {
     76              if (empty($GLOBALS['injector'])) {
     77                  Horde::debug('WTF???');
     78              }
     79               
$GLOBALS['injector']->getInstance('Horde_Log_Logger')->log($event, 
$priority, $options);
     80          } else {
     81              Horde_Core_Factory_Logger::queue($event, 
$priority, $options);
     82          }
# ls -l /tmp/horde_debug.txt
-rw------- 1 wwwrun www 0 Mar  9 19:19 /tmp/horde_debug.txt

I know it is writeable because a left-over Horde::debug statement in 
the ActiveSync code caused /tmp/horde_debug.txt to be spammed with 
messages a few weeks ago.

Now nothing is being logged.

That makes no sense either. Regardless, don't put it at the beginning 
of the method put it right after line 75 (inside the if statement) but 
before the $GLOBALS['injector']->getInstance(...... line.

Also, make sure your configured tmp directory is writable by the webserver.

With those lines inserted at the beginning of this function, I can't 
even login to Horde anymore (not even the login screen shows). Nothing 
is logged, not in /tmp/horde_debug.txt, nor in /tmp/horde.log.

Something along the lines of:

if (empty($GLOBALS['injector'])) {
     Horde::debug('WTF???');
}

will log the backtrace in a horde_debug.txt file located in your tmp 
directory. Though like MIchael S. said, the only way it can be empty 
is if PHP is behaving badly.

I'm seeing the same thing happening here too. If I change line 65 in 
/usr/share/php5/PEAR/Horde.php

from
         if (Horde_Core_Factory_Logger::available()) {
to
         if (isset($GLOBALS['injector']) && 
Horde_Core_Factory_Logger::available()) {

all is well again.

This check was performed in Horde_Core-2.4.1, but was removed in 
Horde_Core-2.4.2. So apparently the global injector value can be 
empty. I'd love to provide a backtrace, but I lack the knowledge how 
to. What code needs to be inserted here to provide a backtrace?

I'm using php5-5.3.22 by the way (the current openSUSE package).

Not sure what this has to do with anything.  Things can be messed up 
and you wouldn't know about it until code triggers it.  So changing 
code that causes it to trigger doesn't mean the new code is broken.

Anyway... I can't reproduce with Turba's browse.php.  So you need to 
debug WHY the global injector value is empty (since according to the 
code there appears to be no possible way this could happen).

Tried all that still no luck. I'm not using APC, only memcached. How 
can it be php messed up, if it used to work with the previous version 
of horde_core package.??

Otherwise, this makes absolutely zero sense.  The ONLY way for 
$registry->hordeInit to be non-empty is if it is set in 
Horde_Registry.  And injector is declared (and made global) 40 lines 
above it in that file.  So the other option is that your PHP is really 
messed up (restarting PHP might also be a good idea to clear any 
potential APC related issues).

Clear out your cache (Horde_Cache backend).  From command-line:

horde/bin/horde-clear-cache (might have to run as superuser/privileged 
user if your cache backend is owned by a different user than yours)

Doesn't help, still getting a blank page.

Sorry, it's in Core/Factory/Logger.php. Comment out either line 128 or 
line 148.

In what file is that function located ??  I don't see it in horde.php.

I'm not seeing this. I've tried all kinds of actions within Turba. Can 
you provide a backtrace?

I have a nagging suspicion that it's being caused by 
Horde_Core_Factory_Logger::processQueue(). If you comment out the 
register_shutdown_function() call, does this go away?

Replacing the horde.php file from horde_core-2.4.1 package seems to 
solve the problem.  So there is something wrong with the changes in   
the latest horde_core package.

Here are some errors in the httpd's log since the update:

[Sat Mar 09 05:18:20 2013] [error] [client xx.xx.xx.xx] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/pear/Horde.php on line 76, referer: https://xxx/imp/
[Sat Mar 09 05:18:23 2013] [error] [client xx.xx.xx.xx] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/pear/Horde.php on line 76, referer: https://xxx/imp/
[Sat Mar 09 05:18:25 2013] [error] [client xx.xx.xx.xx] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/pear/Horde.php on line 76, referer: https://xxx/imp/
[Sat Mar 09 05:18:56 2013] [error] [client xx.xx.xx.xx] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/pear/Horde.php on line 76, referer: https://xxx/imp/
[Sat Mar 09 05:21:09 2013] [error] [client xx.xx.xx.xx] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/pear/Horde.php on line 76, referer: 
https://mail.autoadria.ro/services/portal/
[Sat Mar 09 05:23:12 2013] [error] [client xx..xx.xx.xx] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/pear/Horde.php on line 76, referer: https://xxx/turba/
[Sat Mar 09 05:23:14 2013] [error] [client xx.xx.xx.xx] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/pear/Horde.php on line 76, referer: https://xxx/turba/
[Sat Mar 09 05:26:34 2013] [error] [client xx.xx.xx.xx] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/pear/Horde.php on line 76, referer: https://xxx/turba/
[Sat Mar 09 05:28:02 2013] [error] [client xx.xx.xx.xx] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/pear/Horde.php on line 76, referer: 
https://xxx/services/portal/
[Sat Mar 09 05:28:44 2013] [error] [client xx.xx.xx.xx] PHP Fatal 
error:  Call to a member function getInstance() on a non-object in 
/usr/share/pear/Horde.php on line 76, referer: 
https://xxx/turba/search.php

Hi. Since the latest update to horde_core package, I'm getting a blank 
page when I try to browse turba's address books. Other options like 
adding a new contact, searching for one seems to work. Also the 
autocompleter on IMP works too. I'm using a localsql backend for turba 
shares and also I've cleared the browser's cache and the horde cache, 
but still getting a blank page. In logs there is nothing about the 
error.