| Message ID | 20160216181153.27876.34317.stgit@Solace.station (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
Hi Dario, Since this patch did some obvious change, I will reply with reviewed-by, although my reviewed-by does not count much. ;-) On Tue, Feb 16, 2016 at 1:11 PM, Dario Faggioli <dario.faggioli@citrix.com> wrote: > > it is enabled for pretty much all of them already. > There were just a few that had it disabled. > > When tracing a scheduler, timing information is > really important, so enable it everywhere scheduling > related. > > Note that this was not really a problem if looking > at the traces with xenalyze, but it was if using > xentrace_format. I just have a quick (and perhaps naive) question: :-) If xenanlyze works better than xentrace_format, why shouldn't we stick to xenanlyze? Is there some functionality xentrace_format can but xenalyze cannot? (I have to confess that I only used xenalyze but didn't use xentrace_format before. :-() > > Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com> > --- > Cc: George Dunlap <george.dunlap@citrix.com> > Cc: Meng Xu <xumengpanda@gmail.com> > Cc: Tianyang Chen <tiche@seas.upenn.edu> > Cc: Olaf Hering <olaf@aepfle.de> > --- > xen/common/sched_credit.c | 2 +- > xen/common/sched_credit2.c | 6 +++--- > xen/common/sched_rt.c | 2 +- > 3 files changed, 5 insertions(+), 5 deletions(-) > > diff --git a/xen/common/sched_credit.c b/xen/common/sched_credit.c > index 5279b92..bd2f37f 100644 > --- a/xen/common/sched_credit.c > +++ b/xen/common/sched_credit.c > @@ -476,7 +476,7 @@ static inline void __runq_tickle(struct csched_vcpu *new) > { > /* Avoid TRACE_*: saves checking !tb_init_done each step */ > for_each_cpu(cpu, &mask) > - __trace_var(TRC_CSCHED_TICKLE, 0, sizeof(cpu), &cpu); > + __trace_var(TRC_CSCHED_TICKLE, 1, sizeof(cpu), &cpu); > } > > /* Send scheduler interrupts to designated CPUs */ > diff --git a/xen/common/sched_credit2.c b/xen/common/sched_credit2.c > index cf40f68..2934e26 100644 > --- a/xen/common/sched_credit2.c > +++ b/xen/common/sched_credit2.c > @@ -456,7 +456,7 @@ runq_insert(const struct scheduler *ops, unsigned int cpu, struct csched2_vcpu * > d.dom = svc->vcpu->domain->domain_id; > d.vcpu = svc->vcpu->vcpu_id; > d.pos = pos; > - trace_var(TRC_CSCHED2_RUNQ_POS, 0, > + trace_var(TRC_CSCHED2_RUNQ_POS, 1, > sizeof(d), > (unsigned char *)&d); > } > @@ -564,7 +564,7 @@ tickle: > unsigned cpu:16, pad:16; > } d; > d.cpu = ipid; d.pad = 0; > - trace_var(TRC_CSCHED2_TICKLE, 0, > + trace_var(TRC_CSCHED2_TICKLE, 1, > sizeof(d), > (unsigned char *)&d); > } > @@ -1721,7 +1721,7 @@ csched2_schedule( > */ > if ( tasklet_work_scheduled ) > { > - trace_var(TRC_CSCHED2_SCHED_TASKLET, 0, 0, NULL); > + trace_var(TRC_CSCHED2_SCHED_TASKLET, 1, 0, NULL); > snext = CSCHED2_VCPU(idle_vcpu[cpu]); > } > else > diff --git a/xen/common/sched_rt.c b/xen/common/sched_rt.c > index 53de6d6..33ac9de 100644 > --- a/xen/common/sched_rt.c > +++ b/xen/common/sched_rt.c > @@ -985,7 +985,7 @@ out: > } d; > d.cpu = cpu_to_tickle; > d.pad = 0; > - trace_var(TRC_RTDS_TICKLE, 0, > + trace_var(TRC_RTDS_TICKLE, 1, > sizeof(d), > (unsigned char *)&d); > } > Reviewed-by: Meng Xu <mengxu@cis.upenn.edu> Best, Meng ----------- Meng Xu PhD Student in Computer and Information Science University of Pennsylvania http://www.cis.upenn.edu/~mengxu/
On Tue, 2016-02-16 at 13:21 -0500, Meng Xu wrote: > Hi Dario, > > Since this patch did some obvious change, I will reply with > reviewed-by, although my reviewed-by does not count much. ;-) > That can't be less true. First of all, you're the original author of this code, and you and, although I'm the maintainer, your group are the one doing active development on it, so your opinion does have a weight. But even if that wasn't the case, every reviewed-by is important, and helps the project. It will be maintainers' and committer's job to properly take each one into account in the most appropriate way, but that does not mean it's not worthwhile for you (or anyone else) to review the patches and express your acknowledgment, or send in your comments. :-) Actually, do feel free to do as much review (and, in case it applies, send in your reviewed-by tag) as you like and can, either on RTDS or anywhere else... The project is in great need of that!! > On Tue, Feb 16, 2016 at 1:11 PM, Dario Faggioli > <dario.faggioli@citrix.com> wrote: > > > > Note that this was not really a problem if looking > > at the traces with xenalyze, but it was if using > > xentrace_format. > > I just have a quick (and perhaps naive) question: :-) > If xenanlyze works better than xentrace_format, why shouldn't we > stick > to xenanlyze? > Is there some functionality xentrace_format can but xenalyze cannot? > > (I have to confess that I only used xenalyze but didn't use > xentrace_format before. :-() > xenalyze is indeed more advanced, but I don't think this means we should ignore or neglect xentrace_format: we've got it in tree, so we should not let it bitrot. I'm not in all our users' heads, so I don't know whether --and if yes why-- people may prefer the latter over the former, but I see room for someone wanting something basic and simple, in some cases. Actually, I've been in a couple of situations myself, where the raw output of xentrace_format is easier to consume and, quick-&-dirtily, post-process, than the much more elaborated one of xenalyze. For instance, the thing that you can just change on the fly the way a trace is shown (by tweaking the format file) looks an interesting feature to me, even considering all the limitations of "pure" xentrace. And if one want to change the formats for her own purposes, I feel like it is important that the one that we ship is updated, and can be used as a decent base for that. Regards, Dario
On Wed, Feb 17, 2016 at 4:52 AM, Dario Faggioli <dario.faggioli@citrix.com> wrote: > On Tue, 2016-02-16 at 13:21 -0500, Meng Xu wrote: >> Hi Dario, >> >> Since this patch did some obvious change, I will reply with >> reviewed-by, although my reviewed-by does not count much. ;-) >> > That can't be less true. First of all, you're the original author of > this code, and you and, although I'm the maintainer, your group are the > one doing active development on it, so your opinion does have a weight. > > But even if that wasn't the case, every reviewed-by is important, and > helps the project. It will be maintainers' and committer's job to > properly take each one into account in the most appropriate way, but > that does not mean it's not worthwhile for you (or anyone else) to > review the patches and express your acknowledgment, or send in your > comments. :-) > > Actually, do feel free to do as much review (and, in case it applies, > send in your reviewed-by tag) as you like and can, either on RTDS or > anywhere else... The project is in great need of that!! I see. Thank you very much for the advice and information! I got it now. :-D I'm so glad to know that I can also comment on other parts of the code, besides RTDS. :-D > >> On Tue, Feb 16, 2016 at 1:11 PM, Dario Faggioli >> <dario.faggioli@citrix.com> wrote: >> > >> > Note that this was not really a problem if looking >> > at the traces with xenalyze, but it was if using >> > xentrace_format. >> >> I just have a quick (and perhaps naive) question: :-) >> If xenanlyze works better than xentrace_format, why shouldn't we >> stick >> to xenanlyze? >> Is there some functionality xentrace_format can but xenalyze cannot? >> >> (I have to confess that I only used xenalyze but didn't use >> xentrace_format before. :-() >> > xenalyze is indeed more advanced, but I don't think this means we > should ignore or neglect xentrace_format: we've got it in tree, so we > should not let it bitrot. I'm not in all our users' heads, so I don't > know whether --and if yes why-- people may prefer the latter over the > former, but I see room for someone wanting something basic and simple, > in some cases. > > Actually, I've been in a couple of situations myself, where the raw > output of xentrace_format is easier to consume and, quick-&-dirtily, > post-process, than the much more elaborated one of xenalyze. > > For instance, the thing that you can just change on the fly the way a > trace is shown (by tweaking the format file) looks an interesting > feature to me, even considering all the limitations of "pure" xentrace. > And if one want to change the formats for her own purposes, I feel like > it is important that the one that we ship is updated, and can be used > as a decent base for that. I see the point here now. I will try the xentrace_format next time then. :-) Thanks and best regards, Meng
On 17/02/16 09:52, Dario Faggioli wrote: > On Tue, 2016-02-16 at 13:21 -0500, Meng Xu wrote: >> Hi Dario, >> >> Since this patch did some obvious change, I will reply with >> reviewed-by, although my reviewed-by does not count much. ;-) >> > That can't be less true. First of all, you're the original author of > this code, and you and, although I'm the maintainer, your group are the > one doing active development on it, so your opinion does have a weight. > > But even if that wasn't the case, every reviewed-by is important, and > helps the project. It will be maintainers' and committer's job to > properly take each one into account in the most appropriate way, but > that does not mean it's not worthwhile for you (or anyone else) to > review the patches and express your acknowledgment, or send in your > comments. :-) > > Actually, do feel free to do as much review (and, in case it applies, > send in your reviewed-by tag) as you like and can, either on RTDS or > anywhere else... The project is in great need of that!! > >> On Tue, Feb 16, 2016 at 1:11 PM, Dario Faggioli >> <dario.faggioli@citrix.com> wrote: >>> >>> Note that this was not really a problem if looking >>> at the traces with xenalyze, but it was if using >>> xentrace_format. >> >> I just have a quick (and perhaps naive) question: :-) >> If xenanlyze works better than xentrace_format, why shouldn't we >> stick >> to xenanlyze? >> Is there some functionality xentrace_format can but xenalyze cannot? >> >> (I have to confess that I only used xenalyze but didn't use >> xentrace_format before. :-() >> > xenalyze is indeed more advanced, but I don't think this means we > should ignore or neglect xentrace_format: we've got it in tree, so we > should not let it bitrot. I'm not in all our users' heads, so I don't > know whether --and if yes why-- people may prefer the latter over the > former, but I see room for someone wanting something basic and simple, > in some cases. > > Actually, I've been in a couple of situations myself, where the raw > output of xentrace_format is easier to consume and, quick-&-dirtily, > post-process, than the much more elaborated one of xenalyze. > > For instance, the thing that you can just change on the fly the way a > trace is shown (by tweaking the format file) looks an interesting > feature to me, even considering all the limitations of "pure" xentrace. > And if one want to change the formats for her own purposes, I feel like > it is important that the one that we ship is updated, and can be used > as a decent base for that. So I certainly agree that xentrace_formats should be maintained so that it works. I hadn't thought before about the advantage of being able to change the formats file more easily than adding new records to xenalyze, but that's a good point. But I do want to ask, how neccessary / useful is it to make the *TSC* information available to xentrace_format? The reason most of the traces don't include a timestamp is that it increases the record size by a non-negligible amount -- in all the cases here the traces are 1, 2, or 3 bytes without the tsc, so you're basically doubling the size of what gets traced. How does adding the TSC significantly help someone using xentrace_format? -George
On Thu, 2016-02-18 at 11:43 +0000, George Dunlap wrote: > On 17/02/16 09:52, Dario Faggioli wrote: > > > > For instance, the thing that you can just change on the fly the way > > a > > trace is shown (by tweaking the format file) looks an interesting > > feature to me, even considering all the limitations of "pure" > > xentrace. > > And if one want to change the formats for her own purposes, I feel > > like > > it is important that the one that we ship is updated, and can be > > used > > as a decent base for that. > > So I certainly agree that xentrace_formats should be maintained so > that > it works. I hadn't thought before about the advantage of being able > to > change the formats file more easily than adding new records to > xenalyze, > but that's a good point. > Yeah... To be fair, it's much more the exception than the rule, IMO, that you really need xentrace_format instead of xenalyze... But it can happen, and that's one possible reason. > But I do want to ask, how neccessary / useful is it to make the *TSC* > information available to xentrace_format? > So, when tracing the scheduler, I personally don't see much value in having the record of an event, if I don't also have the time at which the event happened. So, this is an example of xentrace_format with all this series applied, except for this patch: CPU0 2970034498098 (+ 9454788) domain_wake [ dom:vcpu = 0x00000001 ] CPU0 2970034499304 (+ 1206) blocked_to_runnable [ dom:vcpu = 0x00000001 ] CPU0 0 (+ 0) csched:tickle [ cpu = 0 ] CPU0 2970034511640 (+ 12336) switch_infprev [ old_domid = 0x00007fff, runtime = 3956318 ] CPU0 2970034512090 (+ 450) switch_infnext [ new_domid = 0x00000000, time = 4446, r_time = 30000000 ] CPU0 2970034512480 (+ 390) __enter_scheduler [ prev<dom:vcpu> = 0x7fff0000, next<dom:vcpu> = 0x00000001 ] CPU0 2970034513002 (+ 522) running_to_runnable [ dom:vcpu = 0x7fff0000 ] CPU0 2970034513422 (+ 420) runnable_to_running [ dom:vcpu = 0x00000001 ] So, suppose, for instance, I want to figure out how much time passes between when a pcpu is tickled, and when it actually schedules and pick up the task that woke up. From just the trace above, I can't do that. I know that this may not always be reliable when using only xentrace_format (because of TSC not being synchronized or drifting), but if used well (e.g., with pinning) or on good/new enough hardware (with synch and constant rate TSCs), I think it should be possible. On the other hand this is how a similar trace looks if TSC is enabled, where the above can be achived: CPU5 9965509909596 (+ 9268404) domain_wake [ dom:vcpu = 0x00000004 ] CPU5 9965509911030 (+ 1434) blocked_to_runnable [ dom:vcpu = 0x00000004 ] CPU5 9965509912962 (+ 1932) csched:tickle [ cpu = 5 ] CPU5 9965509924002 (+ 11040) switch_infprev [ old_domid = 0x00007fff, runtime = 3879052 ] CPU5 9965509924506 (+ 504) switch_infnext [ new_domid = 0x00000000, time = 5000, r_time = 30000000 ] CPU5 9965509924824 (+ 318) __enter_scheduler [ prev<dom:vcpu> = 0x7fff0005, next<dom:vcpu> = 0x00000004 ] CPU5 9965509925478 (+ 654) running_to_runnable [ dom:vcpu = 0x7fff0005 ] CPU5 9965509925892 (+ 414) runnable_to_running [ dom:vcpu = 0x00000004 ] This is not an issue with xenalyze, and I think that is because you fiddle with timestamps in it, in order to compensate for the per- cpuness/desynch/etc. issues. I haven't checked the code where that happens in xenalyze, though, so I don't know whether having the TSC in more records would also help xenalyze or not. > The reason most of the traces don't include a timestamp is that it > increases the record size by a non-negligible amount -- in all the > cases > here the traces are 1, 2, or 3 bytes without the tsc, so you're > basically doubling the size of what gets traced. > I see, but I think it's worth in this case. Perhaps, we can think of ways of enabling and disabling logging TSC dynamically, either at compile or run time. Doing at run time, given the way tracing is currently implemented, will most likely incur in some overhead. Very small, but still something, and I'm not sure we're ok introducing it. Doing it at compile time would be a lot less flexible, but perhaps a decent compromise, i.e., I at least always have the events... If I want to know exactly when they happened, for all of them, I need a Xen version build to provide that (like I need a debug build to have ASSERT()s and symbols). > How does adding the TSC significantly help someone using > xentrace_format? > Hope I answered to this. Let me know what you think. :-) Regards, Dario
On Thu, Feb 18, 2016 at 4:52 PM, Dario Faggioli <dario.faggioli@citrix.com> wrote: > On Thu, 2016-02-18 at 11:43 +0000, George Dunlap wrote: >> On 17/02/16 09:52, Dario Faggioli wrote: >> > >> > For instance, the thing that you can just change on the fly the way >> > a >> > trace is shown (by tweaking the format file) looks an interesting >> > feature to me, even considering all the limitations of "pure" >> > xentrace. >> > And if one want to change the formats for her own purposes, I feel >> > like >> > it is important that the one that we ship is updated, and can be >> > used >> > as a decent base for that. >> >> So I certainly agree that xentrace_formats should be maintained so >> that >> it works. I hadn't thought before about the advantage of being able >> to >> change the formats file more easily than adding new records to >> xenalyze, >> but that's a good point. >> > Yeah... To be fair, it's much more the exception than the rule, IMO, > that you really need xentrace_format instead of xenalyze... But it can > happen, and that's one possible reason. > >> But I do want to ask, how neccessary / useful is it to make the *TSC* >> information available to xentrace_format? >> > So, when tracing the scheduler, I personally don't see much value in > having the record of an event, if I don't also have the time at which > the event happened. > > So, this is an example of xentrace_format with all this series applied, > except for this patch: > > CPU0 2970034498098 (+ 9454788) domain_wake [ dom:vcpu = 0x00000001 ] > CPU0 2970034499304 (+ 1206) blocked_to_runnable [ dom:vcpu = 0x00000001 ] > CPU0 0 (+ 0) csched:tickle [ cpu = 0 ] > CPU0 2970034511640 (+ 12336) switch_infprev [ old_domid = 0x00007fff, runtime = 3956318 ] > CPU0 2970034512090 (+ 450) switch_infnext [ new_domid = 0x00000000, time = 4446, r_time = 30000000 ] > CPU0 2970034512480 (+ 390) __enter_scheduler [ prev<dom:vcpu> = 0x7fff0000, next<dom:vcpu> = 0x00000001 ] > CPU0 2970034513002 (+ 522) running_to_runnable [ dom:vcpu = 0x7fff0000 ] > CPU0 2970034513422 (+ 420) runnable_to_running [ dom:vcpu = 0x00000001 ] > > So, suppose, for instance, I want to figure out how much time passes > between when a pcpu is tickled, and when it actually schedules and pick > up the task that woke up. From just the trace above, I can't do that. > > I know that this may not always be reliable when using only > xentrace_format (because of TSC not being synchronized or drifting), > but if used well (e.g., with pinning) or on good/new enough hardware > (with synch and constant rate TSCs), I think it should be possible. > > On the other hand this is how a similar trace looks if TSC is enabled, > where the above can be achived: > > CPU5 9965509909596 (+ 9268404) domain_wake [ dom:vcpu = 0x00000004 ] > CPU5 9965509911030 (+ 1434) blocked_to_runnable [ dom:vcpu = 0x00000004 ] > CPU5 9965509912962 (+ 1932) csched:tickle [ cpu = 5 ] > CPU5 9965509924002 (+ 11040) switch_infprev [ old_domid = 0x00007fff, runtime = 3879052 ] > CPU5 9965509924506 (+ 504) switch_infnext [ new_domid = 0x00000000, time = 5000, r_time = 30000000 ] > CPU5 9965509924824 (+ 318) __enter_scheduler [ prev<dom:vcpu> = 0x7fff0005, next<dom:vcpu> = 0x00000004 ] > CPU5 9965509925478 (+ 654) running_to_runnable [ dom:vcpu = 0x7fff0005 ] > CPU5 9965509925892 (+ 414) runnable_to_running [ dom:vcpu = 0x00000004 ] > > This is not an issue with xenalyze, and I think that is because you > fiddle with timestamps in it, in order to compensate for the per- > cpuness/desynch/etc. issues. I haven't checked the code where that > happens in xenalyze, though, so I don't know whether having the TSC in > more records would also help xenalyze or not. > >> The reason most of the traces don't include a timestamp is that it >> increases the record size by a non-negligible amount -- in all the >> cases >> here the traces are 1, 2, or 3 bytes without the tsc, so you're >> basically doubling the size of what gets traced. >> > I see, but I think it's worth in this case. > > Perhaps, we can think of ways of enabling and disabling logging TSC > dynamically, either at compile or run time. Doing at run time, given > the way tracing is currently implemented, will most likely incur in > some overhead. Very small, but still something, and I'm not sure we're > ok introducing it. > > Doing it at compile time would be a lot less flexible, but perhaps a > decent compromise, i.e., I at least always have the events... If I want > to know exactly when they happened, for all of them, I need a Xen > version build to provide that (like I need a debug build to have > ASSERT()s and symbols). > >> How does adding the TSC significantly help someone using >> xentrace_format? >> > Hope I answered to this. Let me know what you think. :-) The other thing to say in favor of this patch is: While we are doubling the size of this small handful of traces, these will constitute a much smaller percentage of the overall trace file, particularly as (as you say in the changelog) a lot of the other traces do already use tsc. So I guess you've convinced me: Acked-by: George Dunlap <george.dunlap@citrix.com>
diff --git a/xen/common/sched_credit.c b/xen/common/sched_credit.c index 5279b92..bd2f37f 100644 --- a/xen/common/sched_credit.c +++ b/xen/common/sched_credit.c @@ -476,7 +476,7 @@ static inline void __runq_tickle(struct csched_vcpu *new) { /* Avoid TRACE_*: saves checking !tb_init_done each step */ for_each_cpu(cpu, &mask) - __trace_var(TRC_CSCHED_TICKLE, 0, sizeof(cpu), &cpu); + __trace_var(TRC_CSCHED_TICKLE, 1, sizeof(cpu), &cpu); } /* Send scheduler interrupts to designated CPUs */ diff --git a/xen/common/sched_credit2.c b/xen/common/sched_credit2.c index cf40f68..2934e26 100644 --- a/xen/common/sched_credit2.c +++ b/xen/common/sched_credit2.c @@ -456,7 +456,7 @@ runq_insert(const struct scheduler *ops, unsigned int cpu, struct csched2_vcpu * d.dom = svc->vcpu->domain->domain_id; d.vcpu = svc->vcpu->vcpu_id; d.pos = pos; - trace_var(TRC_CSCHED2_RUNQ_POS, 0, + trace_var(TRC_CSCHED2_RUNQ_POS, 1, sizeof(d), (unsigned char *)&d); } @@ -564,7 +564,7 @@ tickle: unsigned cpu:16, pad:16; } d; d.cpu = ipid; d.pad = 0; - trace_var(TRC_CSCHED2_TICKLE, 0, + trace_var(TRC_CSCHED2_TICKLE, 1, sizeof(d), (unsigned char *)&d); } @@ -1721,7 +1721,7 @@ csched2_schedule( */ if ( tasklet_work_scheduled ) { - trace_var(TRC_CSCHED2_SCHED_TASKLET, 0, 0, NULL); + trace_var(TRC_CSCHED2_SCHED_TASKLET, 1, 0, NULL); snext = CSCHED2_VCPU(idle_vcpu[cpu]); } else diff --git a/xen/common/sched_rt.c b/xen/common/sched_rt.c index 53de6d6..33ac9de 100644 --- a/xen/common/sched_rt.c +++ b/xen/common/sched_rt.c @@ -985,7 +985,7 @@ out: } d; d.cpu = cpu_to_tickle; d.pad = 0; - trace_var(TRC_RTDS_TICKLE, 0, + trace_var(TRC_RTDS_TICKLE, 1, sizeof(d), (unsigned char *)&d); }
it is enabled for pretty much all of them already. There were just a few that had it disabled. When tracing a scheduler, timing information is really important, so enable it everywhere scheduling related. Note that this was not really a problem if looking at the traces with xenalyze, but it was if using xentrace_format. Signed-off-by: Dario Faggioli <dario.faggioli@citrix.com> --- Cc: George Dunlap <george.dunlap@citrix.com> Cc: Meng Xu <xumengpanda@gmail.com> Cc: Tianyang Chen <tiche@seas.upenn.edu> Cc: Olaf Hering <olaf@aepfle.de> --- xen/common/sched_credit.c | 2 +- xen/common/sched_credit2.c | 6 +++--- xen/common/sched_rt.c | 2 +- 3 files changed, 5 insertions(+), 5 deletions(-)