[horde] Bad log level META

Mon Feb 20 17:55:20 UTC 2017

On 20 February 2017 at 17:50, Michael J Rubinsky <mrubinsk at horde.org> wrote:
>
> Quoting Simon B <simon.buongiorno at gmail.com>:
>
>> On 20 February 2017 at 16:58, Michael J Rubinsky <mrubinsk at horde.org>
>> wrote:
>>>
>>>
>>> Quoting Simon B <simon.buongiorno at gmail.com>:
>>>
>>>> Hi
>>>>
>>>> Since updating via git yesterday AM, ActiveSync has stopped working
>>>> (i.e. IMP is working fine).
>>>>
>>>> Attempting to to go to .../admin/activesync.php in the browser (to
>>>> clear the devices as my first troubleshooting step), give this error:
>>>>
>>>>
>>>>
>>>> A fatal error has occurred
>>>>
>>>> Bad log level META
>>>>
>>>
>>> Are you 100% sure you are up to date with git master? There were a few BC
>>> related fixes I committed after the main push that introduced these
>>> changes.
>>
>>
>> Hi Mike
>>
>> I ran it again this morning before sending the mail.  I even restarted
>> Apache after changing the logging requirement to false..
>
>
>
> I found and fixed an issue that would cause this when logging is turned off,
> or when the path is not writeable. Still not sure what would have caused
> this when logging was configured properly, or when viewing the admin page.
>
> Anyway, let me know if this gets you closer...

Git says it is up to date, but no change in behaviour.

Horde log still has the same errors..

Simon

