Skip to content

Commit 29a1f59

Browse files
wangbaolin719alexandrebelloni
wangbaolin719
authored and
alexandrebelloni
committed
rtc: Add tracepoints for RTC system
It will be more helpful to add some tracepoints to track RTC actions when debugging RTC driver. Below sample is that we set/read the RTC time, then set 2 alarms, so we can see the trace logs: set/read RTC time: kworker/0:1-67 [000] 21.814245: rtc_set_time: UTC (1510301580) (0) kworker/0:1-67 [000] 21.814312: rtc_read_time: UTC (1510301580) (0) set the first alarm timer: kworker/0:1-67 [000] 21.829238: rtc_timer_enqueue: RTC timer:(ffffffc15eb49bc8) expires:1510301700000000000 period:0 kworker/0:1-67 [000] 22.018279: rtc_set_alarm: UTC (1510301700) (0) set the second alarm timer: kworker/0:1-67 [000] 22.230284: rtc_timer_enqueue: RTC timer:(ffffff80088e6430) expires:1510301820000000000 period:0 the first alarm timer was expired: kworker/0:1-67 [000] 145.155584: rtc_timer_dequeue: RTC timer:(ffffffc15eb49bc8) expires:1510301700000000000 period:0 kworker/0:1-67 [000] 145.155593: rtc_timer_fired: RTC timer:(ffffffc15eb49bc8) expires:1510301700000000000 period:0 kworker/0:1-67 [000] 145.172504: rtc_set_alarm: UTC (1510301820) (0) the second alarm timer was expired: kworker/0:1-67 [000] 269.102353: rtc_timer_dequeue: RTC timer:(ffffff80088e6430) expires:1510301820000000000 period:0 kworker/0:1-67 [000] 269.102360: rtc_timer_fired: RTC timer:(ffffff80088e6430) expires:1510301820000000000 period:0 disable alarm irq: kworker/0:1-67 [000] 269.102469: rtc_alarm_irq_enable: disable RTC alarm IRQ (0) Signed-off-by: Baolin Wang <[email protected]> Signed-off-by: Alexandre Belloni <[email protected]>
1 parent 7928b2c commit 29a1f59

File tree

2 files changed

+236
-0
lines changed

2 files changed

+236
-0
lines changed

‎drivers/rtc/interface.c

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,9 @@
1717
#include <linux/log2.h>
1818
#include <linux/workqueue.h>
1919

20+
#define CREATE_TRACE_POINTS
21+
#include <trace/events/rtc.h>
22+
2023
static int rtc_timer_enqueue(struct rtc_device *rtc, struct rtc_timer *timer);
2124
static void rtc_timer_remove(struct rtc_device *rtc, struct rtc_timer *timer);
2225

@@ -53,6 +56,8 @@ int rtc_read_time(struct rtc_device *rtc, struct rtc_time *tm)
5356

5457
err = __rtc_read_time(rtc, tm);
5558
mutex_unlock(&rtc->ops_lock);
59+
60+
trace_rtc_read_time(rtc_tm_to_time64(tm), err);
5661
return err;
5762
}
5863
EXPORT_SYMBOL_GPL(rtc_read_time);
@@ -87,6 +92,8 @@ int rtc_set_time(struct rtc_device *rtc, struct rtc_time *tm)
8792
mutex_unlock(&rtc->ops_lock);
8893
/* A timer might have just expired */
8994
schedule_work(&rtc->irqwork);
95+
96+
trace_rtc_set_time(rtc_tm_to_time64(tm), err);
9097
return err;
9198
}
9299
EXPORT_SYMBOL_GPL(rtc_set_time);
@@ -119,6 +126,8 @@ static int rtc_read_alarm_internal(struct rtc_device *rtc, struct rtc_wkalrm *al
119126
}
120127

121128
mutex_unlock(&rtc->ops_lock);
129+
130+
trace_rtc_read_alarm(rtc_tm_to_time64(&alarm->time), err);
122131
return err;
123132
}
124133

@@ -316,6 +325,7 @@ int rtc_read_alarm(struct rtc_device *rtc, struct rtc_wkalrm *alarm)
316325
}
317326
mutex_unlock(&rtc->ops_lock);
318327

