Hello Amit/Daniel,
I think there is a bug in idlestat due to which it reports wrong irq counts in output.
Log is 9.998478 secs long with 1518 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 455 9921571.00 21805.65 0.00 176303.00 cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 10 2032.00 203.20 27.00 1219.00 C3-SNB 2 5909.00 2954.50 161.00 5748.00 C6-SNB 320 9978546.00 31182.96 48.00 237467.00 cpu0 wakeups name count irq040 eth0 150 cpu1@state hits total(us) avg(us) min(us) max(us) C6-SNB 140 9981689.00 71297.78 80.00 311045.00 cpu1 wakeups name count irq018 ata_piix 19 cpu2@state hits total(us) avg(us) min(us) max(us) C6-SNB 87 9995015.00 114885.23 11935.00 323889.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 383.00 127.67 122.00 139.00 C6-SNB 97 9954601.00 102624.75 51.00 323890.00 cpu3 wakeups name count
from my trace output file -
grep 'irq=40' /tmp/trace | wc -l returns 308. Half should be the irq count = 154. grep 'irq=18' /tmp/trace | wc -l returns 80. Half should be irq count = 40.
I have made a patch to fix the issue below.
Below check causes early unwanted return from store_irq() function. In fact, the whole 'wakeirq' member seems unnecessary, hence the related code.
if (cstates->wakeirq != NULL) return 0;
Would you please check?
diff --git a/idlestat.c b/idlestat.c index 5e8f8d5..d4ea859 100644 --- a/idlestat.c +++ b/idlestat.c @@ -654,7 +654,6 @@ static int store_data(double time, int state, int cpu, cstates->cstate[state].data = data; cstates->cstate_max = MAX(cstates->cstate_max, state); cstates->last_cstate = state; - cstates->wakeirq = NULL;
/* update P-state stats if supported */ if (pstate) @@ -684,9 +683,6 @@ static int store_irq(int cpu, int irqid, char *irqname, struct wakeup_irq *irqinfo; struct wakeup_info *wakeinfo = &cstates->wakeinfo;
- if (cstates->wakeirq != NULL) - return 0; - irqinfo = find_irqinfo(wakeinfo, irqid); if (NULL == irqinfo) { irqinfo = realloc(wakeinfo->irqinfo, @@ -705,8 +701,6 @@ static int store_irq(int cpu, int irqid, char *irqname,
irqinfo->count++;
- cstates->wakeirq = irqinfo; - return 0; }
diff --git a/idlestat.h b/idlestat.h index 1977ab4..bb27e3a 100644 --- a/idlestat.h +++ b/idlestat.h @@ -76,7 +76,6 @@ struct cpuidle_cstates { struct wakeup_info wakeinfo; int last_cstate; int cstate_max; - struct wakeup_irq *wakeirq; };
struct cpufreq_pstate {
-- Thanks, -Meraj
Hi Meraj, We only want to count the wakeup sources (eg: irq/ipi etc *). Hence the total count for an irq /ipi can differ.
* Note there can be spurious wakeups in some systems. ie: core exiting idle without an irq.
Thanks Sandeep
On 20 June 2014 13:58, Mohammad Merajul Islam Molla meraj.enigma@gmail.com wrote:
Hello Amit/Daniel,
I think there is a bug in idlestat due to which it reports wrong irq counts in output.
Log is 9.998478 secs long with 1518 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 455 9921571.00 21805.65 0.00 176303.00 cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 10 2032.00 203.20 27.00 1219.00 C3-SNB 2 5909.00 2954.50 161.00 5748.00 C6-SNB 320 9978546.00 31182.96 48.00 237467.00 cpu0 wakeups name count irq040 eth0 150 cpu1@state hits total(us) avg(us) min(us) max(us) C6-SNB 140 9981689.00 71297.78 80.00 311045.00 cpu1 wakeups name count irq018 ata_piix 19 cpu2@state hits total(us) avg(us) min(us) max(us) C6-SNB 87 9995015.00 114885.23 11935.00 323889.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 383.00 127.67 122.00 139.00 C6-SNB 97 9954601.00 102624.75 51.00 323890.00 cpu3 wakeups name count
from my trace output file -
grep 'irq=40' /tmp/trace | wc -l returns 308. Half should be the irq count = 154. grep 'irq=18' /tmp/trace | wc -l returns 80. Half should be irq count = 40.
I have made a patch to fix the issue below.
Below check causes early unwanted return from store_irq() function. In fact, the whole 'wakeirq' member seems unnecessary, hence the related code.
if (cstates->wakeirq != NULL) return 0;
Would you please check?
diff --git a/idlestat.c b/idlestat.c index 5e8f8d5..d4ea859 100644 --- a/idlestat.c +++ b/idlestat.c @@ -654,7 +654,6 @@ static int store_data(double time, int state, int cpu, cstates->cstate[state].data = data; cstates->cstate_max = MAX(cstates->cstate_max, state); cstates->last_cstate = state;
cstates->wakeirq = NULL; /* update P-state stats if supported */ if (pstate)
@@ -684,9 +683,6 @@ static int store_irq(int cpu, int irqid, char *irqname, struct wakeup_irq *irqinfo; struct wakeup_info *wakeinfo = &cstates->wakeinfo;
if (cstates->wakeirq != NULL)
return 0;
irqinfo = find_irqinfo(wakeinfo, irqid); if (NULL == irqinfo) { irqinfo = realloc(wakeinfo->irqinfo,
@@ -705,8 +701,6 @@ static int store_irq(int cpu, int irqid, char *irqname,
irqinfo->count++;
cstates->wakeirq = irqinfo;
return 0;
}
diff --git a/idlestat.h b/idlestat.h index 1977ab4..bb27e3a 100644 --- a/idlestat.h +++ b/idlestat.h @@ -76,7 +76,6 @@ struct cpuidle_cstates { struct wakeup_info wakeinfo; int last_cstate; int cstate_max;
struct wakeup_irq *wakeirq;
};
struct cpufreq_pstate {
-- Thanks, -Meraj
linaro-dev mailing list linaro-dev@lists.linaro.org http://lists.linaro.org/mailman/listinfo/linaro-dev
Hello Sandeep,
Thanks for reply.
I meant to say I counted "irq_handler_entry: irq=40 name=eth0" and "irq_handler_entry: irq=18 name=ata_piix" instances in trace file (not just grep irq=40/irq=18 as I mentioned before, sorry for the confusion) and that count does not match with the output by idlestat.
Should not they match?
-- Thanks, -Meraj
On Fri, Jun 20, 2014 at 2:42 PM, Sandeep Tripathy sandeep.tripathy@linaro.org wrote:
Hi Meraj, We only want to count the wakeup sources (eg: irq/ipi etc *). Hence the total count for an irq /ipi can differ.
- Note there can be spurious wakeups in some systems. ie: core exiting idle
without an irq.
Thanks Sandeep
On 20 June 2014 13:58, Mohammad Merajul Islam Molla meraj.enigma@gmail.com wrote:
Hello Amit/Daniel,
I think there is a bug in idlestat due to which it reports wrong irq counts in output.
Log is 9.998478 secs long with 1518 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 455 9921571.00 21805.65 0.00 176303.00 cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 10 2032.00 203.20 27.00 1219.00 C3-SNB 2 5909.00 2954.50 161.00 5748.00 C6-SNB 320 9978546.00 31182.96 48.00 237467.00 cpu0 wakeups name count irq040 eth0 150 cpu1@state hits total(us) avg(us) min(us) max(us) C6-SNB 140 9981689.00 71297.78 80.00 311045.00 cpu1 wakeups name count irq018 ata_piix 19 cpu2@state hits total(us) avg(us) min(us) max(us) C6-SNB 87 9995015.00 114885.23 11935.00 323889.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 383.00 127.67 122.00 139.00 C6-SNB 97 9954601.00 102624.75 51.00 323890.00 cpu3 wakeups name count
from my trace output file -
grep 'irq=40' /tmp/trace | wc -l returns 308. Half should be the irq count = 154. grep 'irq=18' /tmp/trace | wc -l returns 80. Half should be irq count = 40.
I have made a patch to fix the issue below.
Below check causes early unwanted return from store_irq() function. In fact, the whole 'wakeirq' member seems unnecessary, hence the related code.
if (cstates->wakeirq != NULL) return 0;
Would you please check?
diff --git a/idlestat.c b/idlestat.c index 5e8f8d5..d4ea859 100644 --- a/idlestat.c +++ b/idlestat.c @@ -654,7 +654,6 @@ static int store_data(double time, int state, int cpu, cstates->cstate[state].data = data; cstates->cstate_max = MAX(cstates->cstate_max, state); cstates->last_cstate = state;
cstates->wakeirq = NULL; /* update P-state stats if supported */ if (pstate)
@@ -684,9 +683,6 @@ static int store_irq(int cpu, int irqid, char *irqname, struct wakeup_irq *irqinfo; struct wakeup_info *wakeinfo = &cstates->wakeinfo;
if (cstates->wakeirq != NULL)
return 0;
irqinfo = find_irqinfo(wakeinfo, irqid); if (NULL == irqinfo) { irqinfo = realloc(wakeinfo->irqinfo,
@@ -705,8 +701,6 @@ static int store_irq(int cpu, int irqid, char *irqname,
irqinfo->count++;
cstates->wakeirq = irqinfo;
return 0;
}
diff --git a/idlestat.h b/idlestat.h index 1977ab4..bb27e3a 100644 --- a/idlestat.h +++ b/idlestat.h @@ -76,7 +76,6 @@ struct cpuidle_cstates { struct wakeup_info wakeinfo; int last_cstate; int cstate_max;
struct wakeup_irq *wakeirq;
};
struct cpufreq_pstate {
-- Thanks, -Meraj
linaro-dev mailing list linaro-dev@lists.linaro.org http://lists.linaro.org/mailman/listinfo/linaro-dev
Hi Meraj, As mentioned earlier, we are counting only the interrupts which caused the core to wake up from one of the c-states. This count can vary from the total number of interrupts to that core. When the core is already running we do not care about number of interrupts its getting. Thanks Sandeep
On 20 June 2014 14:39, Mohammad Merajul Islam Molla meraj.enigma@gmail.com wrote:
Hello Sandeep,
Thanks for reply.
I meant to say I counted "irq_handler_entry: irq=40 name=eth0" and "irq_handler_entry: irq=18 name=ata_piix" instances in trace file (not just grep irq=40/irq=18 as I mentioned before, sorry for the confusion) and that count does not match with the output by idlestat.
Should not they match?
-- Thanks, -Meraj
On Fri, Jun 20, 2014 at 2:42 PM, Sandeep Tripathy sandeep.tripathy@linaro.org wrote:
Hi Meraj, We only want to count the wakeup sources (eg: irq/ipi etc *). Hence the total count for an irq /ipi can differ.
- Note there can be spurious wakeups in some systems. ie: core exiting
idle
without an irq.
Thanks Sandeep
On 20 June 2014 13:58, Mohammad Merajul Islam Molla <
meraj.enigma@gmail.com>
wrote:
Hello Amit/Daniel,
I think there is a bug in idlestat due to which it reports wrong irq counts in output.
Log is 9.998478 secs long with 1518 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 455 9921571.00 21805.65 0.00
176303.00
cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 10 2032.00 203.20 27.00 1219.00 C3-SNB 2 5909.00 2954.50 161.00 5748.00 C6-SNB 320 9978546.00 31182.96 48.00
237467.00
cpu0 wakeups name count irq040 eth0 150 cpu1@state hits total(us) avg(us) min(us) max(us) C6-SNB 140 9981689.00 71297.78 80.00
311045.00
cpu1 wakeups name count irq018 ata_piix 19 cpu2@state hits total(us) avg(us) min(us) max(us) C6-SNB 87 9995015.00 114885.23 11935.00 323889.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 383.00 127.67 122.00 139.00 C6-SNB 97 9954601.00 102624.75 51.00
323890.00
cpu3 wakeups name count
from my trace output file -
grep 'irq=40' /tmp/trace | wc -l returns 308. Half should be the irq count = 154. grep 'irq=18' /tmp/trace | wc -l returns 80. Half should be irq count = 40.
I have made a patch to fix the issue below.
Below check causes early unwanted return from store_irq() function. In fact, the whole 'wakeirq' member seems unnecessary, hence the related code.
if (cstates->wakeirq != NULL) return 0;
Would you please check?
diff --git a/idlestat.c b/idlestat.c index 5e8f8d5..d4ea859 100644 --- a/idlestat.c +++ b/idlestat.c @@ -654,7 +654,6 @@ static int store_data(double time, int state, int
cpu,
cstates->cstate[state].data = data; cstates->cstate_max = MAX(cstates->cstate_max, state); cstates->last_cstate = state;
cstates->wakeirq = NULL; /* update P-state stats if supported */ if (pstate)
@@ -684,9 +683,6 @@ static int store_irq(int cpu, int irqid, char *irqname, struct wakeup_irq *irqinfo; struct wakeup_info *wakeinfo = &cstates->wakeinfo;
if (cstates->wakeirq != NULL)
return 0;
irqinfo = find_irqinfo(wakeinfo, irqid); if (NULL == irqinfo) { irqinfo = realloc(wakeinfo->irqinfo,
@@ -705,8 +701,6 @@ static int store_irq(int cpu, int irqid, char *irqname,
irqinfo->count++;
cstates->wakeirq = irqinfo;
return 0;
}
diff --git a/idlestat.h b/idlestat.h index 1977ab4..bb27e3a 100644 --- a/idlestat.h +++ b/idlestat.h @@ -76,7 +76,6 @@ struct cpuidle_cstates { struct wakeup_info wakeinfo; int last_cstate; int cstate_max;
struct wakeup_irq *wakeirq;
};
struct cpufreq_pstate {
-- Thanks, -Meraj
linaro-dev mailing list linaro-dev@lists.linaro.org http://lists.linaro.org/mailman/listinfo/linaro-dev
Got it, thanks!
On Fri, Jun 20, 2014 at 3:20 PM, Sandeep Tripathy sandeep.tripathy@linaro.org wrote:
Hi Meraj, As mentioned earlier, we are counting only the interrupts which caused the core to wake up from one of the c-states. This count can vary from the total number of interrupts to that core. When the core is already running we do not care about number of interrupts its getting. Thanks Sandeep
On 20 June 2014 14:39, Mohammad Merajul Islam Molla meraj.enigma@gmail.com wrote:
Hello Sandeep,
Thanks for reply.
I meant to say I counted "irq_handler_entry: irq=40 name=eth0" and "irq_handler_entry: irq=18 name=ata_piix" instances in trace file (not just grep irq=40/irq=18 as I mentioned before, sorry for the confusion) and that count does not match with the output by idlestat.
Should not they match?
-- Thanks, -Meraj
On Fri, Jun 20, 2014 at 2:42 PM, Sandeep Tripathy sandeep.tripathy@linaro.org wrote:
Hi Meraj, We only want to count the wakeup sources (eg: irq/ipi etc *). Hence the total count for an irq /ipi can differ.
- Note there can be spurious wakeups in some systems. ie: core exiting
idle without an irq.
Thanks Sandeep
On 20 June 2014 13:58, Mohammad Merajul Islam Molla meraj.enigma@gmail.com wrote:
Hello Amit/Daniel,
I think there is a bug in idlestat due to which it reports wrong irq counts in output.
Log is 9.998478 secs long with 1518 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 455 9921571.00 21805.65 0.00 176303.00 cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 10 2032.00 203.20 27.00 1219.00 C3-SNB 2 5909.00 2954.50 161.00 5748.00 C6-SNB 320 9978546.00 31182.96 48.00 237467.00 cpu0 wakeups name count irq040 eth0 150 cpu1@state hits total(us) avg(us) min(us) max(us) C6-SNB 140 9981689.00 71297.78 80.00 311045.00 cpu1 wakeups name count irq018 ata_piix 19 cpu2@state hits total(us) avg(us) min(us) max(us) C6-SNB 87 9995015.00 114885.23 11935.00 323889.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 383.00 127.67 122.00 139.00 C6-SNB 97 9954601.00 102624.75 51.00 323890.00 cpu3 wakeups name count
from my trace output file -
grep 'irq=40' /tmp/trace | wc -l returns 308. Half should be the irq count = 154. grep 'irq=18' /tmp/trace | wc -l returns 80. Half should be irq count = 40.
I have made a patch to fix the issue below.
Below check causes early unwanted return from store_irq() function. In fact, the whole 'wakeirq' member seems unnecessary, hence the related code.
if (cstates->wakeirq != NULL) return 0;
Would you please check?
diff --git a/idlestat.c b/idlestat.c index 5e8f8d5..d4ea859 100644 --- a/idlestat.c +++ b/idlestat.c @@ -654,7 +654,6 @@ static int store_data(double time, int state, int cpu, cstates->cstate[state].data = data; cstates->cstate_max = MAX(cstates->cstate_max, state); cstates->last_cstate = state;
cstates->wakeirq = NULL; /* update P-state stats if supported */ if (pstate)
@@ -684,9 +683,6 @@ static int store_irq(int cpu, int irqid, char *irqname, struct wakeup_irq *irqinfo; struct wakeup_info *wakeinfo = &cstates->wakeinfo;
if (cstates->wakeirq != NULL)
return 0;
irqinfo = find_irqinfo(wakeinfo, irqid); if (NULL == irqinfo) { irqinfo = realloc(wakeinfo->irqinfo,
@@ -705,8 +701,6 @@ static int store_irq(int cpu, int irqid, char *irqname,
irqinfo->count++;
cstates->wakeirq = irqinfo;
return 0;
}
diff --git a/idlestat.h b/idlestat.h index 1977ab4..bb27e3a 100644 --- a/idlestat.h +++ b/idlestat.h @@ -76,7 +76,6 @@ struct cpuidle_cstates { struct wakeup_info wakeinfo; int last_cstate; int cstate_max;
struct wakeup_irq *wakeirq;
};
struct cpufreq_pstate {
-- Thanks, -Meraj
linaro-dev mailing list linaro-dev@lists.linaro.org http://lists.linaro.org/mailman/listinfo/linaro-dev