>>>> in
>>>>
>>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync/Log/Logger/Deprecated.php:52
>>>>
>>>> 1. Horde_ActiveSync_SyncCache->__construct()
>>>> /usr/share/git-horde5/horde/admin/activesync.php:99
>>>> 2. Horde_ActiveSync_Log_Logger_Deprecated->meta()
>>>>
>>>>
>>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync/SyncCache.php:127
>>>> 3. Horde_ActiveSync_Log_Logger_Deprecated->__call()
>>>>
>>>>
>>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync/SyncCache.php:127
>>>>
>>>> Details
>>>>
>>>> The full error message is logged in Horde's log file, and is shown
>>>> below only to administrators. Non-administrative users will not see
>>>> error details.
>>>>
>>>> Horde_Log_Exception Object
>>>> (
>>>>     [details] =>
>>>>     [logged] => 1
>>>>     [_logLevel:protected] => 0
>>>>     [message:protected] => Bad log level META
>>>>     [string:Exception:private] =>
>>>>     [code:protected] => 0
>>>>     [file:protected] =>
>>>>
>>>>
>>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync/Log/Logger/Deprecated.php
>>>>     [line:protected] => 52
>>>>     [trace:Exception:private] => Array
>>>>
>>>>
>>>> Checking Horde's log file I find..
>>>>
>>>> 2017-02-20T11:09:49+00:00 ERR: HORDE-BETA Buffer contents:  [pid 16901
>>>> on line 165 of "/usr/share/php/Horde/Rpc/ActiveSync.php"]
>>>> 2017-02-20T11:09:50+00:00 ERR: HORDE-BETA Returning HTTP 500 while
>>>> handling Ping command. Error is: Bad log level INFO [pid 16886 on line
>>>> 163 of "/usr/share/git-horde5/horde/rpc.php"]
>>>> 2017-02-20T11:09:50+00:00 ERR: HORDE-BETA Error in communicating with
>>>> ActiveSync server: Bad log level INFO [pid 16886 on line 165 of
>>>> "/usr/share/php/Horde/Rpc/ActiveSync.php"]
>>>> 2017-02-20T11:09:50+00:00 ERR: HORDE-BETA #0
>>>>
>>>>
>>>> /usr/share/git-horde5/framework/Core/lib/Horde/Core/ActiveSync/Driver.php(201):
>>>> Horde_ActiveSync_Log_Logger->__call('info', Array)
>>>> #1
>>>>
>>>> /usr/share/git-horde5/framework/Core/lib/Horde/Core/ActiveSync/Driver.php(201):
>>>> Horde_ActiveSync_Log_Logger->info('----------Horde...')
>>>> #2
>>>>
>>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync.php(578):
>>>> Horde_Core_ActiveSync_Driver->authenticate('username at server.n...',
>>>> 'MungedPassw...', NULL)
>>>> #3
>>>>
>>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync.php(753):
>>>> Horde_ActiveSync->authenticate(Object(Horde_ActiveSync_Credentials))
>>>> #4 /usr/share/php/Horde/Rpc/ActiveSync.php(143):
>>>> Horde_ActiveSync->handleRequest('Ping', 'ADUMD67L3135B8D...')
>>>> #5 /usr/share/git-horde5/horde/rpc.php(163):
>>>> Horde_Rpc_ActiveSync->getResponse(NULL)
>>>> #6 {main} [pid 16886 on line 165 of
>>>> "/usr/share/php/Horde/Rpc/ActiveSync.php"]
>>>> 2017-02-20T11:09:50+00:00 ERR: HORDE-BETA Buffer contents:  [pid 16886
>>>> on line 165 of "/usr/share/php/Horde/Rpc/ActiveSync.php"]
>>>> 2017-02-20T11:10:46+00:00 ERR: HORDE-BETA Returning HTTP 500 while
>>>> handling Ping command. Error is: Bad log level INFO [pid 16806 on line
>>>> 163 of "/usr/share/git-horde5/horde/rpc.php"]
>>>> 2017-02-20T11:10:46+00:00 ERR: HORDE-BETA Error in communicating with
>>>> ActiveSync server: Bad log level INFO [pid 16806 on line 165 of
>>>> "/usr/share/php/Horde/Rpc/ActiveSync.php"]
>>>> 2017-02-20T11:10:46+00:00 ERR: HORDE-BETA #0
>>>>
>>>>
>>>> /usr/share/git-horde5/framework/Core/lib/Horde/Core/ActiveSync/Driver.php(201):
>>>> Horde_ActiveSync_Log_Logger->__call('info', Array)
>>>> #1
>>>>
>>>> /usr/share/git-horde5/framework/Core/lib/Horde/Core/ActiveSync/Driver.php(201):
>>>> Horde_ActiveSync_Log_Logger->info('----------Horde...')
>>>> #2
>>>>
>>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync.php(578):
>>>> Horde_Core_ActiveSync_Driver->authenticate('username at server.n...',
>>>> 'MungedPassw...', NULL)
>>>> #3
>>>>
>>>> /usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync.php(753):
>>>> Horde_ActiveSync->authenticate(Object(Horde_ActiveSync_Credentials))
>>>> #4 /usr/share/php/Horde/Rpc/ActiveSync.php(143):
>>>> Horde_ActiveSync->handleRequest('Ping', '4e696e654339383...')
>>>> #5 /usr/share/git-horde5/horde/rpc.php(163):
>>>> Horde_Rpc_ActiveSync->getResponse(NULL)
>>>> #6 {main} [pid 16806 on line 165 of
>>>> "/usr/share/php/Horde/Rpc/ActiveSync.php"]
>>>> 2017-02-20T11:10:46+00:00 ERR: HORDE-BETA Buffer contents:  [pid 16806
>>>> on line 165 of "/usr/share/php/Horde/Rpc/ActiveSync.php"]
>>>> 2017-02-20T11:11:40+00:00 EMERG: HORDE-BETA [horde] Bad log level META
>>>> [pid 16886 on line 52 of
>>>>
>>>>
>>>> "/usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync/Log/Logger/Deprecated.php"]
>>>> 2017-02-20T11:12:39+00:00 EMERG: HORDE-BETA [horde] Bad log level META
>>>> [pid 27612 on line 52 of
>>>>
>>>>
>>>> "/usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync/Log/Logger/Deprecated.php"]
>>>> 2017-02-20T11:18:28+00:00 EMERG: HORDE-BETA [horde] Bad log level META
>>>> [pid 16880 on line 52 of
>>>>
>>>>
>>>> "/usr/share/git-horde5/framework/ActiveSync/lib/Horde/ActiveSync/Log/Logger/Deprecated.php"]
>>>>
>>>> I reran the git update commands:
>>>> cd /usr/share/git-horde5
>>>> # update the channel
>>>> pear channel-update pear.horde.org
>>>> # do the pull
>>>> git pull  1>&2 >> git.pull.log
>>>> php ./framework/bin/install_dev
>>>>
>>>> But the problem persists..
>>>>
>>>> The log file directory is 660 for www-data, so that shouldn't be an
>>>> issue.
>>>>
>>>> The conf.php active sync entries are:
>>>>
>>>> $conf['activesync']['params']['driverconfig'] = 'horde';
>>>> $conf['activesync']['storage'] = 'Sql';
>>>> $conf['activesync']['no_maillogsync'] = false;
>>>> $conf['activesync']['emailsync'] = true;
>>>> $conf['activesync']['version'] = '16.0';
>>>> $conf['activesync']['auth']['type'] = 'basic';
>>>> $conf['activesync']['autodiscovery'] = 'full';
>>>> $conf['activesync']['hosts']['imap']['host'] = 'mail.server.net';
>>>> $conf['activesync']['hosts']['imap']['port'] = 143;
>>>> $conf['activesync']['hosts']['imap']['encryption'] = 'TLS';
>>>> $conf['activesync']['hosts']['pop']['encryption'] = 'TLS';
>>>> $conf['activesync']['hosts']['smtp']['host'] = 'mail.server.net';
>>>> $conf['activesync']['hosts']['smtp']['port'] = 587;
>>>> $conf['activesync']['hosts']['smtp']['popauth'] = false;
>>>> $conf['activesync']['hosts']['smtp']['encryption'] = 'TLS';
>>>> $conf['activesync']['outlookdiscovery'] = true;
>>>> $conf['activesync']['logging']['path'] = '/var/log/horde/sync/beta/';
>>>> $conf['activesync']['logging']['level'] = '2';
>>>> $conf['activesync']['logging']['type'] = 'perdevice';
>>>> $conf['activesync']['ping']['heartbeatmin'] = 60;
>>>> $conf['activesync']['ping']['heartbeatmax'] = 2700;
>>>> $conf['activesync']['ping']['heartbeatdefault'] = 480;
>>>> $conf['activesync']['ping']['deviceping'] = true;
>>>> $conf['activesync']['ping']['waitinterval'] = 5;
>>>> $conf['activesync']['ping']['maximumwindowsize'] = 0;
>>>> $conf['activesync']['ping']['maximumrequestwindowsize'] = 0;
>>>> $conf['activesync']['enabled'] = true;
>>>>
>>>> I tried to disable the logging but that doesn't change anything either..
>>>>
>>>> Any ideas?
>>>>
>>>> Thanks.
>>>>
>>>> Simon
>>>> --
>>>> Horde mailing list
>>>> Frequently Asked Questions: http://horde.org/faq/
>>>> To unsubscribe, mail: horde-unsubscribe at lists.horde.org
>>>
>>>
>>>
>>>
>>>
>>> --
>>> mike
>>> The Horde Project
>>> http://www.horde.org
>>> https://www.facebook.com/hordeproject
>>> https://www.twitter.com/hordeproject
>>>
>>> --
>>> Horde mailing list
>>> Frequently Asked Questions: http://horde.org/faq/
>>> To unsubscribe, mail: horde-unsubscribe at lists.horde.org
>>>
>
>
>
> --
> mike
> The Horde Project
> http://www.horde.org
> https://www.facebook.com/hordeproject
> https://www.twitter.com/hordeproject