328+
trace_rtc_read_alarm(rtc_tm_to_time64(&alarm->time), err);
319329
return err;
320330
}
321331
EXPORT_SYMBOL_GPL(rtc_read_alarm);
@@ -352,6 +362,7 @@ static int __rtc_set_alarm(struct rtc_device *rtc, struct rtc_wkalrm *alarm)
352362
else
353363
err = rtc->ops->set_alarm(rtc->dev.parent, alarm);
354364

365+
trace_rtc_set_alarm(rtc_tm_to_time64(&alarm->time), err);
355366
return err;
356367
}
357368

@@ -406,6 +417,7 @@ int rtc_initialize_alarm(struct rtc_device *rtc, struct rtc_wkalrm *alarm)
406417

407418
rtc->aie_timer.enabled = 1;
408419
timerqueue_add(&rtc->timerqueue, &rtc->aie_timer.node);
420+
trace_rtc_timer_enqueue(&rtc->aie_timer);
409421
}
410422
mutex_unlock(&rtc->ops_lock);
411423
return err;
@@ -435,6 +447,8 @@ int rtc_alarm_irq_enable(struct rtc_device *rtc, unsigned int enabled)
435447
err = rtc->ops->alarm_irq_enable(rtc->dev.parent, enabled);
436448

437449
mutex_unlock(&rtc->ops_lock);
450+
451+
trace_rtc_alarm_irq_enable(enabled, err);
438452
return err;
439453
}
440454
EXPORT_SYMBOL_GPL(rtc_alarm_irq_enable);
@@ -709,6 +723,8 @@ int rtc_irq_set_state(struct rtc_device *rtc, struct rtc_task *task, int enabled
709723
rtc->pie_enabled = enabled;
710724
}
711725
spin_unlock_irqrestore(&rtc->irq_task_lock, flags);
726+
727+
trace_rtc_irq_set_state(enabled, err);
712728
return err;
713729
}
714730
EXPORT_SYMBOL_GPL(rtc_irq_set_state);
@@ -745,6 +761,8 @@ int rtc_irq_set_freq(struct rtc_device *rtc, struct rtc_task *task, int freq)
745761
}
746762
}
747763
spin_unlock_irqrestore(&rtc->irq_task_lock, flags);
764+
765+
trace_rtc_irq_set_freq(freq, err);
748766
return err;
749767
}
750768
EXPORT_SYMBOL_GPL(rtc_irq_set_freq);
@@ -779,6 +797,7 @@ static int rtc_timer_enqueue(struct rtc_device *rtc, struct rtc_timer *timer)
779797
}
780798

781799
timerqueue_add(&rtc->timerqueue, &timer->node);
800+
trace_rtc_timer_enqueue(timer);
782801
if (!next || ktime_before(timer->node.expires, next->expires)) {
783802
struct rtc_wkalrm alarm;
784803
int err;
@@ -790,6 +809,7 @@ static int rtc_timer_enqueue(struct rtc_device *rtc, struct rtc_timer *timer)
790809
schedule_work(&rtc->irqwork);
791810
} else if (err) {
792811
timerqueue_del(&rtc->timerqueue, &timer->node);
812+
trace_rtc_timer_dequeue(timer);
793813
timer->enabled = 0;
794814
return err;
795815
}
@@ -803,6 +823,7 @@ static void rtc_alarm_disable(struct rtc_device *rtc)
803823
return;
804824

805825
rtc->ops->alarm_irq_enable(rtc->dev.parent, false);
826+
trace_rtc_alarm_irq_enable(0, 0);
806827
}
807828

808829
/**
@@ -821,6 +842,7 @@ static void rtc_timer_remove(struct rtc_device *rtc, struct rtc_timer *timer)
821842
{
822843
struct timerqueue_node *next = timerqueue_getnext(&rtc->timerqueue);
823844
timerqueue_del(&rtc->timerqueue, &timer->node);
845+
trace_rtc_timer_dequeue(timer);
824846
timer->enabled = 0;
825847
if (next == &timer->node) {
826848
struct rtc_wkalrm alarm;
@@ -871,16 +893,19 @@ void rtc_timer_do_work(struct work_struct *work)
871893
/* expire timer */
872894
timer = container_of(next, struct rtc_timer, node);
873895
timerqueue_del(&rtc->timerqueue, &timer->node);
896+
trace_rtc_timer_dequeue(timer);
874897
timer->enabled = 0;
875898
if (timer->task.func)
876899
timer->task.func(timer->task.private_data);
877900

