View Issue Details

IDProjectCategoryView StatusLast Update
0013774Tine 2.0Tinebasepublic2018-04-19 20:31
ReporterbammesAssigned Topmehrer 
PrioritynormalSeveritymajorReproducibilityalways
Status newResolutionopen 
Product Version2018.02.1 Community Edition 
Target VersionFixed in Version 
Summary0013774: since 2018.02.1, the regular maintenance cronjobs dont die and accumulate until there is no more free memory left
DescriptionThe regular maintenance Cronjobs get stuck with the following queries hanging until the database-connection times out:

Crontab:
*/5 * * * * www /usr/local/bin/php -d include_path=.:/usr/local/www/calendar.example.com:/usr/local/www/calendar.example.com/library /usr/local/www/calendar.example.com/tine20.php --method Tinebase.triggerAsyncEvents

Queries:
4879 calendar www-1 calendar 2 Query UPDATE `tine20_container` SET `content_seq` = (CASE WHEN `content_seq` >= 1 THEN `content_seq` + 1 ELSE 1 END) WHERE (`id` = '46')
5532 calendar www-1 calendar 2 Query UPDATE `tine20_container` SET `content_seq` = (CASE WHEN `content_seq` >= 1 THEN `content_seq` + 1 ELSE 1 END) WHERE (`id` = '46')
5190 calendar www-1 calendar 3 Query UPDATE `tine20_container` SET `content_seq` = (CASE WHEN `content_seq` >= 1 THEN `content_seq` + 1 ELSE 1 END) WHERE (`id` = '46')
5679 calendar www-1 calendar 3 Query UPDATE `tine20_container` SET `content_seq` = (CASE WHEN `content_seq` >= 1 THEN `content_seq` + 1 ELSE 1 END) WHERE (`id` = '46')
5797 calendar www-1 calendar 3 Query UPDATE `tine20_container` SET `content_seq` = (CASE WHEN `content_seq` >= 1 THEN `content_seq` + 1 ELSE 1 END) WHERE (`id` = '46')
3440 calendar www-1 calendar 4 Query UPDATE `tine20_container` SET `content_seq` = (CASE WHEN `content_seq` >= 1 THEN `content_seq` + 1 ELSE 1 END) WHERE (`id` = '46')
3911 calendar www-1 calendar 4 Query UPDATE `tine20_container` SET `content_seq` = (CASE WHEN `content_seq` >= 1 THEN `content_seq` + 1 ELSE 1 END) WHERE (`id` = '46')
4383 calendar www-1 calendar 4 Query UPDATE `tine20_container` SET `content_seq` = (CASE WHEN `content_seq` >= 1 THEN `content_seq` + 1 ELSE 1 END) WHERE (`id` = '46')
5039 calendar www-1 calendar 4 Query UPDATE `tine20_container` SET `content_seq` = (CASE WHEN `content_seq` >= 1 THEN `content_seq` + 1 ELSE 1 END) WHERE (`id` = '46')
5375 calendar www-1 calendar 4 Query UPDATE `tine20_container` SET `content_seq` = (CASE WHEN `content_seq` >= 1 THEN `content_seq` + 1 ELSE 1 END) WHERE (`id` = '46')


log is full of these entries:

f0388 cronuser - 2018-02-22T20:05:00+00:00 WARN (4): Tinebase_Backend_Scheduler::cleanZombieTasks::121 cleaning up zombie scheduler task: Array
(
    [id] => dd790704ab9e121b7038001785b94959d00d7687
    [name] => Calendar_Controller_Event::updateConstraintsExdates
    [config] => {"cron":"0 0 * * *","callables":[{"controller":"Calendar_Controller_Event","method":"updateConstraintsExdates"}]}
    [last_run] => 2018-02-21 00:15:02
    [last_duration] => 1337
    [lock_id] => Tinebase_Backend_Scheduler::markTaskRunning::1b6b343531048164cee8e75b1c1bda8c61a0272b
    [next_run] => 2018-02-22 00:00:00
    [last_failure] =>
    [failure_count] => 0
    [server_time] => 2018-02-22 20:05:00
)
TagsNo tags attached.
mwticket

Activities

bammes

bammes

2018-02-27 16:23

reporter   ~0021464

Looks like this is some deadlock when multiple cronjobs run at the same time.
I just solved this for me, using this simple bash-wrapper:

Please note, that from time to time, it takes an excessive amount of time for the cronjob to finish (up to 10 hours). This looks like something is broken.

#!/usr/local/bin/bash
LOCKFILE="/tmp/tine20async.lock"
LOGGER="/usr/bin/logger -t tine20async"
if [ ! -e $LOCKFILE ]; then
        date > $LOCKFILE
        echo "starting triggerAsyncEvents" | $LOGGER
        command="/usr/local/bin/php -d include_path=.:/usr/local/www/calendar.postadigitale.de:/usr/local/www/calendar.postadigitale.de/library /usr/local/www/calendar.postadigitale.de/tine20.php --method Tinebase.triggerAsyncEvents"
        echo $command | $LOGGER
        { time $command ; } 2>&1 | $LOGGER
        echo "finished triggerAsyncEvents" | $LOGGER
        rm $LOCKFILE
else
        echo "another instance still running" | $LOGGER
fi
pmehrer

pmehrer

2018-03-13 21:26

developer   ~0021506

there are two problems here: one with the scheduler (the call to Tinebase.triggerAsyncEvents) and you worked around it.

the second problem is that Calendar_Controller_Event::updateConstraintsExdates seems to get stuck. Lets work on that first: Can you provide logs from one of theose 10 hours runs? like
grep 'cronuser' ....../logfile
bammes

bammes

2018-03-14 12:22

reporter   ~0021514

I am sorry, with the implementation of this semaphore-like mechanism, the problem disappeared after about half a week and unfortunately logrotate did its job...
If I ever see this problem again, I will let you know!
bammes

bammes

2018-03-14 12:28

reporter   ~0021516

Short analysis of what I have in my general syslog right now shows only one occurence today with 629 minutes.
I will raise the loglevel again and keep you posted.


