documentation/debugging.sgml

   1   <chapter id="debugging">
   2     <title>Debug Logging</title>
   3
   4       <para>
   5         Written by &name-dimitrie-paun; <email>&email-dimitrie-paun;</email>, 28 Mar 1998
   6       </para>
   7       <para>
   8         (Extracted from <filename>wine/documentation/debug-msgs</filename>)
   9       </para>
  10
  11       <note>
  12         <para>
  13           It is possible to turn on and of debugging output from
  14           within the debugger using the set command. Please see the
  15           WineDbg Command Reference section for how to do this.
  16         </para>
  17       </note>
  18
  19       <important>
  20         <para>
  21           At the end of the document, there is a "Style Guide" for
  22           debugging messages. Please read it.
  23         </para>
  24       </important>
  25
  26       <sect1 id="dbg-classes">
  27         <title>Debugging classes</title>
  28
  29         <para>
  30           There are 4 types (or classes) of messages:
  31         </para>
  32         <variablelist>
  33           <varlistentry>
  34             <term><literal>FIXME</literal></term>
  35             <listitem>
  36               <para>
  37                 Messages in this class are meant to signal unimplemented
  38                 features, known bugs, etc. They serve as a constant and
  39                 active reminder of what needs to be done.
  40               </para>
  41               <para>Examples: stubs, semi-implemented features, etc.</para>
  42             </listitem>
  43           </varlistentry>
  44           <varlistentry>
  45             <term><literal>ERR</literal></term>
  46             <listitem>
  47               <para>
  48                 Messages in this class relate to serious errors in
  49                 Wine. This sort of messages signal an inconsistent
  50                 internal state, or more general, a condition which
  51                 should never happen by design.
  52               </para>
  53               <para>
  54                 Examples: unexpected change in internal state, etc.
  55               </para>
  56             </listitem>
  57           </varlistentry>
  58           <varlistentry>
  59             <term><literal>WARN</literal></term>
  60             <listitem>
  61               <para>
  62                 These are warning messages. You should report a
  63                 warning when something unwanted happen but the
  64                 function behaves properly. That is, output a warning
  65                 when you encounter something unexpected (ex: could not
  66                 open a file) but the function deals correctly with the
  67                 situation (that is, according to the docs). If you do
  68                 not deal correctly with it, output a fixme.
  69               </para>
  70               <para>
  71                 Examples: fail to access a resource required by the app.
  72               </para>
  73             </listitem>
  74           </varlistentry>
  75           <varlistentry>
  76             <term><literal>TRACE</literal></term>
  77             <listitem>
  78               <para>
  79                 These are detailed debugging messages that are mainly
  80                 useful to debug a component. These are usually turned
  81                 off.
  82               </para>
  83               <para>
  84                 Examples: everything else that does not fall in one of
  85                 the above mentioned categories and the user does not
  86                 need to know about it.
  87               </para>
  88             </listitem>
  89           </varlistentry>
  90         </variablelist>
  91       </sect1>
  92
  93       <sect1 id="dbg-channels">
  94         <title>Debugging channels</title>
  95
  96         <para>
  97           To better manage the large volume of debugging messages that
  98           Wine can generate, we divide them also on a component basis.
  99           Each component is assigned a debugging channel. The
 100           identifier of the channel must be a valid C identifier but
 101           note that it may also be a reserved word like
 102           <type>int</type> or <type>static</type>.
 103         </para>
 104         <para>
 105           Examples of debugging channels:
 106           <simplelist type="inline">
 107             <member><literal>reg</literal></member>
 108             <member><literal>updown</literal></member>
 109             <member><literal>string</literal></member>
 110           </simplelist>
 111         </para>
 112         <para>
 113           We will refer to a generic channel as <literal>xxx</literal>.
 114         </para>
 115       </sect1>
 116
 117       <sect1 id="dbg-using">
 118         <title>How to use it</title>
 119
 120         <para>
 121         Typically, a file contains code pertaining to only one component,
 122         and as such, there is only one channel to output to. To simplify
 123         usage, you can declare that channel at the beginning of the file,
 124         and simply write FIXMEs, ERRs, etc. as such:
 125
 126         <programlisting>
 127 #include "wine/debug.h"
 128
 129 WINE_DEFAULT_DEBUG_CHANNEL(xxx);
 130 ...
 131
 132     FIXME("some unimplemented feature", ...);
 133 ...
 134     if (zero != 0)
 135         ERR("This should never be non-null: %d", zero);
 136 ...
 137         </programlisting>
 138         </para>
 139         <para>
 140           In rare situations there is a need to output to more than one
 141           debug channel per file. In such cases, you need to declare
 142           all the additional channels at the top of the file, and
 143           use the _-version of the debugging macros:
 144         <programlisting>
 145 #include "wine/debug.h"
 146
 147 WINE_DEFAULT_DEBUG_CHANNEL(xxx);
 148 WINE_DECLARE_DEBUG_CHANNEL(yyy);
 149 WINE_DECLARE_DEBUG_CHANNEL(zzz);
 150 ...
 151
 152     FIXME("this one goes to xxx channel");
 153 ...
 154     FIXME_(yyy)("Some other msg for the yyy channel");
 155 ...
 156     WARN_(zzz)("And yet another msg on another channel!");
 157 ...
 158         </programlisting>
 159         </para>
 160
 161         <para>
 162           If you need to declare a new debugging channel, simply use it in
 163           your code. It will be picked up automatically by the build process.
 164         </para>
 165
 166       </sect1>
 167
 168       <sect1 id="dbg-checking">
 169         <title>Are we debugging?</title>
 170
 171         <para>
 172           To test whether the debugging output of class
 173           <literal>yyy</literal> on channel <literal>xxx</literal> is
 174           enabled, use:
 175         </para>
 176         <screen>
 177 TRACE_ON  to test if TRACE is enabled
 178 WARN_ON   to test if WARN is enabled
 179 FIXME_ON  to test if FIXME is enabled
 180 ERR_ON    to test if ERR is enabled
 181         </screen>
 182         <para>
 183           Examples:
 184         </para>
 185         <programlisting>
 186 if(TRACE_ON(atom)){
 187   ...blah...
 188 }
 189         </programlisting>
 190
 191         <note>
 192           <para>
 193             You should normally need to test only if
 194             <literal>TRACE_ON</literal>. At present, none of the other
 195             3 tests (except for <literal>ERR_ON</literal> which is
 196             used only once!) are used in Wine.
 197           </para>
 198         </note>
 199       </sect1>
 200
 201       <sect1 id="dbg-resource-ids">
 202         <title>Resource identifiers</title>
 203
 204         <para>
 205           Resource identifiers can be either strings or numbers. To
 206           make life a bit easier for outputting these beasts (and to
 207           help you avoid the need to build the message in memory), I
 208           introduced a new function called <function>debugres</function>.
 209         </para>
 210         <para>
 211           The function is defined in <filename>wine/debug.h</filename>
 212           and has the following prototype:
 213         </para>
 214         <programlisting>
 215 LPSTR debugres(const void *id);
 216         </programlisting>
 217         <para>
 218           It takes a pointer to the resource id and returns a nicely
 219           formatted string of the identifier (which can be a string or
 220           a number, depending on the value of the high word).
 221           Numbers are formatted as such:
 222         </para>
 223         <programlisting>
 224 #xxxx
 225         </programlisting>
 226         <para>
 227           while strings as:
 228         </para>
 229         <programlisting>
 230 'some-string'
 231         </programlisting>
 232         <para>
 233           Simply use it in your code like this:
 234         </para>
 235         <programlisting>
 236 #include "wine/debug.h"
 237
 238 ...
 239
 240    TRACE("resource is %s", debugres(myresource));
 241         </programlisting>
 242       </sect1>
 243
 244       <sect1 id="dbg-param">
 245         <title>The <parameter>--debugmsg</parameter> command line option</title>
 246
 247         <para>
 248           The <parameter>--debugmsg</parameter> command line
 249           option controls the output of the debug messages.
 250           It has the following syntax:
 251           <parameter>--debugmsg [yyy]#xxx[,[yyy1]#xxx1]*</parameter>
 252         </para>
 253         <itemizedlist>
 254           <listitem>
 255             <para>
 256               where
 257               <literal>#</literal> is either <literal>+</literal> or
 258               <literal>-</literal>
 259             </para>
 260           </listitem>
 261           <listitem>
 262             <para>
 263               when the optional class argument (<literal>yyy</literal>)
 264               is not present, then the statement will
 265               enable(<literal>+</literal>)/disable(<literal>-</literal>)
 266               all messages for the given channel (<literal>xxx</literal>)
 267               on all classes. For example:
 268             </para>
 269             <programlisting>
 270 --debugmsg +reg,-file
 271             </programlisting>
 272             <para>
 273               enables all messages on the <literal>reg</literal>
 274               channel and disables all messages on the
 275               <literal>file</literal> channel.
 276             </para>
 277           </listitem>
 278           <listitem>
 279             <para>
 280               when the optional class argument (<literal>yyy</literal>)
 281               is present,  then the statement will enable
 282               (<literal>+</literal>)/disable(<literal>-</literal>)
 283               messages for the given channel (<literal>xxx</literal>)
 284               only on the given class. For example:
 285             </para>
 286             <programlisting>
 287 --debugmsg trace+reg,warn-file
 288             </programlisting>
 289             <para>
 290               enables trace messages on the <literal>reg</literal>
 291               channel and disables warning messages on the
 292               <literal>file</literal> channel.
 293             </para>
 294           </listitem>
 295           <listitem>
 296             <para>
 297               also, the pseudo-channel all is also supported and it
 298               has the  intuitive semantics:
 299             </para>
 300             <screen>
 301     --debugmsg +all      -- enables all debug messages
 302     --debugmsg -all      -- disables all debug messages
 303     --debugmsg yyy+all   -- enables debug messages for class yyy on all
 304                            channels.
 305     --debugmsg yyy-all   -- disables debug messages for class yyy on all
 306                            channels.
 307             </screen>
 308             <para>
 309               So, for example:
 310             </para>
 311             <screen>
 312     --debugmsg warn-all  -- disables all warning messages.
 313             </screen>
 314           </listitem>
 315         </itemizedlist>
 316
 317         <para>
 318           Also, note that at the moment:
 319         </para>
 320         <itemizedlist>
 321           <listitem>
 322             <para>the <literal>FIXME</literal> and <literal>ERR</literal>
 323               classes are enabled by default</para>
 324           </listitem>
 325           <listitem>
 326             <para>the <literal>TRACE</literal> and
 327               <literal>WARN</literal> classes are disabled by
 328               default</para>
 329           </listitem>
 330         </itemizedlist>
 331       </sect1>
 332
 333       <sect1 id="dbg-compiling">
 334         <title>Compiling Out Debugging Messages</title>
 335
 336         <para>
 337           To compile out the debugging messages, provide
 338           <command>configure</command> with the following options:
 339         </para>
 340         <screen>
 341     --disable-debug      -- turns off TRACE, WARN, and FIXME (and DUMP).
 342     --disable-trace      -- turns off TRACE only.
 343         </screen>
 344         <para>
 345           This will result in an executable that, when stripped, is
 346           about 15%-20% smaller.  Note, however, that you will not be
 347           able to effectively debug Wine without these messages.
 348         </para>
 349         <para>
 350           This feature has not been extensively tested--it may subtly
 351           break some things.
 352         </para>
 353       </sect1>
 354
 355       <sect1 id="dbg-notes">
 356         <title>A Few Notes on Style</title>
 357
 358         <para>
 359           This new scheme makes certain things more consistent but
 360           there is still room for improvement by using a common style
 361           of debug messages. Before I continue, let me note that the
 362           output format is the following:
 363         </para>
 364         <screen>
 365 yyy:xxx:fff &lt;message>
 366
 367 where:
 368   yyy = the class (fixme, err, warn, trace)
 369   xxx = the channel (atom, win, font, etc)
 370   fff = the function name
 371         </screen>
 372         <para>
 373           these fields are output automatically. All you have to
 374           provide is the &lt;message> part.
 375         </para>
 376         <para>
 377           So here are some ideas:
 378         </para>
 379
 380         <itemizedlist>
 381           <listitem>
 382             <para>do NOT include the name of the function: it is included automatically</para>
 383           </listitem>
 384           <listitem>
 385             <para>
 386               if you want to output the parameters of the function, do
 387               it as the first thing and include them in parentheses,
 388               like this:
 389               <programlisting>
 390 TRACE("(%d, %p, ...)\n", par1, par2, ...);
 391               </programlisting>
 392             </para>
 393           </listitem>
 394           <listitem>
 395             <para>
 396               for stubs, you should output a <literal>FIXME</literal>
 397               message. I suggest this style:
 398               <programlisting>
 399 FIXME("(%x, %d, ...): stub\n", par1, par2, ...);
 400               </programlisting>
 401             </para>
 402           </listitem>
 403           <listitem>
 404             <para>
 405               try to output one line per message. That is, the format
 406               string should contain only one <literal>\n</literal> and it
 407               should always appear at the end of the string. (there are
 408               many reasons  for this requirement, one of them is that
 409               each debug macro adds things to the beginning of the line)
 410             </para>
 411           </listitem>
 412           <listitem>
 413             <para>
 414               if you want to name a value, use <literal>=</literal> and
 415               NOT <literal>:</literal>. That is, instead of saying:
 416               <programlisting>
 417 FIXME("(fd: %d, file: %s): stub\n", fd, name);
 418               </programlisting>
 419               say:
 420               <programlisting>
 421 FIXME("(fd=%d, file=%s): stub\n", fd, name);
 422               </programlisting>
 423               use <literal>:</literal> to separate categories.
 424             </para>
 425           </listitem>
 426           <listitem>
 427             <para>
 428               try to avoid the style:
 429               <programlisting>
 430 FIXME(xxx, "(fd=%d, file=%s)\n", fd, name);
 431               </programlisting>
 432               instead use:
 433               <programlisting>
 434 FIXME(xxx, "(fd=%d, file=%s): stub\n", fd, name);
 435               </programlisting>
 436               The reason is that if you want to <command>grep</command>
 437               for things, you would search for <literal>FIXME</literal>
 438               but in the first case there is no additional information
 439               available, where in the second one, there is (e.g. the word
 440               stub)
 441             </para>
 442           </listitem>
 443           <listitem>
 444             <para>
 445               if you output a string s that might contain control
 446               characters, or if <parameter>s</parameter> may be
 447               <literal>NULL</literal>, use
 448               <function>debugstr_a</function> (for ASCII strings, or
 449               <function>debugstr_w</function> for Unicode strings) to
 450               convert <parameter>s</parameter> to a C string, like  this:
 451               <programlisting>
 452 HANDLE32 WINAPI YourFunc(LPCSTR s)
 453 {
 454     FIXME("(%s): stub\n", debugstr_a(s));
 455 }
 456               </programlisting>
 457             </para>
 458           </listitem>
 459           <listitem>
 460             <para>
 461               if you want to output a resource identifier, use debugres to
 462               convert it to a string first, like this:
 463               <programlisting>
 464 HANDLE32 WINAPI YourFunc(LPCSTR res)
 465 {
 466     FIXME("(res=%s): stub\n", debugres(s));
 467 }
 468               </programlisting>
 469               if the resource identifier is a <type>SEGPTR</type>, use
 470               <function>PTR_SEG_TO_LIN</function> to get a
 471               liner pointer first:
 472               <programlisting>
 473 HRSRC16 WINAPI FindResource16( HMODULE16 hModule, SEGPTR name, SEGPTR type )
 474 {
 475 [...]
 476     TRACE(resource, "module=%04x name=%s type=%s\n",
 477                  hModule, debugres(PTR_SEG_TO_LIN(name)),
 478                  debugres(PTR_SEG_TO_LIN(type)) );
 479 [...]
 480 }
 481               </programlisting>
 482             </para>
 483           </listitem>
 484           <listitem>
 485             <para>
 486               for messages intended for the user (specifically those that
 487               report errors in the wine config file), use the
 488               <literal>MSG</literal> macro. Use it like a
 489               <function>printf</function>:
 490               <programlisting>
 491 MSG( "Definition of drive %d is incorrect!\n", drive );
 492               </programlisting>
 493               However, note that there are <emphasis>very</emphasis> few
 494               valid uses of this macro. Most messages are debugging
 495               messages, so chances are you will not need to use this
 496               macro. Grep the source to get an idea where it is
 497               appropriate to use it.
 498             </para>
 499           </listitem>
 500           <listitem>
 501             <para>
 502               For structure dumps, use the <function>DUMP</function>
 503               macro. Use it like a <function>printf</function>, just like
 504               the <literal>MSG</literal> macro. Similarly, there are only
 505               a few valid uses of this macro. Grep the source to see when
 506               to use it.
 507             </para>
 508           </listitem>
 509         </itemizedlist>
 510       </sect1>
 511
 512   </chapter>
 513
 514 <!-- Keep this comment at the end of the file
 515 Local variables:
 516 mode: sgml
 517 sgml-parent-document:("wine-devel.sgml" "set" "book" "part" "chapter" "")
 518 End:
 519 -->