901+
trace_rtc_timer_fired(timer);
878902
/* Re-add/fwd periodic timers */
879903
if (ktime_to_ns(timer->period)) {
880904
timer->node.expires = ktime_add(timer->node.expires,
881905
timer->period);
882906
timer->enabled = 1;
883907
timerqueue_add(&rtc->timerqueue, &timer->node);
908+
trace_rtc_timer_enqueue(timer);
884909
}
885910
}
886911

@@ -902,6 +927,7 @@ void rtc_timer_do_work(struct work_struct *work)
902927

903928
timer = container_of(next, struct rtc_timer, node);
904929
timerqueue_del(&rtc->timerqueue, &timer->node);
930+
trace_rtc_timer_dequeue(timer);
905931
timer->enabled = 0;
906932
dev_err(&rtc->dev, "__rtc_set_alarm: err=%d\n", err);
907933
goto again;
@@ -992,6 +1018,8 @@ int rtc_read_offset(struct rtc_device *rtc, long *offset)
9921018
mutex_lock(&rtc->ops_lock);
9931019
ret = rtc->ops->read_offset(rtc->dev.parent, offset);
9941020
mutex_unlock(&rtc->ops_lock);
1021+
1022+
trace_rtc_read_offset(*offset, ret);
9951023
return ret;
9961024
}
9971025

@@ -1025,5 +1053,7 @@ int rtc_set_offset(struct rtc_device *rtc, long offset)
10251053
mutex_lock(&rtc->ops_lock);
10261054
ret = rtc->ops->set_offset(rtc->dev.parent, offset);
10271055
mutex_unlock(&rtc->ops_lock);
1056+
1057+
trace_rtc_set_offset(offset, ret);
10281058
return ret;
10291059
}

‎include/trace/events/rtc.h

