<html><head><meta http-equiv="Content-Type" content="text/html charset=utf-8"></head><body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" class=""><br class=""><div><blockquote type="cite" class=""><div class="">On 6 Jun 2017, at 16:29, Marc-André Lureau <<a href="mailto:marcandre.lureau@redhat.com" class="">marcandre.lureau@redhat.com</a>> wrote:</div><br class="Apple-interchange-newline"><div class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">Hi</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">----- Original Message -----</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class="">Answering two emails from Frediano and Marc-André that were asking closely<br class="">related questions, to avoid duplication…<br class=""><br class=""><blockquote type="cite" class="">On 6 Jun 2017, at 13:28, Frediano Ziglio <<a href="mailto:fziglio@redhat.com" class="">fziglio@redhat.com</a>> wrote:<br class=""><br class="">Would be helpful if you had recap Pavel problems. I don't remember.<br class=""></blockquote><br class="">I did not find it in email, so it was probably IRC. I remember something<br class="">about having to use --spice-debug for some debug messages, and glib<br class="">environment variables for others. Pavel, do you remember something like<br class="">that?<br class=""><br class=""><blockquote type="cite" class=""><blockquote type="cite" class="">Would you find this useful? The most difficult part being to connect that<br class="">to existing tracing mechanisms to avoid replication of traces, while at<br class="">the same time ensuring that the existing enabling mechanisms work as<br class="">before.<br class=""></blockquote></blockquote><br class=""><blockquote type="cite" class="">The main questions are:<br class="">- what are the original problems exactly?<br class=""></blockquote><br class="">Getting focused debug output, which to me means “conditional, cheap, always<br class="">there". I don’t like having an “all-or-nothing” debug proposition for Spice.<br class="">Currently, we have SPICE_DEBUG=1 or SPICE_DEBUG=0. That’s too binary. I<br class="">would like SPICE_TRACES=channel:memory, for example.<br class=""><br class=""><br class=""><blockquote type="cite" class="">- why your solution is good in your opinion?<br class=""></blockquote><br class="">1. Conditional tracing. Except by misusing domains to identify conditions, I<br class="">think it’s not easy to do with glib. I may be wrong, but did not find<br class="">anything here for example:<br class=""><a href="https://developer.gnome.org/glib/stable/glib-Message-Logging.html" class="">https://developer.gnome.org/glib/stable/glib-Message-Logging.html</a>.<br class=""></blockquote><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">Personally, grep conditions covers 99% of my needs.</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>Not mine. If I’m investigating where some latency comes from, the last thing I want to is to have all-encompassing printouts that would themselves be a primary cause of latency.</div><div><br class=""></div><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class=""><br class="">2. Lightweight enough tracing that you can leave it there all the time. In<br class="">this implementation, adding a trace consumes one bit in memory, testing for<br class="">it is one memory access (plus the conditional jump, I know ;-). By contrast,<br class="">the cost of logging in glib is quite high, which makes little sense for<br class="">low-level debugging messages that are intended to be thrown away under<br class="">normal use.<br class=""><br class=""></blockquote><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">Well, glib logging isn't meant for tracing. So it isn't used for that, and it has no performance issue for regular debugging/logging.</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>Yes. But what I’m presently interested in are performance issues. And the messages I need are presently not in spice, nor is there a sufficient infrastructure to add them. Definitely, glib does not do what I want, see below for more details.</div><div><br class=""></div><br class=""><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class="">3. Scalable, and therefore as fine-grained as we need it to be. With a<br class="">similar mechanism, Tao-3D has about 70 traces (see<br class=""><a href="https://github.com/c3d/tao-3D/blob/master/tao/traces.tbl" class="">https://github.com/c3d/tao-3D/blob/master/tao/traces.tbl</a><span class="Apple-converted-space"> </span>for the graphic<br class="">side traces), including in highly performance-sensitive paths.<br class=""></blockquote><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">I think we have few highly performance-sensitive paths in our code, and before introducing facilities for tracing it, it would be interesting to know what you want to have traced.</span></div></blockquote><div><br class=""></div><div>Let me take some examples straight from Tao3D, which I dearly miss in spice today (with actual output from Tao3D for the first two):</div><div><br class=""></div><div>1. fps: Report frames per second.</div><div><br class=""></div><div><div>Time;PageNum;FPS;Exec;MaxExec;Draw;MaxDraw;GC;MaxGC;Select;MaxSelect;GCWait;MaxGCWait</div><div>1496761089.058;1;0.000;-1;0;-1;0;-1;0;-1;0;-1;0</div><div>1496761093.755;1;13.800;50;3217;9;482;1;13;0;0;0;9</div><div>1496761094.756;1;55.400;13;3217;3;482;0;13;0;0;0;12</div><div>1496761095.759;1;94.200;8;3217;2;482;0;13;0;0;0;12</div><div>1496761096.759;1;136.400;6;3217;2;482;0;13;0;0;0;12</div><div><br class=""></div></div><div>2. memory: Report memory usage on a regular basis (ideally, component by component, e.g. separate codecs from spice code)</div><div><br class=""></div><div><div> NAME TOTAL ALLOC FREED</div><div> N2XL4TreeE 0 0 0</div><div> N2XL7IntegerE 6132 1527 224</div><div> N2XL4RealE 4088 215 3478</div><div> N2XL4TextE 6132 1217 336</div><div> N2XL4NameE 40880 15664 0</div><div> N2XL5InfixE 33726 10246 332</div><div> N2XL6PrefixE 12264 3177 0</div><div> N2XL7PostfixE 1022 254 0</div><div> N2XL5BlockE 5110 1017 112</div><div> N2XL7ContextE 1022 15 0</div><div> N2XL7SymbolsE 4088 1432 0</div><div> N2XL7RewriteE 9198 5519 0</div><div> ===== ===== ===== =====</div><div> Kilobytes 9820K 3293K 223K</div><div>[GCThread] Collect time 3 ms</div><div>[GCThread] GC collect started</div><div>[GCThread] Collect time 0 ms</div><div>[GCThread] GC collect started</div><div class=""><br class=""></div></div><div>3. bandwidth: Report network bandwidth usage (incoming and outcoming)</div><div><br class=""></div><div>4. latency: Report network observed latency</div><div><br class=""></div><div><br class=""></div><blockquote type="cite" class=""><div class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class=""> My feeling is that those performance traces don't need to be in public or release code, since they are usually very specific to the problem you are studying at hand, and don't need to remain checked in code.</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>My experience tells me the exact opposite. If you have a structure like this in place, you start putting a bit more investment in your traces, so that they can be reused later.</div><br class=""><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class="">4. Can be used to conditionally enable / disable code (other than tracing).<br class="">For example, Frediano started chasing memory leaks. Let’s say he develops a<br class="">nice way to track leaks. It’s an investment, we want to keep it. With this<br class="">infrastructure, we could put that under -t leakcheck, and run that if we<br class="">have a doubt about a memory leak.<br class=""></blockquote><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">Does tracing really helps with memory leak? when you have asan and valgrind, really, no.</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>Valgrind? Running a heavily modified executable at a quarter of the speed on a good moon? And clearly, based on the massive memory leak I reported last week, such tools are not used on a regular basis.</div><div><br class=""></div><div>The purpose of something like -t memory is to give you a broad overview. Be able to say “we use 3G of memory, 1.5G of which is for graphics, 1G of which for cached images”. So that you know where to focus your effort. Using valgrind to give you that information? Tell me how.</div><div><br class=""></div><div><br class=""></div><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class="">5. Can be used for non-boolean values. It makes the code only marginally more<br class="">complicated to add “tweaks”, i.e. integer values you can configure at<br class="">run-time easily. Currently, you’d typically use environment variables or a<br class="">configuration file for this, which expensive and not convenient. With this<br class="">approach, add one tweak, say “max_mem”, and tweak with -t max_mem=100 to,<br class="">say, limit allocations to 100M and detect leaks more easily.<br class=""></blockquote><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">What has this to do with tracing?</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>In both cases, it’s runtime configuration intended primarily for developers.</div><div><br class=""></div><div>To better see the continuity between the two, imagine that we have a trace focusing on JPEG encoding. But now, if we focus on understanding JPEG quality, I can do something like -t jpeg -t jpeg_quality=50. So it’s really part of the same kind of usage patterns.</div><br class=""><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class="">6. Self-documented. Using spicy -t list gives you a list of possible tweaks.<br class="">And all messages come with a trace name prefix, so if you later want to get<br class="">that specific message, you know what to pass to -t.<br class=""><br class=""></blockquote><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">I suppose it lists the various domains? or all trace points?</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>The domains if you want to call them that. But I’d rather leave “domain” for glib domains, and traces / tweaks for what I’m proposing here. It’s different concepts, much like domains and command-line options are different, even if you may use a domain name as a grep argument.</div><br class=""><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">For the later, it's probably hard to keep it stable and without associated documentation, it isn't of much help imho.</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>This is exactly why in this implementation, the macros in spice-traces.def mandate an “info” field for self-documentation.</div><br class=""><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">In any case, I don't think it make sense to provide this in a user command line. Using environment variable allows to tweak any program using your library instead, and may be changed at run time.</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>The SPICE_TRACE environment variable can be used to configure that if that’s what you prefer. I personally prefer a short command-line option.</div><br class=""><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class="">I don’t think glib does any of these 6 points. I may be wrong, and I am<br class="">willing to use glib instead where it provides a sufficiently good solution.<br class=""><br class=""><br class=""><blockquote type="cite" class="">- did you try other options (like Marc-andre' suggested) ?<br class=""></blockquote><br class="">Yes. Christophe F already suggested them:<br class=""><br class=""><blockquote type="cite" class=""><blockquote type="cite" class="">On 23 May 2017, at 11:51, Christophe Fergeau <<a href="mailto:cfergeau@redhat.com" class="">cfergeau@redhat.com</a>> wrote:<br class=""></blockquote><br class=""><blockquote type="cite" class="">I think we have SPICE_DEBUG already which might make<br class="">sense, another alternative would be to have a --enable-alignment-debug,<br class="">or something like glib (SPICE_XXX_DEBUG=alignment:foo:bar)<br class=""><br class=""></blockquote></blockquote><br class="">I did not find where the existing code does anything that would correspond to<br class="">this<br class="">SPICE_XXX_DEBUG=alignment:foo:bar (I did ask). Any pointer? In any case,<br class="">what I saw in glib did not respond to my needs.<br class=""><br class=""><br class=""><blockquote type="cite" class=""><br class="">Reading the code is not clear where exactly you implemented the different<br class="">domains<br class="">suggested by the bug report.<br class=""></blockquote><br class="">I didn’t. I propose that we do something finer-grained.<br class=""><br class=""><br class=""><blockquote type="cite" class="">Did you just coded SSL as an example?<br class=""></blockquote><br class="">Yes. I don’t want to convert everything if I sense that the team does not<br class="">like it at all.<br class="">So I only did two in common (ssl and rect) and one in gtk (channel, by<br class="">modifying CHANNEL_DEBUG)<br class=""><br class=""><blockquote type="cite" class="">Also you introduced a new "TRACE" logging level; why DEBUG was not enough?<br class=""></blockquote><br class="">This is transitional, to be able to distinguish preserve existing behavior<br class="">for existing debug code<br class="">(always go to the glib log) while TRACE code can also go to standard error.<br class=""><br class=""><br class=""><br class=""><blockquote type="cite" class="">On 6 Jun 2017, at 12:54, Marc-André Lureau <<a href="mailto:marcandre.lureau@redhat.com" class="">marcandre.lureau@redhat.com</a>><br class="">wrote:<br class=""><br class="">I would rather stick to glib structured logging (and have compatibility<br class="">code for glib < 2.50),<br class=""></blockquote><br class="">This does not address my problem. The structured logging is “how to log”<br class="">(i.e. it is a replacement for “printf”). My patch set is intended to define<br class=""></blockquote><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">"structured logging" is not about "how" or "where" to log. It is about "structured" logs, that is having named fields & value that you can later filter/query. One way is through the journal, but you can implement other handlers.</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>I stand by my comment that it’s about how and where to log things. How: using named fields instead of pure ASCII text. Where: in a shared log, that can be merged between applications, with the benefits you listed, namely that it can be queried.</div><div><br class=""></div><div><blockquote type="cite" class=""><span class="" style="display: inline !important;"> I don't know if your solution could fit. If it does, it would be great to propose it to glib instead.</span></blockquote></div><div><br class=""></div><div>I could probably make conditional tracing part of glib, but only with a much more expensive implementation. In what I proposed, each flag is a bit in a structure. So when you write IFTRACE(foo), it translates to nothing more than if (spice_traces.foo). This relies on the compiler and linker doing the lookup job at compile-time. A library implementation would have to do a run-time lookup of the trace name, making it much more expensive.</div><div><br class=""></div><div>Alternatively, a header-only implementation is feasible, but that makes it much more difficult to statically define where flags are stored. For instance, say glib started using it, then glib would for example need a “glib” set of flags, and a “spicy” set of flags. Let’s say two structures. An implementation of IFTRACE(flag) would have to somehow remember if “flag” was defined in “glib” or in “spicy”. So you end up with a much more complex implementation. At some point, we did something like that for XL vs Tao3D, but that used some C++ trickery that I don’t know how to replicate in C (using namespace lookup IIRC, I’d have to check the code).</div><div><br class=""></div><div>Or you could forget about being smart, and just write something like IFTRACE(glib.flag) and IFTRACE(spicy.flag), with possibly appropriate macros. Hmm. Thinking aloud here. Why not…</div><div><br class=""></div><div><br class=""></div><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class="">*what* to log and *when* (i.e. it is a special form of command-line driven<br class="">“if”). Ultimately, my implementation uses either stderr or glib old log or<br class="">both, but adding a structured-log option would be relatively easy (although<br class="">in a different patch series).<br class=""><br class="">I don’t think glib has command-line driven conditional logging today, beyond<br class="">the debug, info, warning and error levels. Christophe F’s message (quoted<br class="">above) hints at such a facility, but I did not find it.<br class=""><br class=""></blockquote><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">gtk+ has probably more debug and tracing needs than spice-gtk (and perhaps spice-server), yet they seem to be fine with glib facilities for now.</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>At the moment, I care more about instrumenting Spice to understand its behavior.</div><div><br class=""></div><div>But for what it’s worth, the current GTK implementation does not make any use of anything in glib to implement its conditional tracing code. What they have is a more naive version of what I did. It’s more naive because it’s not scalable (limited to 64 flags on a 64-bit system), and you have to hand-edit flags, options, etc. So it’s complicated to add a new trace. Here is for example what it takes to add a “snapshot” trace: <a href="https://github.com/GNOME/gtk/commit/def94f03e240babfd589c8ba8e7cc4961a3d6aab" class="">https://github.com/GNOME/gtk/commit/def94f03e240babfd589c8ba8e7cc4961a3d6aab</a></div><div><br class=""></div><div>Contrast with what it would take with my implementation: <a href="https://github.com/c3d/spice-common/commit/5b2919615c0f55f05a0e1ec6c1a5f238e97b00f8" class="">https://github.com/c3d/spice-common/commit/5b2919615c0f55f05a0e1ec6c1a5f238e97b00f8</a>.</div><div><br class=""></div><div>The combination of “not scalable” and “complicated to add a trace” probably explains why there are presently only 20 traces active in the whole code. It's also unnecessarily slow, since it goes through a loop iterating over displays in gtk_get_display_debug_flags() to find display-specific flags, a non-requirement for spice (and if it became a requirement, looping over all displays would probably the last thing on my mind to implement it).</div><div><br class=""></div><div><br class=""></div><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">fwiw, gtk+ uses a simple bitflag and a macro GDK_DEBUG_CHECK() / GTK_DEBUG_CHECK() to provide conditional debugging information (only with --enable-debug iirc).</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>Yes. Using a manual bitflag is what I called a “naive” implementation. My use of the pre-processor allows the code to generate option parsing to be generated automatically. So you change one file and only one file. And you don’t need to manually write things like 1<<19 when you add a trace.</div><br class=""><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class=""><br class=""><blockquote type="cite" class="">or try to find a way to use qemu tracing facility (ftrace/lttng etc).<br class=""></blockquote><br class="">While it does offer some (ultra-complicated) way to do conditional logging,<br class=""></blockquote><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">but problably more powerful :)</span></div></blockquote><div><br class=""></div><div>Well, the kernel tracing infrastructure is intended to trace stuff inside a kernel. That a system using kernel facilities extensively like KVM/QEMU uses the kernel tracing facilities makes quite a bit of sense. That’s one case where you want to see events in the proper sequence between kernel and user-space operations. An argument could be made for tracing infrastructure in, say, the QXL driver. But for spicy, it does not make any sense to me.</div><div><br class=""></div><blockquote type="cite" class=""><div class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">and more importantly commonly available, used and maintained.</span></div></blockquote><div><br class=""></div><div>For the kernel, yes. Do you know of any purely user-space program that uses ftrace for their own internal state?</div><div><br class=""></div><br class=""><blockquote type="cite" class=""><div class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class=""> So there are probably more documentation available for those than a new solution.</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div><div>As I wrote earlier, that kernel infrastructure is much closer to the “recorder” I talked about earlier. The recorder is *much* simpler than the kernel trace API. Two headers (ring buffer and recorder), one C file, 1262 LOCs with comments. By comparison, last time I checked, the kernel tracing code was 51308 lines of code, 8 headers, automatic code-generation tools, etc. And unlike the kernel tracing subsystem, the recorder is specifically designed to integrate non-intrusively in a user-space program.</div><div><br class=""></div><div>There’s something to be said for simplicity. So far, I have integrated “my” recorder in Mesa, Spice or BTRFS in a couple of hours each time. There’s no way to do that with the kernel infrastructure IMO.</div><div><br class=""></div><div>But again, this has absolutely nothing to do with conditional tracing code. This is yet another case a “where do I store stuff and how” (e.g. for the recorder in a ring buffer). This has nothing to do with enabling / disabling specific debug code (although, granted, the ftrace interface does have this capability, but in a way that only applies to the kernel, i.e. writing to /sys files, not command-line options or environment variables).</div><div><br class=""></div><blockquote type="cite" class=""></blockquote></div><br class=""><blockquote type="cite" class=""><div class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">Also, when tracing, you often need to consider what's happening outside of your domain, so it's quite important that the tracing facility is used by others.</span></div></blockquote><div><br class=""></div><div>Actually, the purpose of this kind of tracing is to offer domain-specific, focused tracing. So in the majority fo cases, you don’t need to consider what is happening outside of the domain, on the contrary, you really want it out of the way. And if/when you do care about it, then you get that data in your instrumentation, not by activating some tracing in another domain. For example, for Tao3D, number of polygons is important, but the -t polygons does not give you that information by activating some polygon tracing in the OpenGL domain. Instead, it collects statistics relevant to Tao3D from OpenGL, and presents them in a usable form.</div><div><br class=""></div><br class=""><blockquote type="cite" class=""><div class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class=""> This is a great argument to keep using glog/glib, obviously for the gtk+ client, but also for the server that uses more and more glib/gobject/gst etc. ftrace/lttng is quite more low level and linux-specific, so probably not the best userspace solution.</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>Agreed, ftrace is definitely not a solution to my problem, let alone the best one.</div><div><br class=""></div><div>I can consider making a glib version of spice_trace(). But I think it will be unnecessarily complicated to get it accepted. And I don’t see what we’d gain from it.</div><div><br class=""></div><br class=""><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><blockquote type="cite" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class="">this is a kernel / server-side logging facility. I want to instrument spice<br class="">itself (client also, not just server). I think using this kind of<br class="">infrastructure could be done, but we are talking about something that, at<br class="">first sight, looks two orders of magnitude more complicated to write and to<br class="">use, only addresses some of my use-cases, and probably several times slower.<br class=""><br class="">BTW, these tools also address post-mortem logging. I also have something in<br class="">the pipe, see <a href="https://github.com/c3d/spice-gtk/compare/master...c3d:recorder" class="">https://github.com/c3d/spice-gtk/compare/master...c3d:recorder</a><br class="">and the associated submodule <a href="https://github.com/c3d/recorder/" class="">https://github.com/c3d/recorder/</a>. But that’s<br class="">for a later RFC. If only Linux had control-T, you would know the joy of<br class="">hitting Control-T at your terminal window right after Spicy does something<br class="">funny, and getting a dump of what it just did, as if you had SPICE_DEBUG to<br class="">start with :-)<br class=""><br class="">(that other patch series has a problem, that the recorder does not like<br class="">dynamic strings, so batch-converting existing messages is more challenging).<br class=""></blockquote><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">As you can see, I am quite reluctant to adding yet another logging/tracing framework to our already (very) long list of tools/libraries. In fact, I am very happy that we killed a dependency on log4cpp some time ago in favour of glib (we were the only users in rhel at that time, and it was quite a pain to use tbh :).</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""></div></blockquote><div><br class=""></div><div>Well, we may have a long list of tools and libraries, but right now, prying even what I consider the most basic information out of Spice is a real pain IMO. If you have a nice grep for the use cases I listed above (e.g. FPS, network bandwidth, memory usage, etc), let me know. For now, to me, this is a problem that is not solved. And that I believe my proposal would solve relatively elegantly.</div><div><br class=""></div><div>Also, while <a href="https://bugs.freedesktop.org/show_bug.cgi?id=91838" class="">https://bugs.freedesktop.org/show_bug.cgi?id=91838</a> mentions a possible solution to the same class of problems that my proposal solves, I believe the solution presented here is much simpler and easier to implement. 91838 has been opened since Sep 2015. My solution took me a couple of days to implement and test.</div><div><br class=""></div><div>As for integrating the recorder… well, if there is an existing framework that does what I’m doing with it, then fine. I don’t know of any, and I looked.</div><div><br class=""></div><div><br class=""></div><div>Christophe</div><div><br class=""></div><blockquote type="cite" class=""><div class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">thanks</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">_______________________________________________</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><span style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px; float: none; display: inline !important;" class="">Spice-devel mailing list</span><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><a href="mailto:Spice-devel@lists.freedesktop.org" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class="">Spice-devel@lists.freedesktop.org</a><br style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; word-spacing: 0px; -webkit-text-stroke-width: 0px;" class=""><a href="https://lists.freedesktop.org/mailman/listinfo/spice-devel" style="font-family: Helvetica; font-size: 12px; font-style: normal; font-variant-caps: normal; font-weight: normal; letter-spacing: normal; orphans: auto; text-align: start; text-indent: 0px; text-transform: none; white-space: normal; widows: auto; word-spacing: 0px; -webkit-text-size-adjust: auto; -webkit-text-stroke-width: 0px;" class="">https://lists.freedesktop.org/mailman/listinfo/spice-devel</a></div></blockquote></div><br class=""></body></html>