Topic: Apache error_log is filling up to abnormal sizes ! (10GB / day)

[svsleuwen]

My customer runs on a SME-Server 7.4 with the latest updates installed.
They sync their Outlook via Funambol 7.04 with Egroupware 1.4.004 (latest contrib via contribs.org).
It needs php5-cgi contrib to sync via SyncML, that works well but generates an abnormaly amount of errors in the logs.
It seems that for every script line it generates an error line in the log!?

Can someone please guide me to a direction how to solve the error messages?
I have raised the error_logging level to critical so the logfiles don't grow to the size that the harddrives are completely full.
I want to lower it back again to "warn" when the problem is solved offcourse.
the load on the server is allso pretty huge every 15 minutes it goes to 50% CPU Load.

I have the same configuration of SME, Egroupware and PHP5-CGI with funambol sync on two other servers at other customers but they do not have these problems.
The syncyng itself goes perfectly so it is really hard to determine where the problem is coming from.

Below there is a piece of error_log from /var/log/httpd/
______________________________________________________

[Fri Mar 27 09:47:03 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML[syncml-4cdebff666ebac054eedd24fb1b20bba]: starting new session for sharon [on line 164 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML.php"]
[Fri Mar 27 09:47:03 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML[syncml-4cdebff666ebac054eedd24fb1b20bba]: create new session state variable [on line 170 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML.php"]
[Fri Mar 27 09:47:03 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML[syncml-4cdebff666ebac054eedd24fb1b20bba]: package 1 +++++++++++++++++++++ started [on line 214 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML.php"]
[Fri Mar 27 09:47:03 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML: Authentication not yet possible currently. Password not available [on line 259 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML/State_egw.php"]
[Fri Mar 27 09:47:04 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML_EGW: Authentication of sharon@default/syncml-4cdebff666ebac054eedd24fb1b20bba succeded [on line 273 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML/State_egw.php"]
[Fri Mar 27 09:47:04 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML[syncml-4cdebff666ebac054eedd24fb1b20bba]: found action commands <Alert> 1 [on line 495 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML.php"]
[Fri Mar 27 09:47:04 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML: create new sync for ./calendar 200 [on line 331 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML/Command/Alert.php"]
[Fri Mar 27 09:47:04 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML: new sync for alerttype 200 [on line 41 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML/Sync.php"]
[Fri Mar 27 09:47:04 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML: checking anchor targetLocURI: clientlast: 1238143320 / 1238143320 [on line 105 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML/Command/Alert.php"]

[Stefano]

hi

IMO you should check also EGW forums as it seems a EGW/funambol issue.

ciao
Stefano

[svsleuwen]

Dear Stefan, I have been busy with it last 4 days and yes I have been reading the forums at Egroupware and no the problem does not seem to be Egroupware only...
It seems that it has something to do with php or pear ?

I havent been succesfull in my search on google etc either.
I allways look at the other forums and this one BEFORE I post!

yes I'm getting a bit desperate, but I am really stuck....

[cactus]

It is a wild guess, but does the package have a debug option which might be (accidentally) turned on? The kind of messages look like debug messages to me.

[svsleuwen]

Offcourse that could be, But to make sure it mas not my foult I reinstalled Egroupware from the RPM provided on Contribs.
It sould replace the default config files, dont it?

I will have another go at looking in the egroupware forums to look at a debug option.
Thanks for your response!

I'll keep you informed!

[svsleuwen]

Dear Stefano,

I have changed PEAR_LOG_DEBUG to PEAR_LOG_INFO which reduced server load significantely but the error messages keep appearing??!
The Contrib for Egroupware 1.4.004 seems to have this setting as default (seems strange to me but maybe someone forgot to turn it off).
You can see where I got it from here: http://www.egroupware.org/index.php?page_name=sync&wikipage=SyncMLInstallHowTo
(It says so at the bottom of the page).
I have included some more logfile as it seems strange (to me) that there are even empty rules in this log.. (see the one above the bottom line)
_________________________________________

[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML[syncml-fd445702b0dd7f154aabca0990d86b53]: syncStatus(client sync started) 1 [on line 502 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML.php"]
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] EGWSYNC: [] SyncML: $this->_targetURI = ./calendar [on line 36 of "/opt/egroupware/html/phpgwapi/inc/horde/Horde/SyncML/Command/Sync.php"]
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] EGWSYNC: [egwcalendarsync] SymcML: egwcalendarsync search content: PD94bWwgdmVyc2lvbj0iMS4wIiBlbmNvZGluZz0iVVRGLTgiPz4KPGFwcG9pbnRtZW50Pgo8U0lGVmVyc2lvbj4xLjE8L1NJRlZlcnNpb24+CjxBbGxEYXlFdmVudD4wPC9BbGxEYXlFdmVudD4KPEJpbGxpbmdJbmZvcm1hdGlvbi8+CjxCb2R5Pg0KPC9Cb2R5Pgo8QnVzeVN0YXR1cz4yPC9CdXN5U3RhdHVzPgo8Q2F0ZWdvcmllcy8+CjxDb21wYW5pZXMvPgo8RW5kPjIwMDgwODI5VDIyMDAwMFo8L0VuZD4KPEZvbGRlcj5ERUZBVUxUX0ZPTERFUjwvRm9sZGVyPgo8SW1wb3J0YW5jZT4xPC9JbXBvcnRhbmNlPgo8SXNSZWN1cnJpbmc+MDwvSXNSZWN1cnJpbmc+CjxMb2NhdGlvbi8+CjxNZWV0aW5nU3RhdHVzPjA8L01lZXRpbmdTdGF0dXM+CjxNaWxlYWdlLz4KPE5vQWdpbmc+MDwvTm9BZ2luZz4KPFJlbWluZGVyTWludXRlc0JlZm9yZVN0YXJ0PjE1PC9SZW1pbmRlck1pbnV0ZXNCZWZvcmVTdGFydD4KPFJlbWluZGVyU2V0PjA8L1JlbWluZGVyU2V0Pgo8UmVtaW5kZXJTb3VuZEZpbGUvPgo8UmVwbHlUaW1lLz4KPFNlbnNpdGl2aXR5PjA8L1NlbnNpdGl2aXR5Pgo8U3RhcnQ+MjAwODA4MjlUMTEwMDAwWjwvU3RhcnQ+CjxTdWJqZWN0Pnp5ZGV2ZWxkIGZlZXN0PC9TdWJqZWN0Pgo8L2FwcG9pbnRtZW50Pg== contenttype: text/x-s4j-sife [on line 208 of "/opt/egroupware/html/syncml/calendar/lib/api.php"]
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] parseDateTime: 20080829T220000Z => Array
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] (
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [hour] => 22
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [minute] => 0
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [second] => 0
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [zone] => UTC
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] )
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] event end val=20080829T220000Z, parsed=1220047200
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] parseDateTime: 20080829T110000Z => Array
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] (
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [hour] => 11
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [minute] => 0
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [second] => 0
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [zone] => UTC
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] )
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] event start val=20080829T110000Z, parsed=1220007600

[cactus]

[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] parseDateTime: 20080829T220000Z => Array
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] (
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [hour] => 22
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [minute] => 0
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [second] => 0
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [zone] => UTC
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] )
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] event end val=20080829T220000Z, parsed=1220047200
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] parseDateTime: 20080829T110000Z => Array
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] (
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [hour] => 11
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [minute] => 0
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [second] => 0
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]     [zone] => UTC
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] )
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1]
[Fri Mar 27 09:47:50 2009] [error] [client 192.168.0.1] event start val=20080829T110000Z, parsed=1220007600

These are most likely caused by the php vardump function, which are often used in debug like messages.

[svsleuwen]

Hi Stefano,
Thanx that's good thinking!
how can I disable this?
Do I have to dive into the code of Egroupware? This should be strange becourse I use the default package from contribs.org
Is there a general setting in apache config that disables the output from this php function? (stupid question perhaps).

[Stefano]

[OT]svsleuwen: you should thank cactus, not me [/OT]

Ciao
Stefano

[svsleuwen]

Yes you are right, sorry Cactus and Stefano.
Thank you Cactus!

[gzartman]

Moving thread to SME 7.x Contribs, as it is more appropriate there.

[cactus]

Hi Stefano,
Thanx that's good thinking!
how can I disable this?
Do I have to dive into the code of Egroupware? This should be strange becourse I use the default package from contribs.org
Is there a general setting in apache config that disables the output from this php function? (stupid question perhaps).

More likely PHP than Apache although PHP is a package ran inside/on top off Apache. Are you sure you did not modify things by hand, not even in the past?
Can you show us the output of the following command:

Code: [Select]

pear config-show

[svsleuwen]

Dear cactus,

I am pretty sure I did not edit PHP by hand (as I am not a PHP Wizard).
Here is the output of " pear config-show ":
______________________________
Configuration (channel pear.php.net):
=====================================
Auto-discover new Channels     auto_discover    <not set>
Default Channel                default_channel  pear.php.net
HTTP Proxy Server Address      http_proxy       <not set>
PEAR server [DEPRECATED]       master_server    pear.php.net
Default Channel Mirror         preferred_mirror pear.php.net
Remote Configuration File      remote_config    <not set>
PEAR executables directory     bin_dir          /usr/bin
PEAR documentation directory   doc_dir          /usr/share/pear/doc
PHP extension directory        ext_dir          /usr/lib/php4
PEAR directory                 php_dir          /usr/share/pear
PEAR Installer cache directory cache_dir        /var/cache/php-pear
PEAR data directory            data_dir         /usr/share/pear/data
PHP CLI/CGI binary             php_bin          /usr/bin/php
PEAR test directory            test_dir         /usr/share/pear/test
Cache TimeToLive               cache_ttl        3600
Preferred Package State        preferred_state  stable
Unix file mask                 umask            22
Debug Log Level                verbose          1
PEAR password (for             password         <not set>
maintainers)
Signature Handling Program     sig_bin          /usr/bin/gpg
Signature Key Directory        sig_keydir       /etc/pearkeys
Signature Key Id               sig_keyid        <not set>
Package Signature Type         sig_type         gpg
PEAR username (for             username         <not set>
maintainers)
User Configuration File        Filename         /root/.pearrc
System Configuration File      Filename         /etc/pear.conf

[cactus]

Dear cactus,

I am pretty sure I did not edit PHP by hand (as I am not a PHP Wizard).
Here is the output of " pear config-show ":

Nothing strange in there... you have me puzzled. I am unfamiliar with egroupware as well as funambol so I think I have to take a rain check on this one unfortunately. I hope someone else can provide you with a clue to solve the issue.

[svsleuwen]

Could it have something to do with PHP5-CGI module that I have to use for SyncML??
I am just guessing, but I don't know what else could couse this..