root@www-1:~ # bzgrep tine20async /var/log/messages | grep real
Mar 13 13:05:00 www-1 tine20async: real 0m0.664s
Mar 13 13:10:00 www-1 tine20async: real 0m0.730s
Mar 13 13:15:00 www-1 tine20async: real 0m0.683s
Mar 13 13:20:01 www-1 tine20async: real 0m1.668s
Mar 13 13:25:01 www-1 tine20async: real 0m1.080s
Mar 13 13:30:01 www-1 tine20async: real 0m1.955s
Mar 13 13:35:00 www-1 tine20async: real 0m0.742s
Mar 13 13:40:01 www-1 tine20async: real 0m1.003s
Mar 13 13:45:01 www-1 tine20async: real 0m1.849s
Mar 13 13:50:00 www-1 tine20async: real 0m0.699s
Mar 13 13:55:00 www-1 tine20async: real 0m0.596s
Mar 13 14:00:03 www-1 tine20async: real 0m3.037s
Mar 13 14:05:00 www-1 tine20async: real 0m0.556s
Mar 13 14:10:00 www-1 tine20async: real 0m0.956s
Mar 13 14:15:00 www-1 tine20async: real 0m0.576s
Mar 13 14:20:01 www-1 tine20async: real 0m1.048s
Mar 13 14:25:01 www-1 tine20async: real 0m1.127s
Mar 13 14:30:01 www-1 tine20async: real 0m1.413s
Mar 13 14:35:00 www-1 tine20async: real 0m0.556s
Mar 13 14:40:01 www-1 tine20async: real 0m1.333s
Mar 13 14:45:04 www-1 tine20async: real 0m4.234s
Mar 13 14:50:02 www-1 tine20async: real 0m2.464s
Mar 13 14:55:00 www-1 tine20async: real 0m0.708s
Mar 13 15:00:07 www-1 tine20async: real 0m7.882s
Mar 13 15:05:00 www-1 tine20async: real 0m0.765s
Mar 13 15:10:00 www-1 tine20async: real 0m0.749s
Mar 13 15:15:00 www-1 tine20async: real 0m0.845s
Mar 13 15:20:01 www-1 tine20async: real 0m0.992s
Mar 13 15:25:01 www-1 tine20async: real 0m1.516s
Mar 13 15:30:01 www-1 tine20async: real 0m0.987s
Mar 13 15:35:00 www-1 tine20async: real 0m0.841s
Mar 13 15:40:00 www-1 tine20async: real 0m0.954s
Mar 13 15:45:00 www-1 tine20async: real 0m0.729s
Mar 13 15:50:00 www-1 tine20async: real 0m0.716s
Mar 13 15:55:00 www-1 tine20async: real 0m0.611s
Mar 13 16:00:01 www-1 tine20async: real 0m1.609s
Mar 13 16:05:00 www-1 tine20async: real 0m0.660s
Mar 13 16:10:00 www-1 tine20async: real 0m0.642s
Mar 13 16:15:00 www-1 tine20async: real 0m0.605s
Mar 13 16:20:09 www-1 tine20async: real 0m9.541s
Mar 13 16:25:01 www-1 tine20async: real 0m1.136s
Mar 13 16:30:01 www-1 tine20async: real 0m1.804s
Mar 13 16:35:00 www-1 tine20async: real 0m0.554s
Mar 13 16:40:00 www-1 tine20async: real 0m0.508s
Mar 13 16:45:00 www-1 tine20async: real 0m0.899s
Mar 13 16:50:01 www-1 tine20async: real 0m1.851s
Mar 13 16:55:01 www-1 tine20async: real 0m1.090s
Mar 13 17:00:01 www-1 tine20async: real 0m1.483s
Mar 13 17:05:00 www-1 tine20async: real 0m0.872s
Mar 13 17:10:00 www-1 tine20async: real 0m0.658s
Mar 13 17:15:00 www-1 tine20async: real 0m0.464s
Mar 13 17:20:00 www-1 tine20async: real 0m0.608s
Mar 13 17:25:00 www-1 tine20async: real 0m0.760s
Mar 13 17:30:00 www-1 tine20async: real 0m0.958s
Mar 13 17:35:00 www-1 tine20async: real 0m0.659s
Mar 13 17:40:00 www-1 tine20async: real 0m0.647s
Mar 13 17:45:00 www-1 tine20async: real 0m0.664s
Mar 13 17:50:00 www-1 tine20async: real 0m0.927s
Mar 13 17:55:00 www-1 tine20async: real 0m0.641s
Mar 13 18:00:05 www-1 tine20async: real 0m5.344s
Mar 13 18:05:00 www-1 tine20async: real 0m0.462s
Mar 13 18:10:00 www-1 tine20async: real 0m0.779s
Mar 13 18:15:00 www-1 tine20async: real 0m0.739s
Mar 13 18:20:03 www-1 tine20async: real 0m3.392s
Mar 13 18:25:00 www-1 tine20async: real 0m0.794s
Mar 13 18:30:00 www-1 tine20async: real 0m0.702s
Mar 13 18:35:00 www-1 tine20async: real 0m0.798s
Mar 13 18:40:00 www-1 tine20async: real 0m0.668s
Mar 13 18:45:01 www-1 tine20async: real 0m1.910s
Mar 13 18:50:00 www-1 tine20async: real 0m0.637s
Mar 13 18:55:00 www-1 tine20async: real 0m0.444s
Mar 13 19:00:04 www-1 tine20async: real 0m4.556s
Mar 13 19:05:00 www-1 tine20async: real 0m0.821s
Mar 13 19:10:00 www-1 tine20async: real 0m0.725s
Mar 13 19:15:00 www-1 tine20async: real 0m0.863s
Mar 13 19:20:00 www-1 tine20async: real 0m0.658s
Mar 13 19:25:00 www-1 tine20async: real 0m0.767s
Mar 13 19:30:01 www-1 tine20async: real 0m1.071s
Mar 13 19:35:00 www-1 tine20async: real 0m0.749s
Mar 13 19:40:00 www-1 tine20async: real 0m0.613s
Mar 13 19:45:00 www-1 tine20async: real 0m0.693s
Mar 13 19:50:00 www-1 tine20async: real 0m0.651s
Mar 13 19:55:00 www-1 tine20async: real 0m0.688s
Mar 13 20:00:01 www-1 tine20async: real 0m1.571s
Mar 13 20:05:00 www-1 tine20async: real 0m0.532s
Mar 13 20:10:00 www-1 tine20async: real 0m0.596s
Mar 13 20:15:00 www-1 tine20async: real 0m0.613s
Mar 13 20:20:16 www-1 tine20async: real 0m16.349s
Mar 13 20:25:00 www-1 tine20async: real 0m0.629s
Mar 13 20:30:01 www-1 tine20async: real 0m1.427s
Mar 13 20:35:00 www-1 tine20async: real 0m0.832s
Mar 13 20:40:00 www-1 tine20async: real 0m0.637s
Mar 13 20:45:01 www-1 tine20async: real 0m1.328s
Mar 13 20:50:00 www-1 tine20async: real 0m0.846s
Mar 13 20:55:00 www-1 tine20async: real 0m0.638s
Mar 13 21:00:02 www-1 tine20async: real 0m2.071s
Mar 13 21:05:01 www-1 tine20async: real 0m1.087s
Mar 13 21:10:00 www-1 tine20async: real 0m0.591s
Mar 13 21:15:01 www-1 tine20async: real 0m0.990s
Mar 13 21:20:00 www-1 tine20async: real 0m0.742s
Mar 13 21:25:00 www-1 tine20async: real 0m0.781s
Mar 13 21:30:01 www-1 tine20async: real 0m1.263s
Mar 13 21:35:00 www-1 tine20async: real 0m0.592s
Mar 13 21:40:00 www-1 tine20async: real 0m0.643s
Mar 13 21:45:00 www-1 tine20async: real 0m0.650s
Mar 13 21:50:00 www-1 tine20async: real 0m0.953s
Mar 13 21:55:00 www-1 tine20async: real 0m0.475s
Mar 13 22:00:04 www-1 tine20async: real 0m4.089s
Mar 13 22:05:00 www-1 tine20async: real 0m0.783s
Mar 13 22:10:02 www-1 tine20async: real 0m1.908s
Mar 13 22:15:03 www-1 tine20async: real 0m3.045s
Mar 13 22:20:38 www-1 tine20async: real 0m38.767s
Mar 13 22:25:02 www-1 tine20async: real 0m2.637s
Mar 13 22:30:00 www-1 tine20async: real 0m0.800s
Mar 13 22:35:00 www-1 tine20async: real 0m0.481s
Mar 13 22:40:00 www-1 tine20async: real 0m0.498s
Mar 13 22:45:00 www-1 tine20async: real 0m0.608s
Mar 13 22:50:00 www-1 tine20async: real 0m0.806s
Mar 13 22:55:00 www-1 tine20async: real 0m0.839s
Mar 13 23:00:01 www-1 tine20async: real 0m1.692s
Mar 13 23:05:00 www-1 tine20async: real 0m0.932s
Mar 13 23:10:01 www-1 tine20async: real 0m0.971s
Mar 13 23:15:00 www-1 tine20async: real 0m0.752s
Mar 13 23:20:00 www-1 tine20async: real 0m0.728s
Mar 13 23:25:00 www-1 tine20async: real 0m0.758s
Mar 13 23:30:03 www-1 tine20async: real 0m3.251s
Mar 13 23:35:00 www-1 tine20async: real 0m0.675s
Mar 13 23:40:01 www-1 tine20async: real 0m1.063s
Mar 13 23:45:00 www-1 tine20async: real 0m0.673s
Mar 13 23:50:00 www-1 tine20async: real 0m0.659s
Mar 13 23:55:01 www-1 tine20async: real 0m1.059s
Mar 14 00:00:02 www-1 tine20async: real 0m2.309s
Mar 14 00:05:00 www-1 tine20async: real 0m0.492s
Mar 14 00:10:01 www-1 tine20async: real 0m1.028s
Mar 14 00:15:00 www-1 tine20async: real 0m0.620s
Mar 14 00:20:00 www-1 tine20async: real 0m0.718s
Mar 14 00:25:00 www-1 tine20async: real 0m0.914s
Mar 14 00:30:00 www-1 tine20async: real 0m0.621s
Mar 14 00:35:00 www-1 tine20async: real 0m0.716s
Mar 14 00:40:00 www-1 tine20async: real 0m0.771s
Mar 14 00:45:00 www-1 tine20async: real 0m0.781s
Mar 14 00:50:00 www-1 tine20async: real 0m0.851s
Mar 14 00:55:00 www-1 tine20async: real 0m0.728s
Mar 14 11:29:22 www-1 tine20async: real 629m22.249s
Mar 14 11:30:24 www-1 tine20async: real 0m24.910s
Mar 14 11:35:00 www-1 tine20async: real 0m0.706s
Mar 14 11:40:01 www-1 tine20async: real 0m1.263s
Mar 14 11:45:00 www-1 tine20async: real 0m0.626s
Mar 14 11:50:01 www-1 tine20async: real 0m1.689s
Mar 14 11:55:00 www-1 tine20async: real 0m0.628s
Mar 14 12:00:03 www-1 tine20async: real 0m3.387s
Mar 14 12:05:00 www-1 tine20async: real 0m0.936s
Mar 14 12:10:00 www-1 tine20async: real 0m0.702s
Mar 14 12:15:00 www-1 tine20async: real 0m0.630s
Mar 14 12:20:19 www-1 tine20async: real 0m19.362s
bammes