Lines changed: 206 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,206 @@
1+
#undef TRACE_SYSTEM
2+
#define TRACE_SYSTEM rtc
3+
4+
#if !defined(_TRACE_RTC_H) || defined(TRACE_HEADER_MULTI_READ)
5+
#define _TRACE_RTC_H
6+
7+
#include <linux/rtc.h>
8+
#include <linux/tracepoint.h>
9+
10+
DECLARE_EVENT_CLASS(rtc_time_alarm_class,
11+
12+
TP_PROTO(time64_t secs, int err),
13+
14+
TP_ARGS(secs, err),
15+
16+
TP_STRUCT__entry(
17+
__field(time64_t, secs)
18+
__field(int, err)
19+
),
20+
21+
TP_fast_assign(
22+
__entry->secs = secs;
23+
__entry->err = err;
24+
),
25+
26+
TP_printk("UTC (%lld) (%d)",
27+
__entry->secs, __entry->err
28+
)
29+
);
30+
31+
DEFINE_EVENT(rtc_time_alarm_class, rtc_set_time,
32+
33+
TP_PROTO(time64_t secs, int err),
34+
35+
TP_ARGS(secs, err)
36+
);
37+
38+
DEFINE_EVENT(rtc_time_alarm_class, rtc_read_time,
39+
40+
TP_PROTO(time64_t secs, int err),
41+
42+
TP_ARGS(secs, err)
43+
);
44+
45+
DEFINE_EVENT(rtc_time_alarm_class, rtc_set_alarm,
46+
47+
TP_PROTO(time64_t secs, int err),
48+
49+
TP_ARGS(secs, err)
50+
);
51+
52+
DEFINE_EVENT(rtc_time_alarm_class, rtc_read_alarm,
53+
54+
TP_PROTO(time64_t secs, int err),
55+
56+
TP_ARGS(secs, err)
57+
);
58+
59+
TRACE_EVENT(rtc_irq_set_freq,
60+
61+
TP_PROTO(int freq, int err),
62+
63+
TP_ARGS(freq, err),
64+
65+
TP_STRUCT__entry(
66+
__field(int, freq)
67+
__field(int, err)
68+
),
69+
70+
TP_fast_assign(
71+
__entry->freq = freq;
72+
__entry->err = err;
73+
),
74+
75+
TP_printk("set RTC periodic IRQ frequency:%u (%d)",
76+
__entry->freq, __entry->err
77+
)
78+
);
79+
80+
TRACE_EVENT(rtc_irq_set_state,
81+
82+
TP_PROTO(int enabled, int err),
83+
84+
TP_ARGS(enabled, err),
85+
86+
TP_STRUCT__entry(
87+
__field(int, enabled)
88+
__field(int, err)
89+
),
90+
91+
TP_fast_assign(
92+
__entry->enabled = enabled;
93+
__entry->err = err;
94+
),
95+
96+
TP_printk("%s RTC 2^N Hz periodic IRQs (%d)",
97+
__entry->enabled ? "enable" : "disable",
98+
__entry->err
99+
)
100+
);
101+
102+
TRACE_EVENT(rtc_alarm_irq_enable,
103+
104+
TP_PROTO(unsigned int enabled, int err),
105+
106+
TP_ARGS(enabled, err),
107+
108+
TP_STRUCT__entry(
109+
__field(unsigned int, enabled)
110+
__field(int, err)
111+
),
112+
113+
TP_fast_assign(
114+
__entry->enabled = enabled;
115+
__entry->err = err;
116+
),
117+
118+
TP_printk("%s RTC alarm IRQ (%d)",
119+
__entry->enabled ? "enable" : "disable",
120+
__entry->err
121+
)
122+
);
123+
124+
DECLARE_EVENT_CLASS(rtc_offset_class,
125+
126+
TP_PROTO(long offset, int err),
127+
128+
TP_ARGS(offset, err),
129+
130+
TP_STRUCT__entry(
131+
__field(long, offset)
132+
__field(int, err)
133+
),
134+
135+
TP_fast_assign(
136+
__entry->offset = offset;
137+
__entry->err = err;
138+
),
139+
140+
TP_printk("RTC offset: %ld (%d)",
141+
__entry->offset, __entry->err
142+
)
143+
);
144+
145+
DEFINE_EVENT(rtc_offset_class, rtc_set_offset,
146+
147+
TP_PROTO(long offset, int err),
148+
149+
TP_ARGS(offset, err)
150+
);
151+
152+
DEFINE_EVENT(rtc_offset_class, rtc_read_offset,
153+
154+
TP_PROTO(long offset, int err),
155+
156+
TP_ARGS(offset, err)
157+
);
158+
159+
DECLARE_EVENT_CLASS(rtc_timer_class,
160+
161+
TP_PROTO(struct rtc_timer *timer),
162+
163+
TP_ARGS(timer),
164+
165+
TP_STRUCT__entry(
166+
__field(struct rtc_timer *, timer)
167+
__field(ktime_t, expires)
168+
__field(ktime_t, period)
169+
),
170+
171+
TP_fast_assign(
172+
__entry->timer = timer;
173+
__entry->expires = timer->node.expires;
174+
__entry->period = timer->period;
175+
),
176+
177+
TP_printk("RTC timer:(%p) expires:%lld period:%lld",
178+
__entry->timer, __entry->expires, __entry->period
179+
)
180+
);
181+
182+
DEFINE_EVENT(rtc_timer_class, rtc_timer_enqueue,
183+
184+
TP_PROTO(struct rtc_timer *timer),
185+
186+
TP_ARGS(timer)
187+
);
188+
189+
DEFINE_EVENT(rtc_timer_class, rtc_timer_dequeue,
190+
191+
TP_PROTO(struct rtc_timer *timer),
192+
193+
TP_ARGS(timer)
194+
);
195+
196+
DEFINE_EVENT(rtc_timer_class, rtc_timer_fired,
197+
198+
TP_PROTO(struct rtc_timer *timer),
199+
200+
TP_ARGS(timer)
201+
);
202+
203+
#endif /* _TRACE_RTC_H */
204+
205+
/* This part must be outside protection */
206+
#include <trace/define_trace.h>

0 commit comments

Comments
 (0)