LustreDebugging.xml

   1 <?xml version='1.0' encoding='UTF-8'?>
   2 <chapter xmlns="http://docbook.org/ns/docbook"
   3  xmlns:xl="http://www.w3.org/1999/xlink" version="5.0" xml:lang="en-US"
   4  xml:id="lustredebugging">
   5   <title xml:id="lustredebugging.title">Debugging a Lustre File System</title>
   6   <para>This chapter describes tips and information to debug a Lustre file system, and includes the
   7     following sections:</para>
   8   <itemizedlist>
   9     <listitem>
  10       <para><xref linkend="dbdoclet.50438274_15874"/></para>
  11     </listitem>
  12     <listitem>
  13       <para><xref linkend="dbdoclet.50438274_23607"/></para>
  14     </listitem>
  15     <listitem>
  16       <para><xref linkend="dbdoclet.50438274_80443"/></para>
  17     </listitem>
  18   </itemizedlist>
  19   <section xml:id="dbdoclet.50438274_15874">
  20     <title><indexterm><primary>debugging</primary></indexterm>
  21 Diagnostic and Debugging Tools</title>
  22     <para>A variety of diagnostic and analysis tools are available to debug
  23       issues with the Lustre software. Some of these are provided in Linux
  24       distributions, while others have been developed and are made available
  25       by the Lustre project.</para>
  26     <section remap="h3" xml:id="section_dms_q21_kk">
  27       <title><indexterm>
  28           <primary>debugging</primary>
  29           <secondary>tools</secondary>
  30         </indexterm> Lustre Debugging Tools</title>
  31       <para>The following in-kernel debug mechanisms are incorporated into
  32         the Lustre software:</para>
  33       <itemizedlist>
  34         <listitem>
  35           <para xml:id="para_fkj_rld_hk"><emphasis role="bold">Debug logs</emphasis>
  36             - A circular debug buffer to which Lustre internal debug messages
  37             are written (in contrast to error messages, which are printed to the
  38             syslog or console). Entries in the Lustre debug log are controlled
  39             by a mask set by <literal>lctl set_param debug=<replaceable>mask</replaceable></literal>.
  40             The log size defaults to 5 MB per CPU but can be increased as a
  41             busy system will quickly overwrite 5 MB. When the buffer fills,
  42             the oldest log records are discarded.</para>
  43         </listitem>
  44         <listitem>
  45           <para><emphasis role="bold">
  46               <literal>lctl get_param debug</literal>
  47             </emphasis> - This shows the current debug mask used to delimit
  48             the debugging information written out to the kernel debug logs.
  49           </para>
  50         </listitem>
  51         <listitem>
  52           <para><emphasis role="bold">
  53               <literal>lctl debug_kernel <replaceable>file</replaceable></literal>
  54             </emphasis> - Dump the Lustre kernel debug log to the specified
  55             file as ASCII text for further debugging and analysis.
  56           </para>
  57         </listitem>
  58         <listitem>
  59           <para><emphasis role="bold">
  60               <literal>lctl set_param debug_mb=<replaceable>size</replaceable></literal>
  61             </emphasis> - This sets the maximum size of the in-kernel Lustre
  62             debug buffer, in units of MiB.
  63           </para>
  64         </listitem>
  65         <listitem>
  66           <para><emphasis role="bold">Debug daemon</emphasis>
  67             - The debug daemon controls the continuous logging of debug
  68             messages to a log file in userspace.</para>
  69         </listitem>
  70       </itemizedlist>
  71       <para>The following tools are also provided with the Lustre software:</para>
  72       <itemizedlist>
  73         <listitem>
  74           <para><emphasis role="bold">
  75               <literal>lctl</literal>
  76             </emphasis> - This tool is used with the debug_kernel option to
  77             manually dump the Lustre debugging log or post-process debugging
  78             logs that are dumped automatically. For more information about the
  79             lctl tool, see <xref linkend="dbdoclet.50438274_62472"/> and <xref
  80               linkend="dbdoclet.50438219_38274"/>.</para>
  81         </listitem>
  82         <listitem>
  83           <para>Lustre subsystem asserts - A panic-style assertion (LBUG) in the kernel causes the
  84             Lustre file system to dump the debug log to the file
  85                 <literal>/tmp/lustre-log.<replaceable>timestamp</replaceable></literal> where it can
  86             be retrieved after a reboot. For more information, see <xref
  87               linkend="dbdoclet.50438198_40669"/>.</para>
  88         </listitem>
  89         <listitem>
  90           <para>
  91             <literal>
  92               <replaceable>lfs</replaceable>
  93             </literal> - This utility provides access to the extended attributes (EAs) of a Lustre
  94             file (along with other information). For more information about lfs, see <xref
  95               linkend="dbdoclet.50438206_94597"/>.</para>
  96         </listitem>
  97       </itemizedlist>
  98     </section>
  99     <section remap="h3">
 100       <title><indexterm><primary>debugging</primary><secondary>external tools</secondary></indexterm>External Debugging Tools</title>
 101       <para>The tools described in this section are provided in the Linux kernel or are available at an external website. For information about using some of these tools for Lustre debugging, see <xref linkend="dbdoclet.50438274_23607"/> and <xref linkend="dbdoclet.50438274_80443"/>.</para>
 102       <section remap="h4">
 103         <title><indexterm><primary>debugging</primary><secondary>admin tools</secondary></indexterm>Tools for Administrators and Developers</title>
 104         <para>Some general debugging tools provided as a part of the standard Linux distribution
 105           are:</para>
 106         <itemizedlist>
 107           <listitem>
 108             <para><emphasis role="bold">
 109                 <literal>strace</literal>
 110               </emphasis> . This tool allows a system call to be traced.</para>
 111           </listitem>
 112           <listitem>
 113             <para><emphasis role="bold">
 114                 <literal>/var/log/messages</literal>
 115               </emphasis> . <literal>syslogd</literal> prints fatal or serious messages at this log.</para>
 116           </listitem>
 117           <listitem>
 118             <para><emphasis role="bold">Crash dumps</emphasis> . On crash-dump enabled kernels,
 119               sysrq c produces a crash dump. The Lustre software enhances this crash dump with a log
 120               dump (the last 64 KB of the log) to the console.</para>
 121           </listitem>
 122           <listitem>
 123             <para><emphasis role="bold">
 124                 <literal>debugfs</literal>
 125               </emphasis>. Interactive file system debugger.</para>
 126           </listitem>
 127         </itemizedlist>
 128         <para>The following logging and data collection tools can be used to collect information for debugging Lustre kernel issues:</para>
 129         <itemizedlist>
 130           <listitem>
 131             <para><emphasis role="bold">
 132                 <literal>kdump</literal>
 133               </emphasis> . A Linux kernel crash utility useful for debugging a system running Red Hat Enterprise Linux. For more information about <literal>kdump</literal>, see the Red Hat knowledge base article <link xl:href="http://kbase.redhat.com/faq/docs/DOC-6039">How do I configure kexec/kdump on Red Hat Enterprise Linux 5?</link>. To download <literal>kdump</literal>, go to the <link xl:href="http://fedoraproject.org/wiki/SystemConfig/kdump#Download">Fedora Project Download</link> site.</para>
 134           </listitem>
 135           <listitem>
 136             <para><emphasis role="bold">
 137                 <literal>netconsole</literal>
 138               </emphasis>. Enables kernel-level network logging over UDP. A system requires (SysRq) allows users to collect relevant data through <literal>netconsole</literal>.</para>
 139           </listitem>
 140           <listitem>
 141             <para><emphasis role="bold">
 142                 <literal>netdump</literal>
 143               </emphasis>. A crash dump utility from Red Hat that allows memory images to be dumped
 144               over a network to a central server for analysis. The <literal>netdump</literal>
 145               utility was replaced by <literal>kdump</literal> in Red Hat Enterprise Linux 5. For
 146               more information about <literal>netdump</literal>, see <link
 147                 xl:href="http://www.redhat.com/support/wpapers/redhat/netdump/">Red Hat, Inc.&apos;s
 148                 Network Console and Crash Dump Facility</link>.</para>
 149           </listitem>
 150           <listitem>
 151             <para><emphasis><literal>wireshark</literal> </emphasis> . A network
 152             packet inspection tool that allows debugging of information that was
 153             sent between the various Lustre nodes. This tool is built on top of
 154             <literal>tcpdump</literal> and can read packet dumps generated by
 155             it.  There are plug-ins available to dissassemble the LNet and
 156             Lustre protocols.  They are located within the <link
 157             xl:href="http://git.whamcloud.com/">Lustre git repository</link>
 158             under <literal>lustre/contrib/wireshark/</literal>.  Installation
 159             instruction are included in that directory. See also <link
 160             xl:href="http://www.wireshark.org/">Wireshark Website</link> for
 161             more details.</para>
 162           </listitem>
 163         </itemizedlist>
 164       </section>
 165       <section remap="h4">
 166         <title><indexterm><primary>debugging</primary><secondary>developer tools</secondary></indexterm>Tools for Developers</title>
 167         <para>The tools described in this section may be useful for debugging a Lustre file system
 168           in a development environment.</para>
 169         <para>Of general interest is:</para>
 170         <itemizedlist>
 171           <listitem>
 172             <para><literal>
 173                 <replaceable>leak_finder.pl</replaceable>
 174               </literal> . This program provided with the Lustre software is useful for finding
 175               memory leaks in the code.</para>
 176           </listitem>
 177         </itemizedlist>
 178         <para>A virtual machine is often used to create an isolated development and test environment. Some commonly-used virtual machines are:</para>
 179         <itemizedlist>
 180           <listitem>
 181             <para><emphasis role="bold">VirtualBox Open Source Edition</emphasis> . Provides enterprise-class virtualization capability for all major platforms and is available free at <link xl:href="http://www.sun.com/software/products/virtualbox/get.jsp?intcmp=2945">Get Sun VirtualBox</link>.</para>
 182           </listitem>
 183           <listitem>
 184             <para><emphasis role="bold">VMware Server</emphasis> . Virtualization platform available as free introductory software at <link xl:href="http://downloads.vmware.com/d/info/datacenter_downloads/vmware_server/2_0">Download VMware Server</link>.</para>
 185           </listitem>
 186           <listitem>
 187             <para><emphasis role="bold">Xen</emphasis> . A para-virtualized environment with virtualization capabilities similar to VMware Server and Virtual Box. However, Xen allows the use of modified kernels to provide near-native performance and the ability to emulate shared storage. For more information, go to <link xl:href="http://xen.org/">xen.org</link>.</para>
 188           </listitem>
 189         </itemizedlist>
 190         <para>A variety of debuggers and analysis tools are available including:</para>
 191         <itemizedlist>
 192           <listitem>
 193             <para><emphasis role="bold">
 194                 <literal>kgdb</literal>
 195               </emphasis> . The Linux Kernel Source Level Debugger kgdb is used in conjunction with the GNU Debugger <literal>gdb</literal> for debugging the Linux kernel. For more information about using <literal>kgdb</literal> with <literal>gdb</literal>, see <link xl:href="http://www.linuxtopia.org/online_books/redhat_linux_debugging_with_gdb/running.html">Chapter 6. Running Programs Under gdb</link> in the <emphasis>Red Hat Linux 4 Debugging with GDB</emphasis> guide.</para>
 196           </listitem>
 197           <listitem>
 198             <para><emphasis role="bold">
 199                 <literal>crash</literal>
 200               </emphasis> . Used to analyze saved crash dump data when a system had panicked or locked up or appears unresponsive. For more information about using crash to analyze a crash dump, see:</para>
 201             <itemizedlist>
 202               <listitem>
 203                 <para> Red Hat Magazine article: <link xl:href="http://magazine.redhat.com/2007/08/15/a-quick-overview-of-linux-kernel-crash-dump-analysis/">A quick overview of Linux kernel crash dump analysis</link></para>
 204               </listitem>
 205               <listitem>
 206                 <para><link xl:href="http://people.redhat.com/anderson/crash_whitepaper/#EXAMPLES">Crash Usage: A Case Study</link>  from the white paper <emphasis>Red Hat Crash Utility</emphasis> by David Anderson</para>
 207               </listitem>
 208               <listitem>
 209                 <para> Kernel Trap forum entry: <link xl:href="http://kerneltrap.org/node/5758">Linux: Kernel Crash Dumps</link></para>
 210               </listitem>
 211               <listitem>
 212                 <para> White paper: <link xl:href="http://www.google.com/url?sa=t&amp;source=web&amp;ct=res&amp;cd=8&amp;ved=0CCUQFjAH&amp;url=http%3A%2F%2Fwww.kernel.sg%2Fpapers%2Fcrash-dump-analysis.pdf&amp;rct=j&amp;q=redhat+crash+dump&amp;ei=6aQBS-ifK4T8tAPcjdiHCw&amp;usg=AFQjCNEk03E3GDtAsawG3gfpwc1gGNELAg">A Quick Overview of Linux Kernel Crash Dump Analysis</link></para>
 213               </listitem>
 214             </itemizedlist>
 215           </listitem>
 216         </itemizedlist>
 217       </section>
 218     </section>
 219   </section>
 220   <section xml:id="dbdoclet.50438274_23607">
 221     <title><indexterm><primary>debugging</primary><secondary>procedure</secondary></indexterm>Lustre Debugging Procedures</title>
 222     <para>The procedures below may be useful to administrators or developers debugging a Lustre files system.</para>
 223     <section remap="h3">
 224       <title><indexterm><primary>debugging</primary><secondary>message format</secondary></indexterm>Understanding the Lustre Debug Messaging Format</title>
 225       <para>Lustre debug messages are categorized by originating subsystem, message type, and location in the source code. For a list of subsystems and message types, see <xref linkend="dbdoclet.50438274_57603"/>.</para>
 226       <note>
 227         <para>For a current list of subsystems and debug message types, see
 228             <literal>libcfs/include/libcfs/libcfs_debug.h</literal> in the Lustre software
 229           tree</para>
 230       </note>
 231       <para>The elements of a Lustre debug message are described in <xref linkend="dbdoclet.50438274_57177"/> Format of Lustre Debug Messages.</para>
 232       <section xml:id="dbdoclet.50438274_57603">
 233         <title>Lustre Debug Messages</title>
 234         <para>Each Lustre debug message has the tag of the subsystem it originated in, the message
 235           type, and the location in the source code. The subsystems and debug types used are as
 236           follows:</para>
 237         <itemizedlist>
 238           <listitem>
 239             <para>  Standard Subsystems:</para>
 240             <para> mdc, mds, osc, ost, obdclass, obdfilter, llite, ptlrpc, portals, lnd, ldlm, lov</para>
 241           </listitem>
 242         </itemizedlist>
 243         <itemizedlist>
 244           <listitem>
 245             <para>  Debug Types:</para>
 246           </listitem>
 247           <listitem>
 248             <para><informaltable frame="all">
 249                 <tgroup cols="2">
 250                   <colspec colname="c1" colwidth="50*"/>
 251                   <colspec colname="c2" colwidth="50*"/>
 252                   <thead>
 253                     <row>
 254                       <entry>
 255                         <para><emphasis role="bold">Types</emphasis></para>
 256                       </entry>
 257                       <entry>
 258                         <para><emphasis role="bold">Description</emphasis></para>
 259                       </entry>
 260                     </row>
 261                   </thead>
 262                   <tbody>
 263                     <row>
 264                       <entry>
 265                         <para> <emphasis role="bold">trace</emphasis></para>
 266                       </entry>
 267                       <entry>
 268                         <para> Function entry/exit markers</para>
 269                       </entry>
 270                     </row>
 271                     <row>
 272                       <entry>
 273                         <para> <emphasis role="bold">dlmtrace</emphasis></para>
 274                       </entry>
 275                       <entry>
 276                         <para> Distributed locking-related information</para>
 277                       </entry>
 278                     </row>
 279                     <row>
 280                       <entry>
 281                         <para> <emphasis role="bold">inode</emphasis></para>
 282                       </entry>
 283                       <entry>
 284                         <para> &#160;</para>
 285                       </entry>
 286                     </row>
 287                     <row>
 288                       <entry>
 289                         <para> <emphasis role="bold">super</emphasis></para>
 290                       </entry>
 291                       <entry>
 292                         <para> &#160;</para>
 293                       </entry>
 294                     </row>
 295                     <row>
 296                       <entry>
 297                         <para> <emphasis role="bold">malloc</emphasis></para>
 298                       </entry>
 299                       <entry>
 300                         <para> Memory allocation or free information</para>
 301                       </entry>
 302                     </row>
 303                     <row>
 304                       <entry>
 305                         <para> <emphasis role="bold">cache</emphasis></para>
 306                       </entry>
 307                       <entry>
 308                         <para> Cache-related information</para>
 309                       </entry>
 310                     </row>
 311                     <row>
 312                       <entry>
 313                         <para> <emphasis role="bold">info</emphasis></para>
 314                       </entry>
 315                       <entry>
 316                         <para> Non-critical general information</para>
 317                       </entry>
 318                     </row>
 319                     <row>
 320                       <entry>
 321                         <para> <emphasis role="bold">dentry</emphasis></para>
 322                       </entry>
 323                       <entry>
 324                         <para> kernel namespace cache handling</para>
 325                       </entry>
 326                     </row>
 327                     <row>
 328                       <entry>
 329                         <para> <emphasis role="bold">mmap</emphasis></para>
 330                       </entry>
 331                       <entry>
 332                         <para> Memory-mapped IO interface</para>
 333                       </entry>
 334                     </row>
 335                     <row>
 336                       <entry>
 337                         <para> <emphasis role="bold">page</emphasis></para>
 338                       </entry>
 339                       <entry>
 340                         <para> Page cache and bulk data transfers</para>
 341                       </entry>
 342                     </row>
 343                     <row>
 344                       <entry>
 345                         <para> <emphasis role="bold">info</emphasis></para>
 346                       </entry>
 347                       <entry>
 348                         <para> Miscellaneous informational messages</para>
 349                       </entry>
 350                     </row>
 351                     <row>
 352                       <entry>
 353                         <para> <emphasis role="bold">net</emphasis></para>
 354                       </entry>
 355                       <entry>
 356                         <para> LNet network related debugging</para>
 357                       </entry>
 358                     </row>
 359                     <row>
 360                       <entry>
 361                         <para> <emphasis role="bold">console</emphasis></para>
 362                       </entry>
 363                       <entry>
 364                         <para>Significant system events, printed to console</para>
 365                       </entry>
 366                     </row>
 367                     <row>
 368                       <entry>
 369                         <para> <emphasis role="bold">warning</emphasis></para>
 370                       </entry>
 371                       <entry>
 372                         <para>Significant but non-fatal exceptions, printed
 373                           to console</para>
 374                       </entry>
 375                     </row>
 376                     <row>
 377                       <entry>
 378                         <para> <emphasis role="bold">error</emphasis></para>
 379                       </entry>
 380                       <entry>
 381                         <para>Critical error messages, printed to console</para>
 382                       </entry>
 383                     </row>
 384                     <row>
 385                       <entry>
 386                         <para> <emphasis role="bold">neterror</emphasis></para>
 387                       </entry>
 388                       <entry>
 389                         <para>Significant LNet error messages</para>
 390                       </entry>
 391                     </row>
 392                     <row>
 393                       <entry>
 394                         <para> <emphasis role="bold">emerg</emphasis></para>
 395                       </entry>
 396                       <entry>
 397                         <para>Fatal system errors, printed to console</para>
 398                       </entry>
 399                     </row>
 400                     <row>
 401                       <entry>
 402                         <para><emphasis role="bold">config</emphasis></para>
 403                       </entry>
 404                       <entry>
 405                         <para>Configuration and setup, enabled by default</para>
 406                       </entry>
 407                     </row>
 408                     <row>
 409                       <entry>
 410                         <para><emphasis role="bold">ha</emphasis></para>
 411                       </entry>
 412                       <entry>
 413                         <para>Failover and recovery-related information,
 414                         enabled by default</para>
 415                       </entry>
 416                     </row>
 417                     <row>
 418                       <entry>
 419                         <para><emphasis role="bold">hsm</emphasis></para>
 420                       </entry>
 421                       <entry>
 422                         <para>Hierarchical space management/tiering</para>
 423                       </entry>
 424                     </row>
 425                     <row>
 426                       <entry>
 427                         <para><emphasis role="bold">ioctl</emphasis></para>
 428                       </entry>
 429                       <entry>
 430                         <para>IOCTL-related information, enabled by default</para>
 431                       </entry>
 432                     </row>
 433                     <row>
 434                       <entry>
 435                         <para><emphasis role="bold">layout</emphasis></para>
 436                       </entry>
 437                       <entry>
 438                         <para>File layout handling (PFL, FLR, DoM)</para>
 439                       </entry>
 440                     </row>
 441                     <row>
 442                       <entry>
 443                         <para><emphasis role="bold">lfsck</emphasis></para>
 444                       </entry>
 445                       <entry>
 446                         <para>Filesystem consistency checking, enabled by
 447                         default</para>
 448                       </entry>
 449                     </row>
 450                     <row>
 451                       <entry>
 452                         <para><emphasis role="bold">other</emphasis></para>
 453                       </entry>
 454                       <entry>
 455                         <para>Miscellaneious other debug messages</para>
 456                       </entry>
 457                     </row>
 458                     <row>
 459                       <entry>
 460                         <para><emphasis role="bold">quota</emphasis></para>
 461                       </entry>
 462                       <entry>
 463                         <para>Space accounting and management</para>
 464                       </entry>
 465                     </row>
 466                     <row>
 467                       <entry>
 468                         <para><emphasis role="bold">reada</emphasis></para>
 469                       </entry>
 470                       <entry>
 471                         <para>Client readahead management</para>
 472                       </entry>
 473                     </row>
 474                     <row>
 475                       <entry>
 476                         <para> <emphasis role="bold">rpctrace</emphasis></para>
 477                       </entry>
 478                       <entry>
 479                         <para>Remote request/reply tracing and debugging</para>
 480                       </entry>
 481                     </row>
 482                     <row>
 483                       <entry>
 484                         <para><emphasis role="bold">sec</emphasis></para>
 485                       </entry>
 486                       <entry>
 487                         <para>Security, Kerberos, Shared Secret Key handling</para>
 488                       </entry>
 489                     </row>
 490                     <row>
 491                       <entry>
 492                         <para><emphasis role="bold">snapshot</emphasis></para>
 493                       </entry>
 494                       <entry>
 495                         <para>Filesystem snapshot management</para>
 496                       </entry>
 497                     </row>
 498                     <row>
 499                       <entry>
 500                         <para><emphasis role="bold">vfstrace</emphasis></para>
 501                       </entry>
 502                       <entry>
 503                         <para>Kernel VFS interface operations</para>
 504                       </entry>
 505                     </row>
 506                   </tbody>
 507                 </tgroup>
 508               </informaltable>
 509 </para>
 510           </listitem>
 511         </itemizedlist>
 512       </section>
 513       <section xml:id="dbdoclet.50438274_57177">
 514         <title>Format of Lustre Debug Messages</title>
 515         <para>The Lustre software uses the <literal>CDEBUG()</literal> and
 516             <literal>CERROR()</literal> macros to print the debug or error messages. To print the
 517           message, the <literal>CDEBUG()</literal> macro uses the function
 518             <literal>libcfs_debug_msg()</literal> (<literal>libcfs/libcfs/tracefile.c</literal>).
 519           The message format is described below, along with an example.</para>
 520         <informaltable frame="all">
 521           <tgroup cols="2">
 522             <colspec colname="c1" colwidth="50*"/>
 523             <colspec colname="c2" colwidth="50*"/>
 524             <thead>
 525               <row>
 526                 <entry>
 527                   <para><emphasis role="bold">Description</emphasis></para>
 528                 </entry>
 529                 <entry>
 530                   <para><emphasis role="bold">Parameter</emphasis></para>
 531                 </entry>
 532               </row>
 533             </thead>
 534             <tbody>
 535               <row>
 536                 <entry>
 537                   <para> <emphasis role="bold">subsystem</emphasis></para>
 538                 </entry>
 539                 <entry>
 540                   <para> 800000</para>
 541                 </entry>
 542               </row>
 543               <row>
 544                 <entry>
 545                   <para> <emphasis role="bold">debug mask</emphasis></para>
 546                 </entry>
 547                 <entry>
 548                   <para> 000010</para>
 549                 </entry>
 550               </row>
 551               <row>
 552                 <entry>
 553                   <para> <emphasis role="bold">smp_processor_id</emphasis></para>
 554                 </entry>
 555                 <entry>
 556                   <para> 0</para>
 557                 </entry>
 558               </row>
 559               <row>
 560                 <entry>
 561                   <para> <emphasis role="bold">seconds.microseconds</emphasis></para>
 562                 </entry>
 563                 <entry>
 564                   <para> 1081880847.677302</para>
 565                 </entry>
 566               </row>
 567               <row>
 568                 <entry>
 569                   <para> <emphasis role="bold">stack size</emphasis></para>
 570                 </entry>
 571                 <entry>
 572                   <para> 1204</para>
 573                 </entry>
 574               </row>
 575               <row>
 576                 <entry>
 577                   <para> <emphasis role="bold">pid</emphasis></para>
 578                 </entry>
 579                 <entry>
 580                   <para> 2973</para>
 581                 </entry>
 582               </row>
 583               <row>
 584                 <entry>
 585                   <para> <emphasis role="bold">host pid (UML only) or zero</emphasis></para>
 586                 </entry>
 587                 <entry>
 588                   <para> 31070</para>
 589                 </entry>
 590               </row>
 591               <row>
 592                 <entry>
 593                   <para> <emphasis role="bold">(file:line #:function_name())</emphasis></para>
 594                 </entry>
 595                 <entry>
 596                   <para> (obd_mount.c:2089:lustre_fill_super())</para>
 597                 </entry>
 598               </row>
 599               <row>
 600                 <entry>
 601                   <para> <emphasis role="bold">debug message</emphasis></para>
 602                 </entry>
 603                 <entry>
 604                   <para> kmalloced &apos;*obj&apos;: 24 at a375571c (tot 17447717)</para>
 605                 </entry>
 606               </row>
 607             </tbody>
 608           </tgroup>
 609         </informaltable>
 610       </section>
 611       <section remap="h4">
 612         <title>Lustre Debug Messages Buffer</title>
 613         <para>Lustre debug messages are maintained in a buffer, with the maximum buffer size specified (in MBs) by the <literal>debug_mb</literal> parameter (<literal>lctl get_param debug_mb</literal>). The buffer is circular, so debug messages are kept until the allocated buffer limit is reached, and then the first messages are overwritten.</para>
 614       </section>
 615     </section>
 616     <section xml:id="dbdoclet.50438274_62472">
 617       <title><indexterm><primary>debugging</primary><secondary>using lctl</secondary></indexterm>Using the lctl Tool to View Debug Messages</title>
 618       <para>The <literal>lctl</literal> tool allows debug messages to be filtered based on subsystems and message types to extract information useful for troubleshooting from a kernel debug log. For a command reference, see <xref linkend="dbdoclet.50438219_38274"/>.</para>
 619       <para>You can use <literal>lctl</literal> to:</para>
 620       <itemizedlist>
 621         <listitem>
 622           <para>Obtain a list of all the types and subsystems:</para>
 623           <screen>lctl &gt; debug_list <replaceable>subsystems|types</replaceable></screen>
 624         </listitem>
 625       </itemizedlist>
 626       <itemizedlist>
 627         <listitem>
 628           <para>Filter the debug log:</para>
 629           <screen>lctl &gt; filter <replaceable>subsystem_name|debug_type</replaceable></screen>
 630         </listitem>
 631       </itemizedlist>
 632       <note>
 633         <para>When <literal>lctl</literal> filters, it removes unwanted lines from the displayed output. This does not affect the contents of the debug log in the kernel&apos;s memory. As a result, you can print the log many times with different filtering levels without worrying about losing data.</para>
 634       </note>
 635       <itemizedlist>
 636         <listitem>
 637           <para>Show debug messages belonging to certain subsystem or type:</para>
 638           <screen>lctl &gt; show <replaceable>subsystem_name|debug_type</replaceable></screen>
 639           <para><literal>debug_kernel</literal> pulls the data from the kernel logs, filters it appropriately, and displays or saves it as per the specified options</para>
 640           <screen>lctl &gt; debug_kernel [<replaceable>output filename</replaceable>]</screen>
 641           <para>If the debugging is being done on User Mode Linux (UML), it might be useful to save the logs on the host machine so that they can be used at a later time.</para>
 642         </listitem>
 643       </itemizedlist>
 644       <itemizedlist>
 645         <listitem>
 646           <para>Filter a log on disk, if you already have a debug log saved to disk (likely from a crash):</para>
 647           <screen>lctl &gt; debug_file <replaceable>input_file</replaceable> [<replaceable>output_file</replaceable>] </screen>
 648           <para>During the debug session, you can add markers or breaks to the log for any reason:</para>
 649           <screen>lctl &gt; mark [marker text] </screen>
 650           <para>The marker text defaults to the current date and time in the debug log (similar to the example shown below):</para>
 651           <screen>DEBUG MARKER: Tue Mar 5 16:06:44 EST 2002
 652 </screen>
 653         </listitem>
 654       </itemizedlist>
 655       <itemizedlist>
 656         <listitem>
 657           <para>Completely flush the kernel debug buffer:</para>
 658           <screen>lctl &gt; clear
 659 </screen>
 660         </listitem>
 661       </itemizedlist>
 662       <note>
 663         <para>Debug messages displayed with <literal>lctl</literal> are also subject to the kernel debug masks; the filters are additive.</para>
 664       </note>
 665       <section remap="h4">
 666         <title><indexterm><primary>debugging</primary><secondary>lctl example</secondary></indexterm>Sample <literal>lctl</literal> Run</title>
 667         <para>Below is a sample run using the <literal>lctl</literal> command.</para>
 668         <screen>bash-2.04# ./lctl
 669 lctl &gt; debug_kernel /tmp/lustre_logs/log_all
 670 Debug log: 324 lines, 324 kept, 0 dropped.
 671 lctl &gt; filter trace
 672 Disabling output of type &quot;trace&quot;
 673 lctl &gt; debug_kernel /tmp/lustre_logs/log_notrace
 674 Debug log: 324 lines, 282 kept, 42 dropped.
 675 lctl &gt; show trace
 676 Enabling output of type &quot;trace&quot;
 677 lctl &gt; filter portals
 678 Disabling output from subsystem &quot;portals&quot;
 679 lctl &gt; debug_kernel /tmp/lustre_logs/log_noportals
 680 Debug log: 324 lines, 258 kept, 66 dropped.
 681 </screen>
 682       </section>
 683     </section>
 684     <section remap="h3">
 685       <title>Dumping the Buffer to a File (<literal>debug_daemon</literal>)</title>
 686       <para>The <literal>lctl debug_daemon</literal> command is used to continuously dump the <literal>debug_kernel</literal> buffer to a user-specified file. This functionality uses a kernel thread to continuously dump the messages from the kernel debug log, so that much larger debug logs can be saved over a longer time than would fit in the kernel ringbuffer.</para>
 687       <para>The <literal>debug_daemon</literal> is highly dependent on file system write speed. File system write operations may not be fast enough to flush out all of the <literal>debug_buffer</literal> if the Lustre file system is under heavy system load and continues to log debug messages to the <literal>debug_buffer</literal>. The <literal>debug_daemon</literal> will write the message <literal>DEBUG MARKER: Trace buffer full</literal> into the <literal>debug_buffer</literal> to indicate the <literal>debug_buffer</literal> contents are overlapping before the <literal>debug_daemon</literal> flushes data to a file.</para>
 688       <para>Users can use the <literal>lctl debug_daemon</literal> command to start or stop the Lustre daemon from dumping the <literal>debug_buffer</literal> to a file.</para>
 689       <section remap="h4">
 690         <title><literal>lctl debug_daemon</literal> Commands</title>
 691         <para>To initiate the <literal>debug_daemon</literal> to start dumping the <literal>debug_buffer</literal> into a file, run as the root user:</para>
 692         <screen>lctl debug_daemon start <replaceable>filename</replaceable> [<replaceable>megabytes</replaceable>]</screen>
 693         <para>The debug log will be written to the specified filename from the kernel.  The file will be limited to the optionally specified number of megabytes.</para>
 694         <para>The daemon wraps around and dumps data to the beginning of the file when the output file size is over the limit of the user-specified file size. To decode the dumped file to ASCII and sort the log entries by time, run:</para>
 695         <screen>lctl debug_file <replaceable>filename</replaceable> &gt; <replaceable>newfile</replaceable></screen>
 696         <para>The output is internally sorted by the <literal>lctl</literal> command.</para>
 697         <para>To stop the <literal>debug_daemon</literal> operation and flush the file output, run:</para>
 698         <screen>lctl debug_daemon stop</screen>
 699         <para>Otherwise, <literal>debug_daemon</literal> is shut down as part of the Lustre file system shutdown process. Users can restart <literal>debug_daemon</literal> by using start command after each stop command issued.</para>
 700         <para>This is an example using <literal>debug_daemon</literal> with the interactive mode of <literal>lctl</literal> to dump debug logs to a 40 MB file.</para>
 701         <screen>lctl</screen>
 702         <screen>lctl &gt; debug_daemon start /var/log/lustre.40.bin 40 </screen>
 703         <screen><replaceable>run filesystem operations to debug</replaceable></screen>
 704         <screen>lctl &gt; debug_daemon stop </screen>
 705         <screen>lctl &gt; debug_file /var/log/lustre.bin /var/log/lustre.log</screen>
 706         <para>To start another daemon with an unlimited file size, run:</para>
 707         <screen>lctl &gt; debug_daemon start /var/log/lustre.bin </screen>
 708         <para>The text message <literal>*** End of debug_daemon trace log ***</literal> appears at the end of each output file.</para>
 709       </section>
 710     </section>
 711     <section remap="h3">
 712       <title><indexterm><primary>debugging</primary><secondary>kernel debug log</secondary></indexterm>Controlling Information Written to the Kernel Debug Log</title>
 713       <para>The <literal>lctl set_param subsystem_debug=<replaceable>subsystem_mask</replaceable></literal> and <literal>lctl set_param debug=<replaceable>debug_mask</replaceable></literal> are used to determine which information is written to the debug log. The subsystem_debug mask determines the information written to the log based on the functional area of the code (such as lnet, osc, or ldlm). The debug mask controls information based on the message type (such as info, error, trace, or malloc). For a complete list of possible debug masks use the <literal>lctl debug_list types</literal> command.</para>
 714       <para>To turn off Lustre debugging completely:</para>
 715       <screen>lctl set_param debug=0 </screen>
 716       <para>To turn on full Lustre debugging:</para>
 717       <screen>lctl set_param debug=-1 </screen>
 718       <para>To list all possible debug masks:</para>
 719       <screen>lctl debug_list types</screen>
 720       <para>To log only messages related to network communications:</para>
 721       <screen>lctl set_param debug=net </screen>
 722       <para>To turn on logging of messages related to network communications and existing debug flags:</para>
 723       <screen>lctl set_param debug=+net </screen>
 724       <para>To turn off network logging with changing existing flags:</para>
 725       <screen>lctl set_param debug=-net </screen>
 726       <para>The various options available to print to kernel debug logs are listed in <literal>libcfs/include/libcfs/libcfs.h</literal></para>
 727     </section>
 728     <section remap="h3">
 729       <title><indexterm><primary>debugging</primary><secondary>using strace</secondary></indexterm>Troubleshooting with <literal>strace</literal></title>
 730       <para>The <literal>strace</literal> utility provided with the Linux distribution enables system calls to be traced by intercepting all the system calls made by a process and recording the system call name, arguments, and return values.</para>
 731       <para>To invoke <literal>strace</literal> on a program, enter:</para>
 732       <screen>$ strace <replaceable>program</replaceable> <replaceable>[arguments]</replaceable> </screen>
 733       <para>Sometimes, a system call may fork child processes. In this situation, use the <literal>-f</literal> option of <literal>strace</literal> to trace the child processes:</para>
 734       <screen>$ strace -f <replaceable>program</replaceable> <replaceable>[arguments]</replaceable> </screen>
 735       <para>To redirect the <literal>strace</literal> output to a file, enter:</para>
 736       <screen>$ strace -o <replaceable>filename</replaceable> <replaceable>program</replaceable> <replaceable>[arguments]</replaceable> </screen>
 737       <para>Use the <literal>-ff</literal> option, along with <literal>-o</literal>, to save the trace output in <literal>filename.pid</literal>, where <literal>pid</literal> is the process ID of the process being traced. Use the <literal>-ttt</literal> option to timestamp all lines in the strace output, so they can be correlated to operations in the lustre kernel debug log.</para>
 738     </section>
 739     <section remap="h3">
 740       <title><indexterm><primary>debugging</primary><secondary>disk contents</secondary></indexterm>Looking at Disk Content</title>
 741       <para>In a Lustre file system, the inodes on the metadata server contain extended attributes
 742         (EAs) that store information about file striping. EAs contain a list of all object IDs and
 743         their locations (that is, the OST that stores them). The <literal>lfs</literal> tool can be
 744         used to obtain this information for a given file using the <literal>getstripe</literal>
 745         subcommand. Use a corresponding <literal>lfs setstripe</literal> command to specify striping
 746         attributes for a new file or directory.</para>
 747       <para>The <literal>lfs getstripe</literal> command takes a Lustre filename as input and lists
 748         all the objects that form a part of this file. To obtain this information for the file
 749           <literal>/mnt/testfs/frog</literal> in a Lustre file system, run:</para>
 750       <screen>$ lfs getstripe /mnt/testfs/frog
 751 lmm_stripe_count:   2
 752 lmm_stripe_size:    1048576
 753 lmm_pattern:        1
 754 lmm_layout_gen:     0
 755 lmm_stripe_offset:  2
 756         obdidx           objid          objid           group
 757              2          818855        0xc7ea7               0
 758              0          873123        0xd52a3               0
 759         </screen>
 760       <para>The <literal>debugfs</literal> tool is provided in the
 761           <literal>e2fsprogs</literal> package. It can be used for interactive
 762           debugging of an <literal>ldiskfs</literal> file system. The
 763           <literal>debugfs</literal> tool can either be used to check status or
 764           modify information in the file system. In a Lustre file system, all
 765           objects that belong to a file are stored in an underlying
 766           <literal>ldiskfs</literal> file system on the OSTs. The file system
 767           uses the object IDs as the file names. Once the object IDs are known,
 768           use the <literal>debugfs</literal> tool to obtain the attributes of
 769           all objects from different OSTs.</para>
 770       <para>A sample run for the <literal>/mnt/testfs/frog</literal> file used
 771           in the above example is shown here:</para>
 772       <screen>$ debugfs -c -R "stat O/0/d$((818855 % 32))/818855" /dev/vgmyth/lvmythost2
 773
 774 debugfs 1.41.90.wc3 (28-May-2011)
 775 /dev/vgmyth/lvmythost2: catastrophic mode - not reading inode or group bitmaps
 776 Inode: 227649   Type: regular    Mode:  0666   Flags: 0x80000
 777 Generation: 1375019198    Version: 0x0000002f:0000728f
 778 User:  1000   Group:  1000   Size: 2800
 779 File ACL: 0    Directory ACL: 0
 780 Links: 1   Blockcount: 8
 781 Fragment:  Address: 0    Number: 0    Size: 0
 782  ctime: 0x4e177fe5:00000000 -- Fri Jul  8 16:08:37 2011
 783  atime: 0x4d2e2397:00000000 -- Wed Jan 12 14:56:39 2011
 784  mtime: 0x4e177fe5:00000000 -- Fri Jul  8 16:08:37 2011
 785 crtime: 0x4c3b5820:a364117c -- Mon Jul 12 12:00:00 2010
 786 Size of extra inode fields: 28
 787 Extended attributes stored in inode body:
 788   fid = "08 80 24 00 00 00 00 00 28 8a e7 fc 00 00 00 00 a7 7e 0c 00 00 00 00 00
 789  00 00 00 00 00 00 00 00 " (32)
 790   fid: objid=818855 seq=0 parent=[0x248008:0xfce78a28:0x0] stripe=0
 791 EXTENTS:
 792 (0):63331288
 793       </screen>
 794     </section>
 795     <section remap="h3">
 796       <title>Finding the Lustre UUID of an OST</title>
 797       <para>To determine the Lustre UUID of an OST disk (for example, if you mix up the cables on your OST devices or the SCSI bus numbering suddenly changes and the SCSI devices get new names), it is possible to extract this from the last_rcvd file using debugfs:</para>
 798       <screen>debugfs -c -R "dump last_rcvd /tmp/last_rcvd" /dev/sdc
 799 strings /tmp/last_rcvd | head -1
 800 myth-OST0004_UUID
 801       </screen>
 802       <para>It is also possible (and easier) to extract this from the file system label using the
 803           <literal>dumpe2fs</literal> command:</para>
 804       <screen>dumpe2fs -h /dev/sdc | grep volume
 805 dumpe2fs 1.41.90.wc3 (28-May-2011)
 806 Filesystem volume name:   myth-OST0004
 807       </screen>
 808       <para>The debugfs and dumpe2fs commands are well documented in the <literal>debugfs(8)</literal> and <literal>dumpe2fs(8)</literal> manual pages.</para>
 809     </section>
 810     <section remap="h3">
 811       <title>Printing Debug Messages to the Console</title>
 812       <para>To dump debug messages to the console (<literal>/var/log/messages</literal>), set the corresponding debug mask in the <literal>printk</literal> flag:</para>
 813       <screen>lctl set_param printk=-1 </screen>
 814       <para>This slows down the system dramatically. It is also possible to selectively enable or disable this capability for particular flags using:<literal>lctl set_param printk=+vfstrace</literal> and <literal>lctl set_param printk=-vfstrace </literal>.</para>
 815       <para>It is possible to disable warning, error, and console messages, though it is strongly recommended to have something like <literal>lctl debug_daemon</literal> running to capture this data to a local file system for failure detection purposes.</para>
 816     </section>
 817     <section remap="h3">
 818       <title>Tracing Lock Traffic</title>
 819       <para>The Lustre software provides a specific debug type category for tracing lock traffic.
 820         Use:</para>
 821       <screen>lctl&gt; filter all_types
 822 lctl&gt; show dlmtrace
 823 lctl&gt; debug_kernel [<replaceable>filename</replaceable>] </screen>
 824     </section>
 825     <section remap="h3">
 826       <title>Controlling Console Message Rate Limiting</title>
 827       <para>Some console messages which are printed by Lustre are rate limited.  When such messages are printed, they may be followed by a message saying "Skipped N previous similar message(s)," where N is the number of messages skipped.  This rate limiting can be completely disabled by a libcfs module parameter called <literal>libcfs_console_ratelimit</literal>.  To disable console message rate limiting, add this line to <literal>/etc/modprobe.d/lustre.conf</literal> and then reload Lustre modules.</para>
 828       <screen>options libcfs libcfs_console_ratelimit=0</screen>
 829       <para>It is also possible to set the minimum and maximum delays between rate-limited console messages using the module parameters <literal>libcfs_console_max_delay</literal> and <literal>libcfs_console_min_delay</literal>.  Set these in <literal>/etc/modprobe.d/lustre.conf</literal> and then reload Lustre modules.  Additional information on libcfs module parameters is available via <literal>modinfo</literal>:</para>
 830       <screen>modinfo libcfs</screen>
 831     </section>
 832   </section>
 833   <section xml:id="dbdoclet.50438274_80443">
 834     <title><indexterm><primary>debugging</primary><secondary>developers tools</secondary></indexterm>Lustre Debugging for Developers</title>
 835     <para>The procedures in this section may be useful to developers debugging Lustre source
 836       code.</para>
 837     <section remap="h3">
 838       <title>Adding Debugging to the Lustre Source Code</title>
 839       <para>The debugging infrastructure provides a number of macros that can be used in Lustre source code to aid in debugging or reporting serious errors.</para>
 840       <para>To use these macros, you will need to set the <literal>DEBUG_SUBSYSTEM</literal> variable at the top of the file as shown below:</para>
 841       <screen>#define DEBUG_SUBSYSTEM S_PORTALS</screen>
 842       <para>A list of available macros with descriptions is provided in the table below.</para>
 843       <informaltable frame="all">
 844         <tgroup cols="2">
 845           <colspec colname="c1" colwidth="50*"/>
 846           <colspec colname="c2" colwidth="50*"/>
 847           <thead>
 848             <row>
 849               <entry>
 850                 <para><emphasis role="bold">Macro</emphasis></para>
 851               </entry>
 852               <entry>
 853                 <para><emphasis role="bold">Description</emphasis></para>
 854               </entry>
 855             </row>
 856           </thead>
 857           <tbody>
 858             <row>
 859               <entry>
 860                 <para> <emphasis role="bold">
 861                     <literal>LBUG()</literal>
 862                   </emphasis></para>
 863               </entry>
 864               <entry>
 865                 <para>A panic-style assertion in the kernel which causes the Lustre file system to
 866                   dump its circular log to the <literal>/tmp/lustre-log</literal> file. This file
 867                   can be retrieved after a reboot. <literal>LBUG()</literal> freezes the thread to
 868                   allow capture of the panic stack. A system reboot is needed to clear the
 869                   thread.</para>
 870               </entry>
 871             </row>
 872             <row>
 873               <entry>
 874                 <para> <emphasis role="bold">
 875                     <literal>LASSERT()</literal>
 876                   </emphasis></para>
 877               </entry>
 878               <entry>
 879                 <para>Validates a given expression as true, otherwise calls LBUG(). The failed expression is printed on the console, although the values that make up the expression are not printed.</para>
 880               </entry>
 881             </row>
 882             <row>
 883               <entry>
 884                 <para> <emphasis role="bold">
 885                     <literal>LASSERTF()</literal>
 886                   </emphasis></para>
 887               </entry>
 888               <entry>
 889                 <para>Similar to <literal>LASSERT()</literal> but allows a free-format message to be printed, like <literal>printf/printk</literal>.</para>
 890               </entry>
 891             </row>
 892             <row>
 893               <entry>
 894                 <para> <emphasis role="bold">
 895                     <literal>CDEBUG()</literal>
 896                   </emphasis></para>
 897               </entry>
 898               <entry>
 899                 <para>The basic, most commonly used debug macro that takes just one more argument than standard <literal>printf()</literal> - the debug type. This message adds to the debug log with the debug mask set accordingly. Later, when a user retrieves the log for troubleshooting, they can filter based on this type.</para>
 900                 <para><literal>CDEBUG(D_INFO, &quot;debug message: rc=%d\n&quot;, number);</literal></para>
 901               </entry>
 902             </row>
 903             <row>
 904               <entry>
 905                 <para> <emphasis role="bold">
 906                     <literal>CDEBUG_LIMIT()</literal>
 907                   </emphasis></para>
 908               </entry>
 909               <entry>
 910                 <para> Behaves similarly to <literal>CDEBUG()</literal>, but rate limits this message when printing to the console (for <literal>D_WARN</literal>, <literal>D_ERROR</literal>, and <literal>D_CONSOLE</literal> message types. This is useful for messages that use a variable debug mask:</para>
 911                 <para><literal>CDEBUG(mask, &quot;maybe bad: rc=%d\n&quot;, rc);</literal></para>
 912               </entry>
 913             </row>
 914             <row>
 915               <entry>
 916                 <para> <emphasis role="bold">
 917                     <literal>CERROR()</literal>
 918                   </emphasis></para>
 919               </entry>
 920               <entry>
 921                 <para>Internally using <literal>CDEBUG_LIMIT(D_ERROR, ...)</literal>, which unconditionally prints the message in the debug log and to the console. This is appropriate for serious errors or fatal conditions.  Messages printed to the console are prefixed with <literal>LustreError:</literal>, and are rate-limited, to avoid flooding the console with duplicates.</para>
 922                 <para><literal>CERROR(&quot;Something bad happened: rc=%d\n&quot;, rc);</literal></para>
 923               </entry>
 924             </row>
 925             <row>
 926               <entry>
 927                 <para> <emphasis role="bold">
 928                     <literal>CWARN()</literal>
 929                   </emphasis></para>
 930               </entry>
 931               <entry>
 932                 <para> Behaves similarly to <literal>CERROR()</literal>, but prefixes the messages with <literal>Lustre:</literal>. This is appropriate for important, but not fatal conditions.  Messages printed to the console are rate-limited.</para>
 933               </entry>
 934             </row>
 935             <row>
 936               <entry>
 937                 <para> <emphasis role="bold">
 938                     <literal>CNETERR()</literal>
 939                   </emphasis></para>
 940               </entry>
 941               <entry>
 942                 <para> Behaves similarly to <literal>CERROR()</literal>, but prints error messages for LNet if <literal>D_NETERR</literal> is set in the <literal>debug</literal> mask. This is appropriate for serious networking errors. Messages printed to the console are rate-limited.</para>
 943               </entry>
 944             </row>
 945             <row>
 946               <entry>
 947                 <para> <emphasis role="bold">
 948                     <literal>DEBUG_REQ()</literal>
 949                   </emphasis></para>
 950               </entry>
 951               <entry>
 952                 <para>Prints information about the given <literal>ptlrpc_request</literal> structure.</para>
 953                 <para><literal>DEBUG_REQ(D_RPCTRACE, req, &quot;"Handled RPC: rc=%d\n&quot;, rc);</literal></para>
 954               </entry>
 955             </row>
 956             <row>
 957               <entry>
 958                 <para> <emphasis role="bold">
 959                     <literal>ENTRY</literal>
 960                   </emphasis></para>
 961               </entry>
 962               <entry>
 963                 <para> Add messages to the entry of a function to aid in call tracing (takes no arguments). When using these macros, cover all exit conditions with a single <literal>EXIT</literal>, <literal>GOTO()</literal>, or <literal>RETURN()</literal> macro to avoid confusion when the debug log reports that a function was entered, but never exited.</para>
 964               </entry>
 965             </row>
 966             <row>
 967               <entry>
 968                 <para> <emphasis role="bold">
 969                     <literal>EXIT</literal>
 970                   </emphasis></para>
 971               </entry>
 972               <entry>
 973                 <para> Mark the exit of a function, to match <literal>ENTRY</literal> (takes no arguments).</para>
 974               </entry>
 975             </row>
 976             <row>
 977               <entry>
 978                 <para> <emphasis role="bold">
 979                     <literal>GOTO()</literal>
 980                   </emphasis></para>
 981               </entry>
 982               <entry>
 983                 <para> Mark when code jumps via <literal>goto</literal> to the end of a function, to match <literal>ENTRY</literal>, and prints out the goto label and function return code in signed and unsigned decimal, and hexadecimal format.</para>
 984               </entry>
 985             </row>
 986             <row>
 987               <entry>
 988                 <para> <emphasis role="bold">
 989                     <literal>RETURN()</literal>
 990                   </emphasis></para>
 991               </entry>
 992               <entry>
 993                 <para> Mark the exit of a function, to match <literal>ENTRY</literal>, and prints out the function return code in signed and unsigned decimal, and hexadecimal format.</para>
 994               </entry>
 995             </row>
 996             <row>
 997               <entry>
 998                 <para> <emphasis role="bold">
 999                     <literal>LDLM_DEBUG()</literal>
1000                   </emphasis></para>
1001                 <para> <emphasis role="bold">
1002                     <literal>LDLM_DEBUG_NOLOCK()</literal>
1003                   </emphasis></para>
1004               </entry>
1005               <entry>
1006                 <para>Used when tracing LDLM locking operations. These macros build a thin trace that shows the locking requests on a node, and can also be linked across the client and server node using the printed lock handles.</para>
1007               </entry>
1008             </row>
1009             <row>
1010               <entry>
1011                 <para> <emphasis role="bold">
1012                     <literal>OBD_FAIL_CHECK()</literal>
1013                   </emphasis></para>
1014               </entry>
1015               <entry>
1016                 <para>Allows insertion of failure points into the Lustre source code. This is useful
1017                   to generate regression tests that can hit a very specific sequence of events. This
1018                   works in conjunction with &quot;<literal>lctl set_param
1019                       fail_loc=<replaceable>fail_loc</replaceable></literal>&quot; to set a specific
1020                   failure point for which a given <literal>OBD_FAIL_CHECK()</literal> will
1021                   test.</para>
1022               </entry>
1023             </row>
1024             <row>
1025               <entry>
1026                 <para> <emphasis role="bold">
1027                     <literal>OBD_FAIL_TIMEOUT()</literal>
1028                   </emphasis></para>
1029               </entry>
1030               <entry>
1031                 <para>Similar to <literal>OBD_FAIL_CHECK()</literal>. Useful to simulate hung, blocked or busy processes or network devices. If the given <literal>fail_loc</literal> is hit, <literal>OBD_FAIL_TIMEOUT()</literal> waits for the specified number of seconds.</para>
1032               </entry>
1033             </row>
1034             <row>
1035               <entry>
1036                 <para> <emphasis role="bold">
1037                     <literal>OBD_RACE()</literal>
1038                   </emphasis></para>
1039               </entry>
1040               <entry>
1041                 <para>Similar to <literal>OBD_FAIL_CHECK()</literal>. Useful to have multiple processes execute the same code concurrently to provoke locking races. The first process to hit <literal>OBD_RACE()</literal> sleeps until a second process hits <literal>OBD_RACE()</literal>, then both processes continue.</para>
1042               </entry>
1043             </row>
1044             <row>
1045               <entry>
1046                 <para> <emphasis role="bold">
1047                     <literal>OBD_FAIL_ONCE</literal>
1048                   </emphasis></para>
1049               </entry>
1050               <entry>
1051                 <para>A flag set on a <literal>fail_loc</literal> breakpoint to cause the <literal>OBD_FAIL_CHECK()</literal> condition to be hit only one time. Otherwise, a <literal>fail_loc</literal> is permanent until it is cleared with &quot;<literal>lctl set_param fail_loc=0</literal>&quot;.</para>
1052               </entry>
1053             </row>
1054             <row>
1055               <entry>
1056                 <para> <emphasis role="bold">
1057                     <literal>OBD_FAIL_RAND</literal>
1058                   </emphasis></para>
1059               </entry>
1060               <entry>
1061                 <para>A flag set on a <literal>fail_loc</literal> breakpoint to cause <literal>OBD_FAIL_CHECK()</literal> to fail randomly; on average every (1 / fail_val) times.</para>
1062               </entry>
1063             </row>
1064             <row>
1065               <entry>
1066                 <para> <emphasis role="bold">
1067                     <literal>OBD_FAIL_SKIP</literal>
1068                   </emphasis></para>
1069               </entry>
1070               <entry>
1071                 <para>A flag set on a <literal>fail_loc</literal> breakpoint to cause <literal>OBD_FAIL_CHECK()</literal> to succeed <literal>fail_val</literal> times, and then fail permanently or once with <literal>OBD_FAIL_ONCE</literal>.</para>
1072               </entry>
1073             </row>
1074             <row>
1075               <entry>
1076                 <para> <emphasis role="bold">
1077                     <literal>OBD_FAIL_SOME</literal>
1078                   </emphasis></para>
1079               </entry>
1080               <entry>
1081                 <para>A flag set on <literal>fail_loc</literal> breakpoint to cause <literal>OBD_FAIL_CHECK</literal> to fail <literal>fail_val</literal> times, and then succeed.</para>
1082               </entry>
1083             </row>
1084           </tbody>
1085         </tgroup>
1086       </informaltable>
1087     </section>
1088     <section remap="h3">
1089       <title>Accessing the <literal>ptlrpc</literal> Request History</title>
1090       <para>Each service maintains a request history, which can be useful for first occurrence troubleshooting.</para>
1091       <para><literal>ptlrpc</literal> is an RPC protocol layered on LNet that deals with stateful servers and has semantics and built-in support for recovery.</para>
1092       <para>The ptlrpc request history works as follows:</para>
1093       <orderedlist>
1094         <listitem>
1095           <para><literal>request_in_callback()</literal> adds the new request to the service&apos;s request history.</para>
1096         </listitem>
1097         <listitem>
1098           <para>When a request buffer becomes idle, it is added to the service&apos;s request buffer history list.</para>
1099         </listitem>
1100         <listitem>
1101           <para>Buffers are culled from the service request buffer history if it has grown above <literal>req_buffer_history_max</literal> and its reqs are removed from the service request history.</para>
1102         </listitem>
1103       </orderedlist>
1104       <para>Request history is accessed and controlled using the following parameters for each service:</para>
1105       <itemizedlist>
1106         <listitem>
1107           <para><literal>req_buffer_history_len </literal></para>
1108           <para>Number of request buffers currently in the history</para>
1109         </listitem>
1110       </itemizedlist>
1111       <itemizedlist>
1112         <listitem>
1113           <para><literal>req_buffer_history_max </literal></para>
1114           <para>Maximum number of request buffers to keep</para>
1115         </listitem>
1116       </itemizedlist>
1117       <itemizedlist>
1118         <listitem>
1119           <para><literal>req_history </literal> </para>
1120           <para>The request history</para>
1121         </listitem>
1122       </itemizedlist>
1123       <para>Requests in the history include &quot;live&quot; requests that are currently being handled. Each line in <literal>req_history</literal> looks like:</para>
1124       <screen><replaceable>sequence</replaceable>:<replaceable>target_NID</replaceable>:<replaceable>client_NID</replaceable>:<replaceable>cliet_xid</replaceable>:<replaceable>request_length</replaceable>:<replaceable>rpc_phase</replaceable> <replaceable>service_specific_data</replaceable> </screen>
1125       <informaltable frame="all">
1126         <tgroup cols="2">
1127           <colspec colname="c1" colwidth="50*"/>
1128           <colspec colname="c2" colwidth="50*"/>
1129           <thead>
1130             <row>
1131               <entry>
1132                 <para><emphasis role="bold">Parameter</emphasis></para>
1133               </entry>
1134               <entry>
1135                 <para><emphasis role="bold">Description</emphasis></para>
1136               </entry>
1137             </row>
1138           </thead>
1139           <tbody>
1140             <row>
1141               <entry>
1142                 <para> <emphasis role="bold">
1143                     <literal>seq</literal>
1144                   </emphasis></para>
1145               </entry>
1146               <entry>
1147                 <para> Request sequence number</para>
1148               </entry>
1149             </row>
1150             <row>
1151               <entry>
1152                 <para> <literal>
1153                     <replaceable>target NID</replaceable>
1154                   </literal></para>
1155               </entry>
1156               <entry>
1157                 <para> Destination <literal>NID</literal> of the incoming request</para>
1158               </entry>
1159             </row>
1160             <row>
1161               <entry>
1162                 <para> <literal>
1163                     <replaceable>client ID</replaceable>
1164                   </literal></para>
1165               </entry>
1166               <entry>
1167                 <para> Client <literal>PID</literal> and <literal>NID</literal></para>
1168               </entry>
1169             </row>
1170             <row>
1171               <entry>
1172                 <para>
1173                         <literal>
1174                     <replaceable>xid</replaceable>
1175                   </literal>
1176                   </para>
1177               </entry>
1178               <entry>
1179                 <para> <literal>rq_xid</literal></para>
1180               </entry>
1181             </row>
1182             <row>
1183               <entry>
1184                 <para> <emphasis role="bold">
1185                     <literal>length</literal>
1186                   </emphasis></para>
1187               </entry>
1188               <entry>
1189                 <para> Size of the request message</para>
1190               </entry>
1191             </row>
1192             <row>
1193               <entry>
1194                 <para> <emphasis role="bold">
1195                     <literal>phase</literal>
1196                   </emphasis></para>
1197               </entry>
1198               <entry>
1199                 <para><itemizedlist>
1200                     <listitem>
1201                       <para>New (waiting to be handled or could not be unpacked)</para>
1202                     </listitem>
1203                     <listitem>
1204                       <para>Interpret (unpacked or being handled)</para>
1205                     </listitem>
1206                     <listitem>
1207                       <para>Complete (handled)</para>
1208                     </listitem>
1209                   </itemizedlist></para>
1210               </entry>
1211             </row>
1212             <row>
1213               <entry>
1214                 <para> <emphasis role="bold">
1215                     <literal>svc specific</literal>
1216                   </emphasis></para>
1217               </entry>
1218               <entry>
1219                 <para>Service-specific request printout. Currently, the only service that does this is the OST (which prints the opcode if the message has been unpacked successfully</para>
1220               </entry>
1221             </row>
1222           </tbody>
1223         </tgroup>
1224       </informaltable>
1225     </section>
1226     <section remap="h3">
1227       <title><indexterm><primary>debugging</primary><secondary>memory leaks</secondary></indexterm>Finding Memory Leaks Using <literal>leak_finder.pl</literal></title>
1228       <para>Memory leaks can occur in code when memory has been allocated and then not freed once it is no longer required. The <literal>leak_finder.pl</literal> program provides a way to find memory leaks.</para>
1229       <para>Before running this program, you must turn on debugging to collect all <literal>malloc</literal> and free entries. Run:</para>
1230       <screen>lctl set_param debug=+malloc </screen>
1231       <para>Then complete the following steps:</para>
1232       <orderedlist>
1233         <listitem>
1234           <para>Dump the log into a user-specified log file using lctl (see <xref linkend="dbdoclet.50438274_62472"/>).</para>
1235         </listitem>
1236         <listitem>
1237           <para>Run the leak finder on the newly-created log dump:</para>
1238           <screen>perl leak_finder.pl <replaceable>ascii-logname</replaceable></screen>
1239         </listitem>
1240       </orderedlist>
1241       <para>The output is:</para>
1242       <screen>malloced 8bytes at a3116744 (called pathcopy)
1243 (lprocfs_status.c:lprocfs_add_vars:80)
1244 freed 8bytes at a3116744 (called pathcopy)
1245 (lprocfs_status.c:lprocfs_add_vars:80)
1246 </screen>
1247       <para>The tool displays the following output to show the leaks found:</para>
1248       <screen>Leak:32bytes allocated at a23a8fc(service.c:ptlrpc_init_svc:144,debug file line 241)</screen>
1249     </section>
1250   </section>
1251 </chapter>
1252 <!--
1253   vim:expandtab:shiftwidth=2:tabstop=8:
1254   -->