bammes

2018-03-21 18:23

reporter   ~0021550

Got something:

Mar 21 00:50:00 www-1 tine20async: real 0m0.578s
Mar 21 00:55:00 www-1 tine20async: real 0m0.665s
Mar 21 11:52:55 www-1 tine20async: real 652m55.814s
Mar 21 11:55:14 www-1 tine20async: real 0m14.493s

Beginning of this issue already rotated by logrotate, but I got at least something of the ongoing task in the attached log.

bugreport.txt (78,244 bytes)
31651 -- none -- - 2018-03-21T10:55:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
31651 -- none -- - 2018-03-21T10:55:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
31651 cronuser - 2018-03-21T10:55:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
31651 cronuser - 2018-03-21T10:55:02+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
31651 cronuser - 2018-03-21T10:55:02+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
31651 cronuser - 2018-03-21T10:55:02+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:03+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
31651 cronuser - 2018-03-21T10:55:03+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_User/Group::syncUsers/Groups
31651 cronuser - 2018-03-21T10:55:03+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_User::syncUsers::749 Start synchronizing users with options Array
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_User::syncUsers::754 User backend is not instanceof Tinebase_User_Ldap, nothing to sync
31651 cronuser - 2018-03-21T10:55:03+00:00 NOTICE (5): Tinebase_Group::syncGroups::270 No syncable group backend found - skipping syncGroups.
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_User/Group::syncUsers/Groups succeeded
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_User/Group::syncUsers/Groups finished
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_AclTablesCleanup
31651 cronuser - 2018-03-21T10:55:03+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_Backend_Sql_Grants::cleanGrants::133 Clear grants in table tree_node_acl for record table tree_nodes
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_Backend_Sql_Grants::cleanGrants::133 Clear grants in table filter_acl for record table filter
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_Backend_Sql_Grants::cleanGrants::133 Clear grants in table container_acl for record table container
31651 cronuser - 2018-03-21T10:55:03+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_AclTablesCleanup succeeded
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_AclTablesCleanup finished
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_FileSystemSanitizePreviews
31651 cronuser - 2018-03-21T10:55:04+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Core::isFilesystemAvailable::1898 Filesystem available: yes
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_FileSystem::sanitizePreviews::3073 starting to sanitize previews
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_FileSystem::sanitizePreviews::3077 previews are disabled
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_FileSystemSanitizePreviews succeeded
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_FileSystemSanitizePreviews finished
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_AccessLogCleanup
31651 cronuser - 2018-03-21T10:55:04+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_AccessLog::clearTable::263 Removing all access log entries before 2018-01-20 10:55:04
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_AccessLog::clearTable::271 Removed 33 rows.
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_AccessLogCleanup succeeded
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_AccessLogCleanup finished
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_FileSystemCheckIndex
31651 cronuser - 2018-03-21T10:55:04+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_FileSystem::checkIndexing::2507 starting to check indexing
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_FileSystemCheckIndex succeeded
31651 cronuser - 2018-03-21T10:55:04+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_FileSystemCheckIndex finished
31651 cronuser - 2018-03-21T10:55:05+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_CredentialCacheCleanup
31651 cronuser - 2018-03-21T10:55:05+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:05+00:00 DEBUG (7): Tinebase_Auth_CredentialCache::setCacheAdapter::117 Using credential cache adapter: Tinebase_Auth_CredentialCache_Adapter_Cookie
31651 cronuser - 2018-03-21T10:55:05+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_CredentialCacheCleanup succeeded
31651 cronuser - 2018-03-21T10:55:05+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_CredentialCacheCleanup finished
31651 cronuser - 2018-03-21T10:55:05+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_cleanupSessions
31651 cronuser - 2018-03-21T10:55:05+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:05+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_cleanupSessions succeeded
31651 cronuser - 2018-03-21T10:55:05+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_cleanupSessions finished
31651 cronuser - 2018-03-21T10:55:06+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_TempFileCleanup
31651 cronuser - 2018-03-21T10:55:06+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:06+00:00 INFO (6): Tinebase_TempFile::clearTableAndTempdir::256 Removing all temp files prior 2018-03-20 10:55:06
31651 cronuser - 2018-03-21T10:55:06+00:00 DEBUG (7): Tinebase_Backend_Sql_Abstract::delete::1412 No records deleted.
31651 cronuser - 2018-03-21T10:55:06+00:00 INFO (6): Tinebase_TempFile::clearTableAndTempdir::275 Removed 0 temp files from database and filesystem.
31651 cronuser - 2018-03-21T10:55:08+00:00 INFO (6): Tinebase_TempFile::clearTableAndTempdir::285 Removed 0 temp files from filesystem only.
31651 cronuser - 2018-03-21T10:55:08+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_TempFileCleanup succeeded
31651 cronuser - 2018-03-21T10:55:09+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_TempFileCleanup finished
31651 cronuser - 2018-03-21T10:55:09+00:00 INFO (6): Tinebase_Scheduler::run::141 run task readModificationLogFromMaster
31651 cronuser - 2018-03-21T10:55:09+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:09+00:00 INFO (6): Tinebase_Scheduler::run::147 task readModificationLogFromMaster succeeded
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Scheduler::run::165 running task readModificationLogFromMaster finished
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_FileSystemSizeRecalculation
31651 cronuser - 2018-03-21T10:55:10+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_FileSystem::recalculateRevisionSize::2479 starting to recalculate revision size
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_FileSystem::recalculateFolderSize::2493 starting to recalculate folder size
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:10+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 DEBUG (7): Tinebase_CustomField::getCustomFieldsForApplication::206 Got 0 uncached custom fields for app id d7a72ae8b1ec77c28b9c21dceee97471569b9d48 (cacheid: getCustomFieldsForApplicationd7a72ae8b1ec77c28b9c21dceee97471569b9d48Tinebase_Model_Tree_NodereadGrant7b968efe373349c6acb6ea119e800369081d3f64)
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_FileSystemSizeRecalculation succeeded
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_FileSystemSizeRecalculation finished
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Calendar_Controller_Event::sendTentativeNotifications
31651 cronuser - 2018-03-21T10:55:11+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:11+00:00 DEBUG (7): Tinebase_Config_Abstract::_loadAllAppConfigsInCache::584 Loading all configs for app Calendar
31651 cronuser - 2018-03-21T10:55:11+00:00 DEBUG (7): Tinebase_Config_Abstract::_loadAllAppConfigsInCache::602 Found 0 configs.
31651 cronuser - 2018-03-21T10:55:11+00:00 DEBUG (7): Tinebase_Config_Abstract::_getAppDefaultsConfigFileData::503 Looking for defaults config.inc.php at /usr/local/www/calendar.postadigitale.de/Calendar/config.inc.php
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Scheduler::run::147 task Calendar_Controller_Event::sendTentativeNotifications succeeded
31651 cronuser - 2018-03-21T10:55:11+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Calendar_Controller_Event::sendTentativeNotifications finished
31651 cronuser - 2018-03-21T10:55:12+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_FileSystemNotifyQuota
31651 cronuser - 2018-03-21T10:55:12+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:13+00:00 INFO (6): Tinebase_Auth_SecondFactor_Abstract::hasValidSecondFactor::59 No session started to check second factor in session
31651 cronuser - 2018-03-21T10:55:13+00:00 DEBUG (7): Tinebase_EmailUser::getInstance::200 Email user backend: Imap_Standard
31651 cronuser - 2018-03-21T10:55:13+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_FileSystemNotifyQuota succeeded
31651 cronuser - 2018-03-21T10:55:13+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_FileSystemNotifyQuota finished
31651 cronuser - 2018-03-21T10:55:14+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_CacheCleanup
31651 cronuser - 2018-03-21T10:55:14+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:14+00:00 INFO (6): Tinebase_Controller::cleanupCache::575 Cleaning up the cache (mode: old)
31651 cronuser - 2018-03-21T10:55:14+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_CacheCleanup succeeded
31651 cronuser - 2018-03-21T10:55:14+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_CacheCleanup finished
31651 cronuser - 2018-03-21T10:55:14+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
31651 cronuser - 2018-03-21T10:55:14+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
31651 cronuser - 2018-03-21T10:55:14+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
31651 cronuser - 2018-03-21T10:55:14+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
31651 cronuser - 2018-03-21T10:55:14+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
521df -- none -- - 2018-03-21T11:00:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
521df -- none -- - 2018-03-21T11:00:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
521df cronuser - 2018-03-21T11:00:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
521df cronuser - 2018-03-21T11:00:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
521df cronuser - 2018-03-21T11:00:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task readModificationLogFromMaster
521df cronuser - 2018-03-21T11:00:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
521df cronuser - 2018-03-21T11:00:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task readModificationLogFromMaster succeeded
521df cronuser - 2018-03-21T11:00:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task readModificationLogFromMaster finished
521df cronuser - 2018-03-21T11:00:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_User/Group::syncUsers/Groups
521df cronuser - 2018-03-21T11:00:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
521df cronuser - 2018-03-21T11:00:00+00:00 INFO (6): Tinebase_User::syncUsers::749 Start synchronizing users with options Array
521df cronuser - 2018-03-21T11:00:00+00:00 INFO (6): Tinebase_User::syncUsers::754 User backend is not instanceof Tinebase_User_Ldap, nothing to sync
521df cronuser - 2018-03-21T11:00:00+00:00 NOTICE (5): Tinebase_Group::syncGroups::270 No syncable group backend found - skipping syncGroups.
521df cronuser - 2018-03-21T11:00:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_User/Group::syncUsers/Groups succeeded
521df cronuser - 2018-03-21T11:00:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_User/Group::syncUsers/Groups finished
521df cronuser - 2018-03-21T11:00:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
521df cronuser - 2018-03-21T11:00:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
521df cronuser - 2018-03-21T11:00:01+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
521df cronuser - 2018-03-21T11:00:01+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
521df cronuser - 2018-03-21T11:00:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
521df cronuser - 2018-03-21T11:00:02+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
521df cronuser - 2018-03-21T11:00:02+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_cleanupSessions
521df cronuser - 2018-03-21T11:00:02+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
521df cronuser - 2018-03-21T11:00:02+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_cleanupSessions succeeded
521df cronuser - 2018-03-21T11:00:03+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_cleanupSessions finished
521df cronuser - 2018-03-21T11:00:03+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
521df cronuser - 2018-03-21T11:00:03+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
521df cronuser - 2018-03-21T11:00:03+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
521df cronuser - 2018-03-21T11:00:03+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
521df cronuser - 2018-03-21T11:00:05+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
a8d54 -- none -- - 2018-03-21T11:05:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
a8d54 -- none -- - 2018-03-21T11:05:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
a8d54 cronuser - 2018-03-21T11:05:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
a8d54 cronuser - 2018-03-21T11:05:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
a8d54 cronuser - 2018-03-21T11:05:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
a8d54 cronuser - 2018-03-21T11:05:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
a8d54 cronuser - 2018-03-21T11:05:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
a8d54 cronuser - 2018-03-21T11:05:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
a8d54 cronuser - 2018-03-21T11:05:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
a8d54 cronuser - 2018-03-21T11:05:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
a8d54 cronuser - 2018-03-21T11:05:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
a8d54 cronuser - 2018-03-21T11:05:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
a8d54 cronuser - 2018-03-21T11:05:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
a8d54 cronuser - 2018-03-21T11:05:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
a8d54 cronuser - 2018-03-21T11:05:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
310f5 -- none -- - 2018-03-21T11:10:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
310f5 -- none -- - 2018-03-21T11:10:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
310f5 cronuser - 2018-03-21T11:10:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
310f5 cronuser - 2018-03-21T11:10:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
310f5 cronuser - 2018-03-21T11:10:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
310f5 cronuser - 2018-03-21T11:10:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
310f5 cronuser - 2018-03-21T11:10:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
310f5 cronuser - 2018-03-21T11:10:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
310f5 cronuser - 2018-03-21T11:10:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
310f5 cronuser - 2018-03-21T11:10:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
310f5 cronuser - 2018-03-21T11:10:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
310f5 cronuser - 2018-03-21T11:10:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
310f5 cronuser - 2018-03-21T11:10:01+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
310f5 cronuser - 2018-03-21T11:10:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
310f5 cronuser - 2018-03-21T11:10:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
3b00f -- none -- - 2018-03-21T11:15:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
3b00f -- none -- - 2018-03-21T11:15:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
3b00f cronuser - 2018-03-21T11:15:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
3b00f cronuser - 2018-03-21T11:15:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
3b00f cronuser - 2018-03-21T11:15:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
3b00f cronuser - 2018-03-21T11:15:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
3b00f cronuser - 2018-03-21T11:15:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
3b00f cronuser - 2018-03-21T11:15:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
3b00f cronuser - 2018-03-21T11:15:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
3b00f cronuser - 2018-03-21T11:15:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
3b00f cronuser - 2018-03-21T11:15:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
3b00f cronuser - 2018-03-21T11:15:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
3b00f cronuser - 2018-03-21T11:15:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
3b00f cronuser - 2018-03-21T11:15:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
3b00f cronuser - 2018-03-21T11:15:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
a60a7 -- none -- - 2018-03-21T11:20:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
a60a7 -- none -- - 2018-03-21T11:20:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
a60a7 cronuser - 2018-03-21T11:20:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
a60a7 cronuser - 2018-03-21T11:20:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
a60a7 cronuser - 2018-03-21T11:20:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
a60a7 cronuser - 2018-03-21T11:20:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
a60a7 cronuser - 2018-03-21T11:20:01+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
a60a7 cronuser - 2018-03-21T11:20:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
a60a7 cronuser - 2018-03-21T11:20:02+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
a60a7 cronuser - 2018-03-21T11:20:02+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
a60a7 cronuser - 2018-03-21T11:20:02+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
a60a7 cronuser - 2018-03-21T11:20:02+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
a60a7 cronuser - 2018-03-21T11:20:02+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
a60a7 cronuser - 2018-03-21T11:20:02+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
a60a7 cronuser - 2018-03-21T11:20:02+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
fa361 -- none -- - 2018-03-21T11:25:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
fa361 -- none -- - 2018-03-21T11:25:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
fa361 cronuser - 2018-03-21T11:25:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
fa361 cronuser - 2018-03-21T11:25:01+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
fa361 cronuser - 2018-03-21T11:25:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
fa361 cronuser - 2018-03-21T11:25:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
fa361 cronuser - 2018-03-21T11:25:01+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
fa361 cronuser - 2018-03-21T11:25:01+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
fa361 cronuser - 2018-03-21T11:25:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
fa361 cronuser - 2018-03-21T11:25:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
fa361 cronuser - 2018-03-21T11:25:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
fa361 cronuser - 2018-03-21T11:25:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
fa361 cronuser - 2018-03-21T11:25:02+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
fa361 cronuser - 2018-03-21T11:25:02+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
fa361 cronuser - 2018-03-21T11:25:02+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
13fbd -- none -- - 2018-03-21T11:30:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
13fbd -- none -- - 2018-03-21T11:30:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
13fbd cronuser - 2018-03-21T11:30:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
13fbd cronuser - 2018-03-21T11:30:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
13fbd cronuser - 2018-03-21T11:30:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
13fbd cronuser - 2018-03-21T11:30:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
13fbd cronuser - 2018-03-21T11:30:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
13fbd cronuser - 2018-03-21T11:30:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
13fbd cronuser - 2018-03-21T11:30:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
13fbd cronuser - 2018-03-21T11:30:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
13fbd cronuser - 2018-03-21T11:30:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
13fbd cronuser - 2018-03-21T11:30:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
13fbd cronuser - 2018-03-21T11:30:01+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
13fbd cronuser - 2018-03-21T11:30:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
13fbd cronuser - 2018-03-21T11:30:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
09892 -- none -- - 2018-03-21T11:35:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
09892 -- none -- - 2018-03-21T11:35:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
09892 cronuser - 2018-03-21T11:35:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
09892 cronuser - 2018-03-21T11:35:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
09892 cronuser - 2018-03-21T11:35:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
09892 cronuser - 2018-03-21T11:35:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
09892 cronuser - 2018-03-21T11:35:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
09892 cronuser - 2018-03-21T11:35:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
09892 cronuser - 2018-03-21T11:35:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
09892 cronuser - 2018-03-21T11:35:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
09892 cronuser - 2018-03-21T11:35:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
09892 cronuser - 2018-03-21T11:35:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
09892 cronuser - 2018-03-21T11:35:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
09892 cronuser - 2018-03-21T11:35:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
09892 cronuser - 2018-03-21T11:35:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
22bce -- none -- - 2018-03-21T11:40:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
22bce -- none -- - 2018-03-21T11:40:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
22bce cronuser - 2018-03-21T11:40:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
22bce cronuser - 2018-03-21T11:40:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
22bce cronuser - 2018-03-21T11:40:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
22bce cronuser - 2018-03-21T11:40:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
22bce cronuser - 2018-03-21T11:40:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
22bce cronuser - 2018-03-21T11:40:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
22bce cronuser - 2018-03-21T11:40:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
22bce cronuser - 2018-03-21T11:40:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
22bce cronuser - 2018-03-21T11:40:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
22bce cronuser - 2018-03-21T11:40:01+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
22bce cronuser - 2018-03-21T11:40:01+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
22bce cronuser - 2018-03-21T11:40:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
22bce cronuser - 2018-03-21T11:40:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
1d22b -- none -- - 2018-03-21T11:45:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
1d22b -- none -- - 2018-03-21T11:45:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
1d22b cronuser - 2018-03-21T11:45:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
1d22b cronuser - 2018-03-21T11:45:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
1d22b cronuser - 2018-03-21T11:45:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
1d22b cronuser - 2018-03-21T11:45:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
1d22b cronuser - 2018-03-21T11:45:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
1d22b cronuser - 2018-03-21T11:45:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
1d22b cronuser - 2018-03-21T11:45:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
1d22b cronuser - 2018-03-21T11:45:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
1d22b cronuser - 2018-03-21T11:45:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
1d22b cronuser - 2018-03-21T11:45:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
1d22b cronuser - 2018-03-21T11:45:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
1d22b cronuser - 2018-03-21T11:45:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
1d22b cronuser - 2018-03-21T11:45:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
3c8d8 -- none -- - 2018-03-21T11:50:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
3c8d8 -- none -- - 2018-03-21T11:50:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
3c8d8 cronuser - 2018-03-21T11:50:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
3c8d8 cronuser - 2018-03-21T11:50:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
d732b -- none -- - 2018-03-21T11:55:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
d732b -- none -- - 2018-03-21T11:55:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
d732b cronuser - 2018-03-21T11:55:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
d732b cronuser - 2018-03-21T11:55:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
d732b cronuser - 2018-03-21T11:55:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
d732b cronuser - 2018-03-21T11:55:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
d732b cronuser - 2018-03-21T11:55:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
d732b cronuser - 2018-03-21T11:55:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
d732b cronuser - 2018-03-21T11:55:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
d732b cronuser - 2018-03-21T11:55:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
d732b cronuser - 2018-03-21T11:55:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
d732b cronuser - 2018-03-21T11:55:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
d732b cronuser - 2018-03-21T11:55:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
d732b cronuser - 2018-03-21T11:55:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
d732b cronuser - 2018-03-21T11:55:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
5a87d -- none -- - 2018-03-21T12:00:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
5a87d -- none -- - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task readModificationLogFromMaster
5a87d cronuser - 2018-03-21T12:00:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task readModificationLogFromMaster succeeded
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task readModificationLogFromMaster finished
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_User/Group::syncUsers/Groups
5a87d cronuser - 2018-03-21T12:00:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_User::syncUsers::749 Start synchronizing users with options Array
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_User::syncUsers::754 User backend is not instanceof Tinebase_User_Ldap, nothing to sync
5a87d cronuser - 2018-03-21T12:00:00+00:00 NOTICE (5): Tinebase_Group::syncGroups::270 No syncable group backend found - skipping syncGroups.
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_User/Group::syncUsers/Groups succeeded
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_User/Group::syncUsers/Groups finished
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
5a87d cronuser - 2018-03-21T12:00:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
5a87d cronuser - 2018-03-21T12:00:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
5a87d cronuser - 2018-03-21T12:00:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
5a87d cronuser - 2018-03-21T12:00:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
5a87d cronuser - 2018-03-21T12:00:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
5a87d cronuser - 2018-03-21T12:00:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
5a87d cronuser - 2018-03-21T12:00:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
5a87d cronuser - 2018-03-21T12:00:01+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
5a87d cronuser - 2018-03-21T12:00:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
5a87d cronuser - 2018-03-21T12:00:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
5a87d cronuser - 2018-03-21T12:00:02+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_cleanupSessions
5a87d cronuser - 2018-03-21T12:00:02+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
5a87d cronuser - 2018-03-21T12:00:02+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_cleanupSessions succeeded
5a87d cronuser - 2018-03-21T12:00:02+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_cleanupSessions finished
c1dae -- none -- - 2018-03-21T12:05:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
c1dae -- none -- - 2018-03-21T12:05:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
c1dae cronuser - 2018-03-21T12:05:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
c1dae cronuser - 2018-03-21T12:05:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
c1dae cronuser - 2018-03-21T12:05:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
c1dae cronuser - 2018-03-21T12:05:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
c1dae cronuser - 2018-03-21T12:05:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
c1dae cronuser - 2018-03-21T12:05:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
c1dae cronuser - 2018-03-21T12:05:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
c1dae cronuser - 2018-03-21T12:05:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
c1dae cronuser - 2018-03-21T12:05:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
c1dae cronuser - 2018-03-21T12:05:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
c1dae cronuser - 2018-03-21T12:05:01+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
c1dae cronuser - 2018-03-21T12:05:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
c1dae cronuser - 2018-03-21T12:05:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
e7d14 -- none -- - 2018-03-21T12:10:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
e7d14 -- none -- - 2018-03-21T12:10:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
e7d14 cronuser - 2018-03-21T12:10:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
e7d14 cronuser - 2018-03-21T12:10:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
e7d14 cronuser - 2018-03-21T12:10:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
e7d14 cronuser - 2018-03-21T12:10:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
e7d14 cronuser - 2018-03-21T12:10:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
e7d14 cronuser - 2018-03-21T12:10:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
e7d14 cronuser - 2018-03-21T12:10:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
e7d14 cronuser - 2018-03-21T12:10:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
e7d14 cronuser - 2018-03-21T12:10:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
e7d14 cronuser - 2018-03-21T12:10:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
e7d14 cronuser - 2018-03-21T12:10:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
e7d14 cronuser - 2018-03-21T12:10:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
e7d14 cronuser - 2018-03-21T12:10:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
f12c4 -- none -- - 2018-03-21T12:15:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
f12c4 -- none -- - 2018-03-21T12:15:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
f12c4 cronuser - 2018-03-21T12:15:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
f12c4 cronuser - 2018-03-21T12:15:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
f12c4 cronuser - 2018-03-21T12:15:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
f12c4 cronuser - 2018-03-21T12:15:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
f12c4 cronuser - 2018-03-21T12:15:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
f12c4 cronuser - 2018-03-21T12:15:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
f12c4 cronuser - 2018-03-21T12:15:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
f12c4 cronuser - 2018-03-21T12:15:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
f12c4 cronuser - 2018-03-21T12:15:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
f12c4 cronuser - 2018-03-21T12:15:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
f12c4 cronuser - 2018-03-21T12:15:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
f12c4 cronuser - 2018-03-21T12:15:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
f12c4 cronuser - 2018-03-21T12:15:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
b7abf -- none -- - 2018-03-21T12:20:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
b7abf -- none -- - 2018-03-21T12:20:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
b7abf cronuser - 2018-03-21T12:20:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
b7abf cronuser - 2018-03-21T12:20:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
b7abf cronuser - 2018-03-21T12:20:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
b7abf cronuser - 2018-03-21T12:20:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
b7abf cronuser - 2018-03-21T12:20:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
b7abf cronuser - 2018-03-21T12:20:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
b7abf cronuser - 2018-03-21T12:20:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
b7abf cronuser - 2018-03-21T12:20:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
b7abf cronuser - 2018-03-21T12:20:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
b7abf cronuser - 2018-03-21T12:20:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
b7abf cronuser - 2018-03-21T12:20:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
b7abf cronuser - 2018-03-21T12:20:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
b7abf cronuser - 2018-03-21T12:20:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
ce99f -- none -- - 2018-03-21T12:25:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
ce99f -- none -- - 2018-03-21T12:25:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
ce99f cronuser - 2018-03-21T12:25:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
ce99f cronuser - 2018-03-21T12:25:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
ce99f cronuser - 2018-03-21T12:25:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
ce99f cronuser - 2018-03-21T12:25:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
ce99f cronuser - 2018-03-21T12:25:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
ce99f cronuser - 2018-03-21T12:25:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
ce99f cronuser - 2018-03-21T12:25:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
ce99f cronuser - 2018-03-21T12:25:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
ce99f cronuser - 2018-03-21T12:25:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
ce99f cronuser - 2018-03-21T12:25:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
ce99f cronuser - 2018-03-21T12:25:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
ce99f cronuser - 2018-03-21T12:25:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
ce99f cronuser - 2018-03-21T12:25:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
87edc -- none -- - 2018-03-21T12:30:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
87edc -- none -- - 2018-03-21T12:30:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
87edc cronuser - 2018-03-21T12:30:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
87edc cronuser - 2018-03-21T12:30:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
87edc cronuser - 2018-03-21T12:30:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
87edc cronuser - 2018-03-21T12:30:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
87edc cronuser - 2018-03-21T12:30:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
87edc cronuser - 2018-03-21T12:30:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
87edc cronuser - 2018-03-21T12:30:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
87edc cronuser - 2018-03-21T12:30:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
87edc cronuser - 2018-03-21T12:30:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
87edc cronuser - 2018-03-21T12:30:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
87edc cronuser - 2018-03-21T12:30:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
87edc cronuser - 2018-03-21T12:30:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
87edc cronuser - 2018-03-21T12:30:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
fe1d2 -- none -- - 2018-03-21T12:35:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
fe1d2 -- none -- - 2018-03-21T12:35:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
fe1d2 cronuser - 2018-03-21T12:35:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
fe1d2 cronuser - 2018-03-21T12:35:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
fe1d2 cronuser - 2018-03-21T12:35:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
fe1d2 cronuser - 2018-03-21T12:35:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
fe1d2 cronuser - 2018-03-21T12:35:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
fe1d2 cronuser - 2018-03-21T12:35:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
fe1d2 cronuser - 2018-03-21T12:35:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
fe1d2 cronuser - 2018-03-21T12:35:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
fe1d2 cronuser - 2018-03-21T12:35:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
fe1d2 cronuser - 2018-03-21T12:35:01+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
fe1d2 cronuser - 2018-03-21T12:35:01+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
fe1d2 cronuser - 2018-03-21T12:35:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
fe1d2 cronuser - 2018-03-21T12:35:02+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
868ff -- none -- - 2018-03-21T12:40:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
868ff -- none -- - 2018-03-21T12:40:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
868ff cronuser - 2018-03-21T12:40:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
868ff cronuser - 2018-03-21T12:40:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
868ff cronuser - 2018-03-21T12:40:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
868ff cronuser - 2018-03-21T12:40:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
868ff cronuser - 2018-03-21T12:40:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
868ff cronuser - 2018-03-21T12:40:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
868ff cronuser - 2018-03-21T12:40:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
868ff cronuser - 2018-03-21T12:40:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
868ff cronuser - 2018-03-21T12:40:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
868ff cronuser - 2018-03-21T12:40:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
868ff cronuser - 2018-03-21T12:40:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
868ff cronuser - 2018-03-21T12:40:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
868ff cronuser - 2018-03-21T12:40:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
f9e63 -- none -- - 2018-03-21T12:45:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
f9e63 -- none -- - 2018-03-21T12:45:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
f9e63 cronuser - 2018-03-21T12:45:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
f9e63 cronuser - 2018-03-21T12:45:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
f9e63 cronuser - 2018-03-21T12:45:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
f9e63 cronuser - 2018-03-21T12:45:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
f9e63 cronuser - 2018-03-21T12:45:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
f9e63 cronuser - 2018-03-21T12:45:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
f9e63 cronuser - 2018-03-21T12:45:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
f9e63 cronuser - 2018-03-21T12:45:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
f9e63 cronuser - 2018-03-21T12:45:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
f9e63 cronuser - 2018-03-21T12:45:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
f9e63 cronuser - 2018-03-21T12:45:01+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
f9e63 cronuser - 2018-03-21T12:45:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
f9e63 cronuser - 2018-03-21T12:45:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
51918 -- none -- - 2018-03-21T12:50:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
51918 -- none -- - 2018-03-21T12:50:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
51918 cronuser - 2018-03-21T12:50:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
51918 cronuser - 2018-03-21T12:50:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
51918 cronuser - 2018-03-21T12:50:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
51918 cronuser - 2018-03-21T12:50:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
51918 cronuser - 2018-03-21T12:50:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
51918 cronuser - 2018-03-21T12:50:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
51918 cronuser - 2018-03-21T12:50:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
51918 cronuser - 2018-03-21T12:50:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
51918 cronuser - 2018-03-21T12:50:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
51918 cronuser - 2018-03-21T12:50:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
51918 cronuser - 2018-03-21T12:50:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
51918 cronuser - 2018-03-21T12:50:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
51918 cronuser - 2018-03-21T12:50:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
3ca65 -- none -- - 2018-03-21T12:55:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
3ca65 -- none -- - 2018-03-21T12:55:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
3ca65 cronuser - 2018-03-21T12:55:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
3ca65 cronuser - 2018-03-21T12:55:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
3ca65 cronuser - 2018-03-21T12:55:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
3ca65 cronuser - 2018-03-21T12:55:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
3ca65 cronuser - 2018-03-21T12:55:00+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
3ca65 cronuser - 2018-03-21T12:55:00+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
3ca65 cronuser - 2018-03-21T12:55:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
3ca65 cronuser - 2018-03-21T12:55:01+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
3ca65 cronuser - 2018-03-21T12:55:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
3ca65 cronuser - 2018-03-21T12:55:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
3ca65 cronuser - 2018-03-21T12:55:01+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
3ca65 cronuser - 2018-03-21T12:55:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
3ca65 cronuser - 2018-03-21T12:55:02+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
75a5d -- none -- - 2018-03-21T13:00:00+00:00 DEBUG (7): Tinebase_Frontend_Cli_Abstract::_getCronuserFromConfigOrCreateOnTheFly::523 Setting user with id 7b968efe373349c6acb6ea119e800369081d3f64 as cronuser.
75a5d -- none -- - 2018-03-21T13:00:00+00:00 INFO (6): Tinebase_Core::set::1378 Setting user cronuser
75a5d cronuser - 2018-03-21T13:00:00+00:00 INFO (6): Tinebase_Scheduler::run::89 Scheduler started
75a5d cronuser - 2018-03-21T13:00:00+00:00 INFO (6): Tinebase_Lock::getBackend::105 lock backend is: Tinebase_Lock_Redis
75a5d cronuser - 2018-03-21T13:00:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task readModificationLogFromMaster
75a5d cronuser - 2018-03-21T13:00:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
75a5d cronuser - 2018-03-21T13:00:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task readModificationLogFromMaster succeeded
75a5d cronuser - 2018-03-21T13:00:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task readModificationLogFromMaster finished
75a5d cronuser - 2018-03-21T13:00:00+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Alarm
75a5d cronuser - 2018-03-21T13:00:00+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
75a5d cronuser - 2018-03-21T13:00:00+00:00 DEBUG (7): Tinebase_Alarm::sendPendingAlarms::105 Sending 0 alarms (limit: 100).
75a5d cronuser - 2018-03-21T13:00:00+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Alarm succeeded
75a5d cronuser - 2018-03-21T13:00:00+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Alarm finished
75a5d cronuser - 2018-03-21T13:00:01+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_User/Group::syncUsers/Groups
75a5d cronuser - 2018-03-21T13:00:01+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
75a5d cronuser - 2018-03-21T13:00:01+00:00 INFO (6): Tinebase_User::syncUsers::749 Start synchronizing users with options Array
75a5d cronuser - 2018-03-21T13:00:01+00:00 INFO (6): Tinebase_User::syncUsers::754 User backend is not instanceof Tinebase_User_Ldap, nothing to sync
75a5d cronuser - 2018-03-21T13:00:01+00:00 NOTICE (5): Tinebase_Group::syncGroups::270 No syncable group backend found - skipping syncGroups.
75a5d cronuser - 2018-03-21T13:00:01+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_User/Group::syncUsers/Groups succeeded
75a5d cronuser - 2018-03-21T13:00:03+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_User/Group::syncUsers/Groups finished
75a5d cronuser - 2018-03-21T13:00:04+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_Controller_ScheduledImport
75a5d cronuser - 2018-03-21T13:00:04+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
75a5d cronuser - 2018-03-21T13:00:04+00:00 DEBUG (7): Tinebase_Controller_Record_Abstract::search::245 Got 0 search results of Tinebase_Model_Import
75a5d cronuser - 2018-03-21T13:00:04+00:00 DEBUG (7): Tinebase_Controller_ScheduledImport::_getNextScheduledImport 152 No valid ScheduledImport could be found.
75a5d cronuser - 2018-03-21T13:00:04+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_Controller_ScheduledImport succeeded
75a5d cronuser - 2018-03-21T13:00:05+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_Controller_ScheduledImport finished
75a5d cronuser - 2018-03-21T13:00:06+00:00 INFO (6): Tinebase_Scheduler::run::141 run task Tinebase_cleanupSessions
75a5d cronuser - 2018-03-21T13:00:06+00:00 DEBUG (7): Tinebase_Scheduler_Task::run::132 starting .... 
75a5d cronuser - 2018-03-21T13:00:06+00:00 INFO (6): Tinebase_Scheduler::run::147 task Tinebase_cleanupSessions succeeded
75a5d cronuser - 2018-03-21T13:00:06+00:00 INFO (6): Tinebase_Scheduler::run::165 running task Tinebase_cleanupSessions finished
bugreport.txt (78,244 bytes)
pmehrer

