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