Skip to content

Commit

Permalink
feat: Improve log output (#27)
Browse files Browse the repository at this point in the history
  • Loading branch information
irvinlim authored Oct 26, 2024
1 parent 1cf15d5 commit 19ee594
Show file tree
Hide file tree
Showing 4 changed files with 170 additions and 14 deletions.
53 changes: 41 additions & 12 deletions pkg/backends/influxdb/backend.go
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ import (

"github.com/irvinlim/apple-health-ingester/pkg/backends"
"github.com/irvinlim/apple-health-ingester/pkg/healthautoexport"
utiltime "github.com/irvinlim/apple-health-ingester/pkg/util/time"
)

const (
Expand Down Expand Up @@ -59,7 +60,7 @@ func (b *Backend) Name() string {

func (b *Backend) Write(payload *healthautoexport.Payload, targetName string) error {
// Properly handle nil data.
if payload.Data == nil {
if payload == nil || payload.Data == nil {
log.WithFields(log.Fields{
"backend": b.Name(),
"target": targetName,
Expand All @@ -68,13 +69,17 @@ func (b *Backend) Write(payload *healthautoexport.Payload, targetName string) er
}

// Write metrics.
if err := b.writeMetrics(payload.Data.Metrics, targetName); err != nil {
return errors.Wrapf(err, "write metrics error")
if len(payload.Data.Metrics) > 0 {
if err := b.writeMetrics(payload.Data.Metrics, targetName); err != nil {
return errors.Wrapf(err, "write metrics error")
}
}

// Write workouts.
if err := b.writeWorkouts(payload.Data.Workouts, targetName); err != nil {
return errors.Wrapf(err, "write workouts error")
if len(payload.Data.Workouts) > 0 {
if err := b.writeWorkouts(payload.Data.Workouts, targetName); err != nil {
return errors.Wrapf(err, "write workouts error")
}
}

return nil
Expand All @@ -87,7 +92,6 @@ func (b *Backend) writeMetrics(metrics []*healthautoexport.Metric, targetName st
"num_metrics": len(metrics),
})

var count int
startTime := time.Now()
logger.Info("start writing all metrics")

Expand All @@ -96,32 +100,51 @@ func (b *Backend) writeMetrics(metrics []*healthautoexport.Metric, targetName st
}
tags = append(tags, b.staticTags...)

var info timeseriesInfo
for _, metric := range metrics {
points := b.getMetricPoints(metric, tags)
points, metricInfo := b.processMetricPoints(metric, tags)
if len(points) > 0 {
logger := logger.WithFields(log.Fields{
"metric_name": metric.Name,
"count": len(points),
"time_range": utiltime.FormatTimeRange(metricInfo.StartTime, metricInfo.EndTime, time.RFC3339),
})
startTime := time.Now()
count += len(points)
logger.Debug("writing metric points")
if err := b.client.WriteMetrics(b.ctx, points...); err != nil {
return errors.Wrapf(err, "write error for %v", metric.Name)
}

// Process info before moving on.
info.Count += metricInfo.Count
info.StartTime = utiltime.MinTimeNonZero(info.StartTime, metricInfo.StartTime)
info.EndTime = utiltime.MaxTime(info.EndTime, metricInfo.EndTime)

logger.WithField("elapsed", time.Since(startTime)).Debug("write metric points success")
}
}

logger.WithFields(log.Fields{
"points": count,
"elapsed": time.Since(startTime),
"points": info.Count,
"time_range": utiltime.FormatTimeRange(info.StartTime, info.EndTime, time.RFC3339),
"elapsed": time.Since(startTime),
}).Info("write all metrics success")

return nil
}

func (b *Backend) getMetricPoints(metric *healthautoexport.Metric, tags []lp.Tag) []*write.Point {
type timeseriesInfo struct {
// Earliest timestamp that is collected.
StartTime time.Time `json:"start_time"`
// Latest timestamp that is collected.
EndTime time.Time `json:"end_time"`
// Total number of points.
Count int `json:"count"`
}

func (b *Backend) processMetricPoints(metric *healthautoexport.Metric, tags []lp.Tag) ([]*write.Point, timeseriesInfo) {
var info timeseriesInfo

points := make([]*write.Point, 0, len(metric.Datapoints))
datapointMeasurement := GetUnitizedMeasurementName(metric.Name, metric)
for _, datum := range metric.Datapoints {
Expand All @@ -140,6 +163,12 @@ func (b *Backend) getMetricPoints(metric *healthautoexport.Metric, tags []lp.Tag
continue
}
point.SetTime(datum.Date.Time)

// Process info before moving on.
info.StartTime = utiltime.MinTimeNonZero(info.StartTime, datum.Date.Time)
info.EndTime = utiltime.MaxTime(info.EndTime, datum.Date.Time)
info.Count++

points = append(points, point)
}

Expand Down Expand Up @@ -174,7 +203,7 @@ func (b *Backend) getMetricPoints(metric *healthautoexport.Metric, tags []lp.Tag
}
}

return points
return points, info
}

func makeSleepPoint(measurement string, source string, value string,
Expand Down
14 changes: 12 additions & 2 deletions pkg/backends/influxdb/backend_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -24,14 +24,23 @@ func TestBackend(t *testing.T) {
wantMetrics []string
wantWorkouts []string
}{
{
name: "write nil payload",
payload: nil,
},
{
name: "write nil payload data",
payload: &healthautoexport.Payload{Data: nil},
},
{
name: "write active energy metrics",
target: "test",
payload: &healthautoexport.Payload{
Data: &healthautoexport.PayloadData{
Metrics: []*healthautoexport.Metric{fixtures.MetricActiveEnergy},
},
}, wantMetrics: []string{
},
wantMetrics: []string{
"active_energy_kJ,target_name=test qty=0.7685677437484512 1640275440000000000",
"active_energy_kJ,target_name=test qty=0.377848256251549 1640275500000000000",
},
Expand All @@ -43,7 +52,8 @@ func TestBackend(t *testing.T) {
Data: &healthautoexport.PayloadData{
Metrics: []*healthautoexport.Metric{fixtures.MetricBasalBodyTemperatureNoData},
},
}, wantMetrics: []string{},
},
wantMetrics: []string{},
},
{
name: "write aggregated sleep analysis metrics",
Expand Down
33 changes: 33 additions & 0 deletions pkg/util/time/time.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,33 @@
package time

import (
"fmt"
"time"
)

// MinTimeNonZero returns the smallest time.Time from the input timestamps, excluding zero times.
func MinTimeNonZero(ts ...time.Time) time.Time {
var minTime time.Time
for _, t := range ts {
if !t.IsZero() && (minTime.IsZero() || t.Before(minTime)) {
minTime = t
}
}
return minTime
}

// MaxTime returns the largest time.Time from the input timestamps.
func MaxTime(ts ...time.Time) time.Time {
var maxTime time.Time
for _, t := range ts {
if maxTime.IsZero() || t.After(maxTime) {
maxTime = t
}
}
return maxTime
}

// FormatTimeRange outputs a time range as a formatted string.
func FormatTimeRange(start, end time.Time, layout string) string {
return fmt.Sprintf("%v - %v", start.Format(layout), end.Format(layout))
}
84 changes: 84 additions & 0 deletions pkg/util/time/time_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,84 @@
package time

import (
"testing"
"time"
)

var (
ts1 = mktime("2024-10-24T17:58:09Z")
ts2 = mktime("2024-10-24T17:58:10Z")
tsNegative = mktime("1969-10-24T17:58:10Z")
)

func TestMinTimeNonZero(t *testing.T) {
tests := []struct {
name string
ts []time.Time
want time.Time
}{
{name: "no inputs"},
{name: "zero timestamp", ts: []time.Time{{}}},
{name: "non-zero timestamp", ts: []time.Time{ts1}, want: ts1},
{name: "multiple timestamps", ts: []time.Time{ts1, ts2}, want: ts1},
{name: "only negative timestamp", ts: []time.Time{tsNegative}, want: tsNegative},
{name: "negative timestamp in list", ts: []time.Time{ts1, tsNegative}, want: tsNegative},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
if got := MinTimeNonZero(tt.ts...); !got.Equal(tt.want) {
t.Errorf("MinTimeNonZero not equal, want %v got %v", tt.want, got)
}
})
}
}

func TestMaxTime(t *testing.T) {
tests := []struct {
name string
ts []time.Time
want time.Time
}{
{name: "no inputs"},
{name: "zero timestamp", ts: []time.Time{{}}},
{name: "non-zero timestamp", ts: []time.Time{ts1}, want: ts1},
{name: "multiple timestamps", ts: []time.Time{ts1, ts2}, want: ts2},
{name: "only negative timestamp", ts: []time.Time{tsNegative}, want: tsNegative},
{name: "negative timestamp in list", ts: []time.Time{ts1, tsNegative}, want: ts1},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
if got := MaxTime(tt.ts...); !got.Equal(tt.want) {
t.Errorf("MinTimeNonZero not equal, want %v got %v", tt.want, got)
}
})
}
}

func TestFormatTimeRange(t *testing.T) {
tests := []struct {
name string
start time.Time
end time.Time
layout string
want string
}{
{name: "basic test", start: ts1, end: ts2, layout: time.RFC3339, want: "2024-10-24T17:58:09Z - 2024-10-24T17:58:10Z"},
{name: "custom time format", start: ts1, end: ts2, layout: time.DateTime, want: "2024-10-24 17:58:09 - 2024-10-24 17:58:10"},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
if got := FormatTimeRange(tt.start, tt.end, tt.layout); got != tt.want {
t.Errorf("FormatTimeRange() = %v, want %v", got, tt.want)
}
})
}
}

func mktime(ts string) time.Time {
t, err := time.Parse(time.RFC3339, ts)
if err != nil {
panic(err)
}
return t
}

0 comments on commit 19ee594

Please sign in to comment.