Set low-order bit of module handle for LOAD_LIBRARY_AS_DATAFILE.
[wine] / 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           The new debugging interface can be considered to be
14           stable, with the exception of the in-memory message
15           construction functions. However, there is still a lot of
16           work to be done to polish things up. To make my life
17           easier, please follow the guidelines described in this
18           document. 
19         </para>
20       </note>
21
22       <important>
23         <para>
24           Read this document before writing new code. DO NOT USE
25           <function>fprintf</function>  (or
26           <function>printf</function>) to output things. Also, instead
27           of writing  FIXMEs in the source, output a FIXME message if
28           you can. 
29         </para>
30         <para>
31           At the end of the document, there is a "Style Guide" for
32           debugging messages. Please read it.
33         </para>
34       </important>
35
36       <sect1 id="dbg-classes">
37         <title>Debugging classes</title>
38
39         <para>
40           There are 4 types (or classes) of debugging messages:
41         </para>
42         <variablelist>
43           <varlistentry>
44             <term><literal>FIXME</literal></term>
45             <listitem>
46               <para>
47                 Messages in this class relate to behavior of Wine that
48                 does not correspond to standard Windows behavior and
49                 that should be fixed. 
50               </para>
51               <para>Examples: stubs, semi-implemented features, etc.</para>
52             </listitem>
53           </varlistentry>
54           <varlistentry>
55             <term><literal>ERR</literal></term>
56             <listitem>
57               <para>
58                 Messages in this class relate to serious errors in
59                 Wine. This sort of messages are close to asserts --
60                 that is, you should output an error message when the
61                 code detects a condition which should not happen. In
62                 other words, important things that are not warnings
63                 (see below), are errors. 
64               </para>
65               <para>
66                 Examples: unexpected change in internal state, etc.
67               </para>
68             </listitem>
69           </varlistentry>
70           <varlistentry>
71             <term><literal>WARN</literal></term>
72             <listitem>
73               <para>
74                 These are warning messages. You should report a
75                 warning when something unwanted happen but the
76                 function behaves properly. That is, output a warning
77                 when you encounter something unexpected (ex: could not
78                 open a file) but the function deals correctly with the
79                 situation (that is, according to the docs). If you do
80                 not deal correctly with it, output a fixme. 
81               </para>
82               <para>
83                 Examples: fail to access a resource required by the
84                 app, etc.
85               </para>
86             </listitem>
87           </varlistentry>
88           <varlistentry>
89             <term><literal>TRACE</literal></term>
90             <listitem>
91               <para>
92                 These are detailed debugging messages that are mainly
93                 useful  to debug a component. These are usually turned
94                 off.
95               </para>
96               <para>
97                 Examples: everything else that does not fall in one of
98                 the above mentioned categories and the user does not
99                 need to know about it.
100               </para>
101             </listitem>
102           </varlistentry>
103         </variablelist>
104
105         <para>
106           The user has the capability to turn on or off messages of a
107           particular type. You can expect the following patterns of
108           usage (but note that  any combination is possible):
109         </para>
110         <itemizedlist>
111           <listitem>
112             <para>
113               when you debug a component, all types
114               (<literal>TRACE</literal>, <literal>WARN</literal>,
115               <literal>ERR</literal>, <literal>FIXME</literal>) will
116               be enabled.
117             </para>
118           </listitem>
119           <listitem>
120             <para>
121               during the pre-alpha (maybe alpha) stage of Wine, most
122               likely the <literal>TRACE</literal> class will be
123               disabled by default, but all others
124               (<literal>WARN</literal>, <literal>ERR</literal>,
125               <literal>FIXME</literal>) will be enabled by default.
126             </para>
127           </listitem>
128           <listitem>
129             <para>
130               when Wine will become stable, most likely the
131               <literal>TRACE</literal> and <literal>WARN</literal>
132               classes will be disabled by default, but all
133               <literal>ERR</literal>s and <literal>FIXME</literal>s
134               will be enabled.
135             </para>
136           </listitem>
137           <listitem>
138             <para>
139               in some installations that want the smallest footprint
140               and where the debug information is of no interest,  all
141               classes may be disabled by default.
142             </para>
143           </listitem>
144         </itemizedlist>
145         <para>
146           Of course, the user will have the runtime ability to
147           override these defaults. However, this ability may be turned
148           off and certain classes of messages may be completely
149           disabled at compile time to reduce the  size of Wine.
150         </para>
151       </sect1>
152
153       <sect1 id="dbg-channels">
154         <title>Debugging channels</title>
155
156         <para>
157           Also, we divide the debugging messages on a component basis.
158           Each component is assigned a debugging channel. The
159           identifier of the channel must be a valid C identifier but
160           note that it may also be a reserved word like
161           <type>int</type> or <type>static</type>.
162         </para>
163         <para>
164           Examples of debugging channels:
165           <simplelist type="inline">
166             <member><literal>reg</literal></member>
167             <member><literal>updown</literal></member>
168             <member><literal>string</literal></member>
169           </simplelist>
170         </para>
171         <para>
172           We will refer to a generic channel as <literal>xxx</literal>.
173         </para>
174         <note>
175           <para>
176             for those who know the old interface, the channel/type is
177             what followed the _ in the
178             <function>dprintf_xxx</function> statements. For example,
179             to output a message on the debugging channel
180             <literal>reg</literal> in the old interface you would had
181             to write:
182           </para>
183           <programlisting>
184 dprintf_reg(stddeb, "Could not access key!\n");
185           </programlisting>
186           <para>
187             In the new interface, we drop the
188             <literal>stddeb</literal> as it is implicit. However, we
189             add an orthogonal piece of information to the message: its
190             class. This is very important as it will allow us to
191             selectively turn on or off certain messages based on the
192             type of information they report. For this reason it is
193             essential to choose the right class for the message.
194             Anyhow, suppose we figured that this message should belong
195             in the <literal>WARN</literal> class, so in the new
196             interface, you write:
197           </para>
198           <programlisting>
199 WARN(reg, "Could not access key!\n");
200           </programlisting>
201         </note>
202       </sect1>
203
204       <sect1 id="dbg-using">
205         <title>How to use it</title>
206
207         <para>
208           So, to output a message (class <literal>YYY</literal>) on
209           channel <literal>xxx</literal>, do:
210         </para>
211         <programlisting>
212 #include "debug.h"
213
214 ....
215
216 YYY(xxx, "&lt;message>", ...);
217         </programlisting>
218         <para>
219           Some examples from the code:
220         </para>
221         <programlisting>
222 #include "debug.h"
223
224 ...
225
226   TRACE(crtdll, "CRTDLL_setbuf(file %p buf %p)", file, buf);
227
228   WARN(aspi, "Error opening device errno=%d", save_error);
229         </programlisting>
230         <para>
231           If you need to declare a new debugging channel, use it in
232           your code and then do:
233         </para>
234         <screen>
235 %tools/make_debug
236         </screen>
237         <para>
238           in the root directory of Wine. Note that this will result in
239           almost complete recompilation of Wine.
240         </para>
241
242         <note>
243           <orderedlist>
244             <listitem>
245               <para>
246                 Please pay attention to which class you assign the
247                 message. There are only 4 classes, so it is not hard.
248                 The reason it is important to get it right is that too
249                 much information is no information. For example, if
250                 you put things into the <literal>WARN</literal> class
251                 that should really be in the <literal>TRACE</literal>
252                 class, the  output will be too big and this will force
253                 the user to  turn warnings off. But this way he will
254                 fail to see the important ones. Also, if you put
255                 warnings into the <literal>TRACE</literal> class lets
256                 say, he will most likely miss those because usually
257                 the <literal>TRACE</literal> class is turned off. A
258                 similar argument can be made if you mix any other two
259                 classes.
260               </para>
261             </listitem>
262             <listitem>
263               <para>
264                 All lines should end with a newline. If you can NOT
265                 output everything that you want in the line with only
266                 one statement, then you need to build the string in
267                 memory. Please read the section below "In-memory
268                 messages" on the preferred way to do it. PLEASE USE
269                 THAT INTERFACE TO BUILD MESSAGES IN MEMORY. The reason
270                 is that we are not sure that we like it and having
271                 everything in one format will facilitate the
272                 (automatic) translation to a better interface.
273               </para>
274             </listitem>
275           </orderedlist>
276         </note>
277       </sect1>
278
279       <sect1 id="dbg-checking">
280         <title>Are we debugging?</title>
281
282         <para>
283           To test whether the debugging output of class
284           <literal>yyy</literal> on channel <literal>xxx</literal> is
285           enabled, use:
286         </para>
287         <screen>
288 TRACE_ON  to test if TRACE is enabled
289 WARN_ON   to test if WARN is enabled
290 FIXME_ON  to test if FIXME is enabled
291 ERR_ON    to test if ERR is enabled
292         </screen>
293         <para>
294           Examples:
295         </para>
296         <programlisting>
297 if(TRACE_ON(atom)){
298   ...blah...
299 }
300         </programlisting>
301
302         <note>
303           <para>
304             You should normally need to test only if
305             <literal>TRACE_ON</literal>. At present, none of the other
306             3 tests (except for <literal>ERR_ON</literal> which is
307             used only once!) are used in Wine.
308           </para>
309         </note>
310       </sect1>
311
312       <sect1 id="dbg-in-memory">
313         <title>In-memory messages</title>
314
315         <para>
316           If you NEED to build the message from multiple calls, you
317           need to  build it in memory. To do that, you should use the
318           following interface:
319         </para>
320
321         <orderedlist>
322           <listitem>
323             <para>
324               declare a string (where you are allowed to declare C
325               variables) as follows:
326             <programlisting>
327 dbg_decl_str(name, len);
328             </programlisting>
329               where <parameter>name</parameter> is the name of the
330               string (you should use the channel name on which you
331               are going to output it)
332             </para>
333           </listitem>
334           <listitem>
335             <para>
336               print in it with:
337             <programlisting>
338 dsprintf(name, "&lt;message>", ...);
339             </programlisting>
340               which is just like a <function>sprintf</function>
341               function but instead of a C string as first parameter it
342               takes the name you used to declare it.
343             </para>
344           </listitem>
345           <listitem>
346             <para>
347               obtain a pointer to the string with: <function>dbg_str(name)</function>
348             </para>
349           </listitem>
350           <listitem>
351             <para>
352               reset the string (if you want to reuse it with):
353               <programlisting>
354 dbg_reset_str(name);
355               </programlisting>
356             </para>
357           </listitem>
358         </orderedlist>
359
360         <para>
361           Example (modified from the code):
362         </para>
363         <programlisting>
364 void some_func(tabs)
365 {
366   INT32 i;
367   LPINT16 p = (LPINT16)tabs;
368   dbg_decl_str(listbox, 256);                   /* declare the string */
369
370   for (i = 0; i &lt; descr->nb_tabs; i++) {
371     descr->tabs[i] = *p++&lt;&lt;1; 
372     if(TRACING(listbox))                         /* write in it only if
373       dsprintf(listbox, "%hd ", descr->tabs[i]); /* we are gonna output it */
374   }
375   TRACE(listbox, "Listbox %04x: settabstops %s", 
376         wnd->hwndSelf, dbg_str(listbox));        /* output the whole thing */
377 }
378         </programlisting>
379         <para>
380           If you need to use it two times in the same scope do like
381           this:
382         </para>
383         <programlisting>
384 void some_func(tabs)
385 {
386   INT32 i;
387   LPINT16 p = (LPINT16)tabs;
388   dbg_decl_str(listbox, 256);                   /* declare the string      */
389
390   for (i = 0; i &lt; descr->nb_tabs; i++) {
391     descr->tabs[i] = *p++&lt;&lt;1;  
392     if(TRACING(listbox))                         /* write in it only if
393       dsprintf(listbox, "%hd ", descr->tabs[i]); /* we are gonna output it */
394   }
395   TRACE(listbox, "Listbox %04x: settabstops %s\n", 
396         wnd->hwndSelf, dbg_str(listbox));        /* output the whole thing */
397
398   dbg_reset_str(listbox);                        /* !!!reset the string!!! */
399   for (i = 0; i &lt; descr->extrainfo_nr; i++) {
400     descr->extrainfo = *p+1; 
401     if(TRACING(listbox))                         /* write in it only if
402       dsprintf(listbox,"%3d ",descr->extrainfo); /* we are gonna output it */
403   }
404
405   TRACE(listbox, "Listbox %04x: extrainfo %s\n", 
406         wnd->hwndSelf, dbg_str(listbox));        /* output the whole thing */
407
408 }
409         </programlisting>
410
411         <important>
412           <para>
413             As I already stated, I do not think this will be the
414             ultimate interface for building in-memory debugging
415             messages. In fact, I do have better ideas which I hope to
416             have time to implement for the next release. For this
417             reason, please try not to use it. However, if you need to
418             output a line in more than one
419             <function>dprintf_xxx</function> calls, then USE THIS
420             INTERFACE. DO NOT use other methods. This way, I will
421             easily translate everything to the new interface (when it
422             will become available). So, if you need to use it, then
423             follow the following guidelines:
424           </para>
425           <itemizedlist>
426             <listitem>
427               <para>wrap calls to <function>dsprintf</function> with a
428               </para>
429               <programlisting>
430 if(YYY(xxx))
431   dsprintf(xxx,...);
432               </programlisting>
433               <para>
434                 Of course, if the call to
435                 <function>dsprintf</function> is made from within a
436                 function  which you know is called only if
437                 <function>YYY(xxx)</function> is true, for example if
438                 you call it only like this:
439               </para>
440               <programlisting>
441 if(YYY(xxx))
442   print_some_debug_info();
443               </programlisting>
444               <para>
445                 then you need not (and should not) wrap calls to
446                 <function>dsprintf</function> with the before
447                 mentioned <function>if</function>.
448               </para>
449             </listitem>
450             <listitem>
451               <para>
452                 name the string EXACTLY like the debugging channel on
453                 which is going to be output. Please see the above
454                 example. 
455               </para>
456             </listitem>
457           </itemizedlist>
458         </important>
459       </sect1>
460
461       <sect1 id="dbg-resource-ids">
462         <title>Resource identifiers</title>
463
464         <para>
465           Resource identifiers can be either strings or numbers. To
466           make life a bit easier for outputting these beasts (and to
467           help you avoid the need to build the message in memory), I
468           introduced a new function called <function>debugres</function>.
469         </para>
470         <para>
471           The function is defined in <filename>debugstr.h</filename>
472           and has the following prototype:
473         </para>
474         <programlisting>
475 LPSTR debugres(const void *id);
476         </programlisting>
477         <para>
478           It takes a pointer to the resource id and returns a nicely
479           formatted string of the identifier. If the high word of the
480           pointer is <literal>0</literal>, then it assumes that the
481           identifier is a number and thus returns a string of the
482           form:
483         </para>
484         <programlisting>
485 #xxxx
486         </programlisting>
487         <para>
488           where <literal>xxxx</literal> are 4 hex-digits representing
489           the low word of <parameter>id</parameter>.
490         </para>
491         <para>
492           If the high word of the pointer is not <literal>0</literal>,
493           then it assumes that the identifier is a string and thus
494           returns a string of the form:
495         </para>
496         <programlisting>
497 '&lt;identifier>'
498         </programlisting>
499         <para>
500           Thus, to use it, do something on the following lines:
501         </para>
502         <programlisting>
503 #include "debug.h"
504
505 ...
506
507    YYY(xxx, "resource is %s", debugres(myresource));
508         </programlisting>
509       </sect1>
510
511       <sect1 id="dbg-param">
512         <title>The <parameter>--debugmsg</parameter> command line option</title>
513
514         <para>
515           So, the <parameter>--debugmsg</parameter> command line
516           option has been changed as follows:
517         </para>
518         <itemizedlist>
519           <listitem>
520             <para>
521               the new syntax is: <parameter>--debugmsg
522                 [yyy]#xxx[,[yyy1]#xxx1]*</parameter> where
523               <literal>#</literal> is either <literal>+</literal> or
524               <literal>-</literal>
525             </para>
526           </listitem>
527           <listitem>
528             <para>
529               when the optional class argument (<literal>yyy</literal>)
530               is not present, then the statement will
531               enable(<literal>+</literal>)/disable(<literal>-</literal>)
532               all messages for the given channel (<literal>xxx</literal>)
533               on all classes. For example:
534             </para>
535             <programlisting>
536 --debugmsg +reg,-file
537             </programlisting>
538             <para>
539               enables all messages on the <literal>reg</literal>
540               channel and disables all messages on the
541               <literal>file</literal> channel. This is same as the old
542               semantics.
543             </para>
544           </listitem>
545           <listitem>
546             <para>
547               when the optional class argument (<literal>yyy</literal>)
548               is present,  then the statement will enable
549               (<literal>+</literal>)/disable(<literal>-</literal>)
550               messages for the given channel (<literal>xxx</literal>)
551               only on the given class. For example:
552             </para>
553             <programlisting>
554 --debugmsg trace+reg,warn-file
555             </programlisting>
556             <para>
557               enables trace messages on the <literal>reg</literal>
558               channel and disables warning messages on the
559               <literal>file</literal> channel.
560             </para>
561           </listitem>
562           <listitem>
563             <para>
564               also, the pseudo-channel all is also supported and it
565               has the  intuitive semantics:
566             </para>
567             <screen>
568     --debugmsg +all      -- enables all debug messages
569     --debugmsg -all      -- disables all debug messages   
570     --debugmsg yyy+all   -- enables debug messages for class yyy on all
571                            channels.
572     --debugmsg yyy-all   -- disables debug messages for class yyy on all
573                            channels.
574             </screen>
575             <para>
576               So, for example:
577             </para>
578             <screen>
579     --debugmsg warn-all  -- disables all warning messages.
580             </screen>
581           </listitem>
582         </itemizedlist>
583
584         <para>
585           Also, note that at the moment:
586         </para>
587         <itemizedlist>
588           <listitem>
589             <para>the <literal>FIXME</literal> and <literal>ERR</literal>
590               classes are enabled by default</para>
591           </listitem>
592           <listitem>
593             <para>the <literal>TRACE</literal> and
594               <literal>WARN</literal> classes are disabled by
595               default</para>
596           </listitem>
597         </itemizedlist>
598       </sect1>
599
600       <sect1 id="dbg-compiling">
601         <title>Compiling Out Debugging Messages</title>
602
603         <para>
604           To compile out the debugging messages, provide
605           <command>configure</command> with the following options:
606         </para>
607         <screen>
608     --disable-debug      -- turns off TRACE, WARN, and FIXME (and DUMP).
609     --disable-trace      -- turns off TRACE only.
610         </screen>
611         <para>
612           This will result in an executable that, when stripped, is
613           about 15%-20% smaller.  Note, however, that you will not be
614           able to effectively debug Wine without these messages.  
615         </para>
616         <para>
617           This feature has not been extensively tested--it may subtly
618           break some things.
619         </para>
620       </sect1>
621
622       <sect1 id="dbg-notes">
623         <title>A Few Notes on Style</title>
624
625         <para>
626           This new scheme makes certain things more consistent but
627           there is still room for improvement by using a common style
628           of debug messages. Before I continue, let me note that the
629           output format is the following:
630         </para>
631         <screen>
632 yyy:xxx:fff &lt;message>
633
634 where: 
635   yyy = the class (fixme, err, warn, trace)
636   xxx = the channel (atom, win, font, etc)
637   fff = the function name
638         </screen>
639         <para>
640           these fields are output automatically. All you have to
641           provide is the &lt;message> part.
642         </para>
643         <para>
644           So here are some ideas:
645         </para>
646
647         <itemizedlist>
648           <listitem>
649             <para>do NOT include the name of the function: it is included automatically</para>
650           </listitem>
651           <listitem>
652             <para>
653               if you want to output the parameters of the function, do
654               it as the first thing and include them in parentheses,
655               like this: 
656               <programlisting>
657 YYY(xxx, "(%d,%p,etc)...\n", par1, par2, ...);
658               </programlisting>
659             </para>
660           </listitem>
661           <listitem>
662             <para>
663               for stubs, you should output a <literal>FIXME</literal>
664               message. I suggest this style:
665               <programlisting>
666    FIXME(xxx, "(%x,%d...): stub\n", par1, par2, ...);
667               </programlisting>
668               That is, you output the parameters, then a : and then a string
669               containing the word "stub". I've seen "empty stub", and others, but I
670               think that just "stub" suffices.
671             </para>
672           </listitem>
673           <listitem>
674             <para>
675               output 1 and ONLY 1 line per message. That is, the format
676               string should contain only 1 <literal>\n</literal> and it
677               should always appear at the end of the string. (there are
678               many reasons  for this requirement, one of them is that
679               each debug macro adds things to the beginning of the line)
680             </para>
681           </listitem>
682           <listitem>
683             <para>
684               if you want to name a value, use <literal>=</literal> and
685               NOT <literal>:</literal>. That is, instead of saying:
686               <programlisting>
687 FIXME(xxx, "(fd: %d, file: %s): stub\n", fd, name);
688               </programlisting>
689               say:
690               <programlisting>
691 FIXME(xxx, "(fd=%d, file=%s): stub\n", fd, name);
692               </programlisting>
693               use <literal>:</literal> to separate categories.
694             </para>
695           </listitem>
696           <listitem>
697             <para>
698               try to avoid the style:
699               <programlisting>
700 FIXME(xxx, "(fd=%d, file=%s)\n", fd, name);
701               </programlisting>
702               but use:
703               <programlisting>
704 FIXME(xxx, "(fd=%d, file=%s): stub\n", fd, name);
705               </programlisting>
706               The reason is that if you want to <command>grep</command>
707               for things, you would search for <literal>FIXME</literal>
708               but in the first case there is no additional information
709               available, where in the second one, there is (e.g. the word
710               stub)
711             </para>
712           </listitem>
713           <listitem>
714             <para>
715               if you output a string s that might contain control
716               characters, or if <parameter>s</parameter> may be
717               <literal>NULL</literal>, use
718               <function>debugstr_a</function> (for ASCII strings, or
719               <function>debugstr_w</function> for Unicode strings) to
720               convert <parameter>s</parameter> to a C string, like  this:
721               <programlisting>
722 HANDLE32 WINAPI YourFunc(LPCSTR s)
723 {
724     FIXME(xxx, "(%s): stub\n", debugstr_a(s)); 
725 }
726               </programlisting>
727             </para>
728           </listitem>
729           <listitem>
730             <para>
731               if you want to output a resource identifier, use debugres to
732               convert it to a string first, like this:
733               <programlisting>
734 HANDLE32 WINAPI YourFunc(LPCSTR res)
735 {
736     FIXME(xxx, "(res=%s): stub\n", debugres(s));
737 }
738               </programlisting>
739               if the resource identifier is a <type>SEGPTR</type>, use
740               <function>PTR_SEG_TO_LIN</function> to get a
741               liner pointer first:
742               <programlisting>
743 HRSRC16 WINAPI FindResource16( HMODULE16 hModule, SEGPTR name, SEGPTR type )
744 {
745 [...]
746     TRACE(resource, "module=%04x name=%s type=%s\n", 
747                  hModule, debugres(PTR_SEG_TO_LIN(name)), 
748                  debugres(PTR_SEG_TO_LIN(type)) );
749 [...]
750 }
751               </programlisting>
752             </para>
753           </listitem>
754           <listitem>
755             <para>
756               for messages intended for the user (specifically those that
757               report errors in <filename>wine.conf</filename>), use the
758               <literal>MSG</literal> macro. Use it like a
759               <function>printf</function>:
760               <programlisting>
761 MSG( "Definition of drive %d is incorrect!\n", drive ); 
762               </programlisting>
763               However, note that there are <emphasis>very</emphasis> few
764               valid uses of this macro. Most messages are debugging
765               messages, so chances are you will not need to use this
766               macro. Grep the source to get an idea where it is
767               appropriate to use it.
768             </para>
769           </listitem>
770           <listitem>
771             <para>
772               For structure dumps, use the <function>DUMP</function>
773               macro. Use it like a <function>printf</function>, just like
774               the <literal>MSG</literal> macro. Similarly, there are only
775               a few valid uses of this macro. Grep the source to see when
776               to use it.
777             </para>
778           </listitem>
779         </itemizedlist>
780       </sect1>
781
782   </chapter>
783
784 <!-- Keep this comment at the end of the file
785 Local variables:
786 mode: sgml
787 sgml-parent-document:("wine-doc.sgml" "set" "book" "part" "chapter" "")
788 End:
789 -->