pmehrer

2018-03-29 17:36

developer   ~0021578

Last edited: 2018-03-29 17:37

View 2 revisions

Hello,

the long running task:
Mar 21 11:52:55 www-1 tine20async: real 652m55.814s
started on Mar 21 00:00:00 (that makes sense, all the daily jobs are executed at midnight, they may take a while, though not 10 hours of course)

in the log file you send I can't see anything related to that. Interessting would be the time from 00:00:00 to ... wherever the job gets stuck (I would assume we should see something within the first 15 minutes or so) Do you still have the logs from Mar 21?

thanks for providing information on this issue

bammes

bammes

2018-04-05 20:45

reporter   ~0021606

Hi,

I pasted everything I got, since I worked around this problem, my monitoring system does not complain about php eating all my memory. So I have to look in the logs from time to time and very often, the relevant logs have been rotated out.

But if you have a look on the list of jobs I posted before my last post, you can clearly see, that no all of these long-running jobs happen at midnight:

Mar 14 00:55:00 www-1 tine20async: real 0m0.728s
Mar 14 11:29:22 www-1 tine20async: real 629m22.249s
Mar 14 11:30:24 www-1 tine20async: real 0m24.910s

I will keep my eyes open and hope to catch another occurence of this bug with full log...
pmehrer

pmehrer

2018-04-19 20:31

developer   ~0021668

Hi,

they do happen at midnight:

Mar 14 11:29:22 www-1 tine20async: real 629m22.249s
it started exactly 6 hours 29 minutes and 22 seconds ago (that should be midnight or 1pm or a like)

so the interessting log is not Mar 14 11:29, the interessting log is Mar 14 01:00 to Mar 14 01:15 if I can get that, I can help you.

Issue History

Date Modified Username Field Change
2018-02-22 21:16 bammes New Issue
2018-02-27 16:23 bammes Note Added: 0021464
2018-02-28 08:27 pschuele Assigned To => pmehrer
2018-03-13 21:26 pmehrer Note Added: 0021506
2018-03-14 12:22 bammes Note Added: 0021514
2018-03-14 12:28 bammes Note Added: 0021516
2018-03-21 18:23 bammes File Added: bugreport.txt
2018-03-21 18:23 bammes Note Added: 0021550
2018-03-29 17:36 pmehrer Note Added: 0021578
2018-03-29 17:37 pmehrer Note Edited: 0021578 View Revisions
2018-04-05 20:45 bammes Note Added: 0021606
2018-04-19 20:31 pmehrer Note Added: 0021668