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 -- <<This happens because I choose it to happen!>> (Raistlin Majere) ----------------------------------------------------------------- Dario Faggioli, Ph.D, http://about.me/dario.faggioli Senior Software Engineer, Citrix Systems R&D Ltd., Cambridge (UK)
signature.asc
Description: This is a digitally signed message part
_______________________________________________ Xen-devel mailing list Xen-devel@lists.xen.org http://lists.xen.org/xen-devel
