Convert RRule debugging to use dbg_error_log

This stops the debugging from being sent to stdout, which goes to the client and
mucks up the test results.
This commit is contained in:
Andrew Ruthven 2022-12-14 13:59:54 +13:00
parent 80102c2700
commit 3909ec52f1

View File

@ -248,7 +248,7 @@ class RepeatRuleDateTime extends DateTime {
// $value_type = $date->GetParameterValue('VALUE');
// if ( isset($value_type) && $value_type == 'DATE' ) $this->is_date = true;
$date = $actual_date;
if ( DEBUG_RRULE ) printf( "Date%s property%s: %s%s\n", ($this->is_date ? "" : "Time"),
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Date%s property%s: %s%s", ($this->is_date ? "" : "Time"),
(isset($this->tzid) ? ' with timezone' : ''), $date,
(isset($this->tzid) ? ' in '.$this->tzid : '') );
}
@ -267,7 +267,7 @@ class RepeatRuleDateTime extends DateTime {
$dtz = self::$UTCzone;
$this->tzid = null;
}
if ( DEBUG_RRULE ) printf( "Date%s property%s: %s%s\n", ($this->is_date ? "" : "Time"),
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Date%s property%s: %s%s", ($this->is_date ? "" : "Time"),
(isset($this->tzid) ? ' with timezone' : ''), $date,
(isset($this->tzid) ? ' in '.$this->tzid : '') );
}
@ -278,7 +278,7 @@ class RepeatRuleDateTime extends DateTime {
// Floating
$dtz = self::$UTCzone;
$this->tzid = null;
if ( DEBUG_RRULE ) printf( "Floating Date value: %s\n", $date );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Floating Date value: %s", $date );
}
elseif ( $dtz === null || $dtz == '' ) {
$dtz = self::$UTCzone;
@ -292,18 +292,18 @@ class RepeatRuleDateTime extends DateTime {
}
}
$this->is_date = (strlen($date) == 8 );
if ( DEBUG_RRULE ) printf( "Date%s value with timezone 1: %s in %s\n", ($this->is_date?"":"Time"), $date, $this->tzid );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Date%s value with timezone 1: %s in %s", ($this->is_date?"":"Time"), $date, $this->tzid );
}
elseif ( is_string($dtz) ) {
$dtz = new RepeatRuleTimeZone($dtz);
$this->tzid = $dtz->tzid();
$type = gettype($date);
if ( DEBUG_RRULE ) printf( "Date%s $type with timezone 2: %s in %s\n", ($this->is_date?"":"Time"), $date, $this->tzid );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Date%s $type with timezone 2: %s in %s", ($this->is_date?"":"Time"), $date, $this->tzid );
}
else {
$this->tzid = $dtz->getName();
$type = gettype($date);
if ( DEBUG_RRULE ) printf( "Date%s $type with timezone 3: %s in %s\n", ($this->is_date?"":"Time"), $date, $this->tzid );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Date%s $type with timezone 3: %s in %s", ($this->is_date?"":"Time"), $date, $this->tzid );
}
parent::__construct($date, $dtz);
@ -648,7 +648,7 @@ class RepeatRule {
$this->original_rule = $rrule;
if ( DEBUG_RRULE ) {
printf( "Constructing RRULE based on: '%s', rrule: '%s' (float: %s)\n", $basedate, $rrule, ($return_floating_times ? "yes" : "no") );
dbg_error_log( 'RRULE', "Constructing RRULE based on: '%s', rrule: '%s' (float: %s)", $basedate, $rrule, ($return_floating_times ? "yes" : "no") );
}
if ( preg_match('{FREQ=([A-Z]+)(;|$)}', $rrule, $m) ) $this->freq = $m[1];
@ -688,7 +688,7 @@ class RepeatRule {
/** need to handle the error, but FREQ is mandatory so unlikely */
}
$this->frequency_string = sprintf('+%d %s', $this->interval, $freq_name );
if ( DEBUG_RRULE ) printf( "Frequency modify string is: '%s', base is: '%s', TZ: %s\n", $this->frequency_string, $this->base->format('c'), $this->base->getTimeZone() );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Frequency modify string is: '%s', base is: '%s', TZ: %s", $this->frequency_string, $this->base->format('c'), $this->base->getTimeZone() );
$this->Start($return_floating_times);
}
@ -735,7 +735,7 @@ class RepeatRule {
if ( !$this->valid() ) return null;
if ( !isset($this->instances[$this->position]) ) $this->GetMoreInstances($return_floating_times);
if ( !$this->valid() ) return null;
if ( DEBUG_RRULE ) printf( "Returning date from position %d: %s (%s)\n", $this->position,
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Returning date from position %d: %s (%s)", $this->position,
$this->instances[$this->position]->format('c'), $this->instances[$this->position]->FloatOrUTC($return_floating_times) );
return $this->instances[$this->position];
}
@ -754,10 +754,9 @@ class RepeatRule {
public function valid() {
if ( DEBUG_RRULE && isset($this->instances[$this->position])) {
$current = $this->instances[$this->position];
print "TimeZone: " . $current->getTimeZone() . "\n";
print "Date: " . $current->format('r') . "\n";
print "Errors:\n";
print_r($current->getLastErrors());
dbg_error_log( 'RRULE', "TimeZone: " . $current->getTimeZone());
dbg_error_log( 'RRULE', "Date: " . $current->format('r'));
dbg_log_array( 'RRULE', "Errors:", $current->getLastErrors());
}
if ( isset($this->instances[$this->position]) || !$this->finished ) return true;
return false;
@ -814,7 +813,7 @@ class RepeatRule {
$this->current_base->modify( $this->frequency_string );
}
if ( $return_floating_times ) $this->current_base->setAsFloat();
if ( DEBUG_RRULE ) printf( "Getting more instances from: '%s' - %d, TZ: %s\n", $this->current_base->format('c'), count($this->instances), $this->current_base->getTimeZone() );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Getting more instances from: '%s' - %d, TZ: %s", $this->current_base->format('c'), count($this->instances), $this->current_base->getTimeZone() );
$this->current_set = array( clone($this->current_base) );
foreach( self::rrule_expand_limit($this->freq) AS $bytype => $action ) {
if ( isset($this->{$bytype}) ) {
@ -827,7 +826,7 @@ class RepeatRule {
if ( isset($this->bysetpos) ) $this->limit_bysetpos();
$position = count($this->instances) - 1;
if ( DEBUG_RRULE ) printf( "Inserting %d from current_set into position %d\n", count($this->current_set), $position + 1 );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Inserting %d from current_set into position %d", count($this->current_set), $position + 1 );
foreach( $this->current_set AS $k => $instance ) {
if ( $instance < $this->base ) continue;
if ( isset($this->until) && $instance > $this->until ) {
@ -842,7 +841,7 @@ class RepeatRule {
return;
}
$this->instances[$position] = $instance;
if ( DEBUG_RRULE ) printf( "Added date %s into position %d in current set\n", $instance->format('c'), $position );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Added date %s into position %d in current set", $instance->format('c'), $position );
}
}
}
@ -888,7 +887,7 @@ class RepeatRule {
foreach( $instances AS $k => $instance ) {
foreach( $this->bymonth AS $k => $month ) {
$expanded = $this->date_mask( clone($instance), null, $month, null, null, null, null);
if ( DEBUG_RRULE ) printf( "Expanded BYMONTH $month into date %s\n", $expanded->format('c') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Expanded BYMONTH $month into date %s", $expanded->format('c') );
$this->current_set[] = $expanded;
}
}
@ -901,10 +900,10 @@ class RepeatRule {
foreach( $this->bymonthday AS $k => $monthday ) {
$expanded = $this->date_mask( clone($instance), null, null, $monthday, null, null, null);
if ($monthday == -1 || $expanded->format('d') == $monthday) {
if ( DEBUG_RRULE ) printf( "Expanded BYMONTHDAY $monthday into date %s from %s\n", $expanded->format('c'), $instance->format('c') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Expanded BYMONTHDAY $monthday into date %s from %s", $expanded->format('c'), $instance->format('c') );
$this->current_set[] = $expanded;
} else {
if ( DEBUG_RRULE ) printf( "Expanded BYMONTHDAY $monthday into date %s from %s, which is not the same day of month, skipping.\n", $expanded->format('c'), $instance->format('c') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Expanded BYMONTHDAY $monthday into date %s from %s, which is not the same day of month, skipping.", $expanded->format('c'), $instance->format('c') );
}
}
}
@ -940,7 +939,7 @@ class RepeatRule {
$expanded = clone($day_in_week);
$expanded->modify( sprintf('+%d day', $offset) );
$this->current_set[] = $expanded;
if ( DEBUG_RRULE ) printf( "Expanded BYDAY(W) $weekday into date %s\n", $expanded->format('c') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Expanded BYDAY(W) $weekday into date %s", $expanded->format('c') );
}
}
@ -955,7 +954,7 @@ class RepeatRule {
$dow = self::rrule_day_number($matches[3]);
$first_dom = 1 + $dow - $dow_of_first; if ( $first_dom < 1 ) $first_dom +=7; // e.g. 1st=WE, dow=MO => 1+1-3=-1 => MO is 6th, etc.
$whichweek = intval($matches[2]);
if ( DEBUG_RRULE ) printf( "Expanding BYDAY(M) $weekday in month of %s\n", $first_of_month->format('c') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Expanding BYDAY(M) $weekday in month of %s", $first_of_month->format('c') );
if ( $whichweek > 0 ) {
$whichweek--;
$monthday = $first_dom;
@ -969,14 +968,14 @@ class RepeatRule {
}
if ( $monthday > 0 && $monthday <= $days_in_month ) {
$expanded = $this->date_mask( clone($day_in_month), null, null, $monthday, null, null, null);
if ( DEBUG_RRULE ) printf( "Expanded BYDAY(M) $weekday now $monthday into date %s\n", $expanded->format('c') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Expanded BYDAY(M) $weekday now $monthday into date %s", $expanded->format('c') );
$this->current_set[] = $expanded;
}
}
else {
for( $monthday = $first_dom; $monthday <= $days_in_month; $monthday += 7 ) {
$expanded = $this->date_mask( clone($day_in_month), null, null, $monthday, null, null, null);
if ( DEBUG_RRULE ) printf( "Expanded BYDAY(M) $weekday now $monthday into date %s\n", $expanded->format('c') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Expanded BYDAY(M) $weekday now $monthday into date %s", $expanded->format('c') );
$this->current_set[] = $expanded;
}
}
@ -996,7 +995,7 @@ class RepeatRule {
$dow = self::rrule_day_number($matches[3]);
$first_doy = 1 + $dow - $dow_of_first; if ( $first_doy < 1 ) $first_doy +=7; // e.g. 1st=WE, dow=MO => 1+1-3=-1 => MO is 6th, etc.
$whichweek = intval($matches[2]);
if ( DEBUG_RRULE ) printf( "Expanding BYDAY(Y) $weekday from date %s\n", $instance->format('c') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Expanding BYDAY(Y) $weekday from date %s", $instance->format('c') );
if ( $whichweek > 0 ) {
$whichweek--;
$yearday = $first_doy;
@ -1010,14 +1009,14 @@ class RepeatRule {
}
if ( $yearday > 0 && $yearday <= $days_in_year ) {
$expanded->modify(sprintf('+%d day', $yearday - 1));
if ( DEBUG_RRULE ) printf( "Expanded BYDAY(Y) $weekday now $yearday into date %s\n", $expanded->format('c') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Expanded BYDAY(Y) $weekday now $yearday into date %s", $expanded->format('c') );
$this->current_set[] = $expanded;
}
}
else {
$expanded->modify(sprintf('+%d day', $first_doy - 1));
for( $yearday = $first_doy; $yearday <= $days_in_year; $yearday += 7 ) {
if ( DEBUG_RRULE ) printf( "Expanded BYDAY(Y) $weekday now $yearday into date %s\n", $expanded->format('c') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Expanded BYDAY(Y) $weekday now $yearday into date %s", $expanded->format('c') );
$this->current_set[] = clone($expanded);
$expanded->modify('+1 week');
}
@ -1095,7 +1094,7 @@ class RepeatRule {
$this->current_set = array();
foreach( $instances AS $k => $instance ) {
foreach( $this->{$element_name} AS $k => $element_value ) {
if ( DEBUG_RRULE ) printf( "Limiting '$fmt_char' on '%s' => '%s' ?=? '%s' ? %s\n", $instance->format('c'), $instance->format($fmt_char), $element_value, ($instance->format($fmt_char) == $element_value ? 'Yes' : 'No') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Limiting '$fmt_char' on '%s' => '%s' ?=? '%s' ? %s", $instance->format('c'), $instance->format($fmt_char), $element_value, ($instance->format($fmt_char) == $element_value ? 'Yes' : 'No') );
if ( $instance->format($fmt_char) == $element_value ) $this->current_set[] = $instance;
}
}
@ -1108,7 +1107,7 @@ class RepeatRule {
foreach( $this->byday AS $k => $weekday ) {
$dow = self::rrule_day_number($weekday);
foreach( $instances AS $k => $instance ) {
if ( DEBUG_RRULE ) printf( "Limiting '$fmt_char' on '%s' => '%s' ?=? '%s' (%d) ? %s\n", $instance->format('c'), $instance->format($fmt_char), $weekday, $dow, ($instance->format($fmt_char) == $dow ? 'Yes' : 'No') );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Limiting '$fmt_char' on '%s' => '%s' ?=? '%s' (%d) ? %s", $instance->format('c'), $instance->format($fmt_char), $weekday, $dow, ($instance->format($fmt_char) == $dow ? 'Yes' : 'No') );
if ( $instance->format($fmt_char) == $dow ) $this->current_set[] = $instance;
}
}
@ -1127,7 +1126,7 @@ class RepeatRule {
$count = count($instances);
$this->current_set = array();
foreach( $this->bysetpos AS $k => $element_value ) {
if ( DEBUG_RRULE ) printf( "Limiting bysetpos %s of %d instances\n", $element_value, $count );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Limiting bysetpos %s of %d instances", $element_value, $count );
if ( $element_value > 0 ) {
$this->current_set[] = $instances[$element_value - 1];
}
@ -1199,20 +1198,20 @@ function rrule_expand( $dtstart, $property, $component, $range_end, $is_date=nul
if ( $return_floating_times ) $this_start->setAsFloat();
// if ( DEBUG_RRULE ) print_r( $this_start );
if ( DEBUG_RRULE ) printf( "RRULE: %s (floating: %s)\n", $recur, ($return_floating_times?"yes":"no") );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "%s (floating: %s)", $recur, ($return_floating_times?"yes":"no") );
$rule = new RepeatRule( $this_start, $recur, $is_date, $return_floating_times );
$i = 0;
if ( !isset($c->rrule_expansion_limit) ) $c->rrule_expansion_limit = 5000;
while( $date = $rule->next($return_floating_times) ) {
// if ( DEBUG_RRULE ) printf( "[%3d] %s\n", $i, $date->UTC() );
// if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "[%3d] %s", $i, $date->UTC() );
$expansion[$date->FloatOrUTC($return_floating_times)] = $component;
if ( $date > $range_end ) break;
if ( $i++ >= $c->rrule_expansion_limit ) {
dbg_error_log( 'ERROR', "Hit rrule expansion limit of ".$c->rrule_expansion_limit." on %s %s - increase rrule_expansion_limit in config to avoid events missing from freebusy", $component->GetType(), $component->GetProperty('UID'));
}
}
// if ( DEBUG_RRULE ) print_r( $expansion );
// if ( DEBUG_RRULE ) dbg_log_array( 'RRULE', 'expansion', $expansion );
return $expansion;
}
@ -1290,7 +1289,7 @@ function expand_event_instances( vComponent $vResource, $range_start = null, $ra
if ( !isset($dtstart_prop) ) continue;
$dtstart = new RepeatRuleDateTime( $dtstart_prop );
if ( $return_floating_times ) $dtstart->setAsFloat();
if ( DEBUG_RRULE ) printf( "Component is: %s (floating: %s)\n", $comp->GetType(), ($return_floating_times?"yes":"no") );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Component is: %s (floating: %s)", $comp->GetType(), ($return_floating_times?"yes":"no") );
$is_date = $dtstart->isDate();
$instances[$dtstart->FloatOrUTC($return_floating_times)] = $comp;
$rrule = $comp->GetProperty('RRULE');
@ -1304,7 +1303,7 @@ function expand_event_instances( vComponent $vResource, $range_start = null, $ra
$recur_utc = $recur_utc->FloatOrUTC($return_floating_times);
if ( isset($range) && $range == 'THISANDFUTURE' ) {
foreach( $instances AS $k => $v ) {
if ( DEBUG_RRULE ) printf( "Removing overridden instance at: $k\n" );
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Removing overridden instance at: $k" );
if ( $k >= $recur_utc ) unset($instances[$k]);
}
}
@ -1319,39 +1318,35 @@ function expand_event_instances( vComponent $vResource, $range_start = null, $ra
$summary = ( isset($p) ? $p->Value() : 'not set');
$p = $comp->GetProperty('UID');
$uid = ( isset($p) ? $p->Value() : 'not set');
printf( "Processing event '%s' with UID '%s' starting on %s\n",
dbg_error_log( 'RRULE', "Processing event '%s' with UID '%s' starting on %s",
$summary, $uid, $dtstart->FloatOrUTC($return_floating_times) );
print( "Instances at start");
dbg_error_log( 'RRULE', "Instances at start");
foreach( $instances AS $k => $v ) {
print ' : '.$k;
dbg_error_log( 'RRULE', ' : '.$k);
}
print "\n";
}
$instances += rrule_expand($dtstart, 'RRULE', $comp, $range_end, null, $return_floating_times, $fallback_tzid);
if ( DEBUG_RRULE ) {
print( "After rrule_expand");
dbg_error_log( 'RRULE', "After rrule_expand");
foreach( $instances AS $k => $v ) {
print ' : '.$k;
dbg_error_log ('RRULE', ' : '.$k);
}
print "\n";
}
$instances += rdate_expand($dtstart, 'RDATE', $comp, $range_end, null, $return_floating_times);
if ( DEBUG_RRULE ) {
print( "After rdate_expand");
dbg_error_log( 'RRULE', "After rdate_expand");
foreach( $instances AS $k => $v ) {
print ' : '.$k;
dbg_error_log ('RRULE', ' : '.$k);
}
print "\n";
}
foreach ( rdate_expand($dtstart, 'EXDATE', $comp, $range_end, null, $return_floating_times) AS $k => $v ) {
unset($instances[$k]);
}
if ( DEBUG_RRULE ) {
print( "After exdate_expand");
dbg_error_log( 'RRULE', "After exdate_expand");
foreach( $instances AS $k => $v ) {
print ' : '.$k;
dbg_error_log( 'RRULE', ' : '.$k);
}
print "\n";
}
}
@ -1362,7 +1357,7 @@ function expand_event_instances( vComponent $vResource, $range_start = null, $ra
$end_utc = $range_end->FloatOrUTC($return_floating_times);
foreach( $instances AS $utc => $comp ) {
if ( $utc > $end_utc ) {
if ( DEBUG_RRULE ) printf( "We're done: $utc is out of the range.\n");
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "We're done: $utc is out of the range.");
break;
}
@ -1393,7 +1388,7 @@ function expand_event_instances( vComponent $vResource, $range_start = null, $ra
if ( $utc < $start_utc ) {
if ( isset($early_start) && isset($last_duration) && $duration->equals($last_duration) ) {
if ( $utc < $early_start ) {
if ( DEBUG_RRULE ) printf( "Next please: $utc is before $early_start and before $start_utc.\n");
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Next please: $utc is before $early_start and before $start_utc.");
continue;
}
}
@ -1404,7 +1399,7 @@ function expand_event_instances( vComponent $vResource, $range_start = null, $ra
$early_start = $latest_start->FloatOrUTC($return_floating_times);
$last_duration = $duration;
if ( $utc < $early_start ) {
if ( DEBUG_RRULE ) printf( "Another please: $utc is before $early_start and before $start_utc.\n");
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Another please: $utc is before $early_start and before $start_utc.");
continue;
}
}
@ -1460,7 +1455,7 @@ function expand_event_instances( vComponent $vResource, $range_start = null, $ra
if ( !isset($new_components[$recurrence_id]) && $dtend < $start_utc ) continue; // End before start of range: skip that too.
if ( DEBUG_RRULE ) printf( "Replacing overridden instance at %s\n", $recurrence_id);
if ( DEBUG_RRULE ) dbg_error_log( 'RRULE', "Replacing overridden instance at %s", $recurrence_id);
$new_components[$recurrence_id] = $comp;
}
}