WARNING: This is the _old_ Lustre wiki, and it is in the process of being retired. The information found here is all likely to be out of date. Please search the new wiki for more up to date information.

Lustre Debugging Procedures: Difference between revisions

From Obsolete Lustre Wiki
Jump to navigationJump to search
 
(83 intermediate revisions by 2 users not shown)
Line 1: Line 1:
<small>''(Updated: Feb 2010)''</small>
__TOC__
The procedures below may be useful to administrators or developers debugging a Lustre™ file system.
The procedures below may be useful to administrators or developers debugging a Lustre™ file system.


== Understanding the Lustre debug messaging format ==
== Understanding the Lustre debug messaging format ==


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 [http://wiki.lustre.org/manual/LustreManual18_HTML/LustreDebugging.html#50532482_pgfId-1291339|Section 23.1 ''Lustre Debug Messages''] in the [[Lustre Documentation|''Lustre Operations Manual'']].
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 [http://wiki.lustre.org/manual/LustreManual20_HTML/LustreDebugging.html#50438274_pgfId-1295747 Section 28.2.1.1: ''Lustre Debug Messages''] in the [http://wiki.lustre.org/manual/LustreManual20_HTML/index.html ''Lustre Operations Manual''].


'''''Note:''''' For a  current list of subsystems and debug message types, see lnet/include/libcfs/libcfs.h '''[[Keep this note?]]'''
'''''Note:''''' For a  current list of subsystems and debug message types, see ''lnet/include/libcfs/libcfs.h'' in the Lustre tree.


The elements of a Lustre debug message are described in [http://wiki.lustre.org/manual/LustreManual18_HTML/LustreDebugging.html#50532482_pgfId-1291365|Section 23.1.1 ''Format of Lustre Debug Messages''] in the [[Lustre Documentation|''Lustre Operations Manual'']].
The elements of a Lustre debug message are described in [http://wiki.lustre.org/manual/LustreManual20_HTML/LustreDebugging.html#50438274_pgfId-1295842 Section 28.2.1.2: ''Format of Lustre Debug Messages''] in the [http://wiki.lustre.org/manual/LustreManual20_HTML/index.html ''Lustre Operations Manual''].


== Using the ''lctl'' tool to view debug messages==
== Using the ''lctl'' tool to view debug messages==


The ''lctl'' 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 more information, see [http://wiki.lustre.org/manual/LustreManual18_HTML/LustreDebugging.html#50532482_pgfId-1291455|Section 23.2.3 ''The lctl Tool''] in the [[Lustre Documentation|''Lustre Operations Manual'']].
The ''lctl'' 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 more information about the ''lctl'' tool, see [http://wiki.lustre.org/manual/LustreManual20_HTML/LustreDebugging.html#50438274_pgfId-1295889 Section 28.2.2: ''Using the lctl Tool to View Debug Messages''] and [http://wiki.lustre.org/manual/LustreManual20_HTML/SystemConfigurationUtilities_HTML.html#50438219_pgfId-1318224 Section 36.3: ''lctl''] in the [http://wiki.lustre.org/manual/LustreManual20_HTML/index.html ''Lustre Operations Manual''].


A sample ''lctl'' run is shown in [http://wiki.lustre.org/manual/LustreManual18_HTML/LustreDebugging.html#50532482_pgfId-1291455|Section 23.2.7 ''Sample lctl Run''] in the [[Lustre Documentation|''Lustre Operations Manual'']].
A sample ''lctl'' run is shown in [http://wiki.lustre.org/manual/LustreManual20_HTML/LustreDebugging.html#50438274_pgfId-1295915 Section 28.2.2.1: ''Sample lctl Run''] in the [http://wiki.lustre.org/manual/LustreManual20_HTML/index.html ''Lustre Operations Manual''].


==== Using the debug daemon option to ''lctl''====
==== Using the ''lctl'' debug daemon option to dump the buffer to a file====
The debug_daemon option is used by ''lctl'' to control the dumping of the ''debug_kernel'' buffer to a user-specified file. For more information about the debug daemon including a list of commands, see [http://wiki.lustre.org/manual/LustreManual18_HTML/LustreDebugging.html#50532482_pgfId-1291420|Section 23.2.1 ''Debug Daemon Option to lctl''] in the [[Lustre Documentation|''Lustre Operations Manual'']].
The debug_daemon option is used by ''lctl'' to control the dumping of the ''debug_kernel'' buffer to a user-specified file. For more information about the debug daemon including a list of commands, see [http://wiki.lustre.org/manual/LustreManual20_HTML/LustreDebugging.html#50438274_pgfId-1295930 Section 28.2.3: ''Dumping the Buffer to a File (debug_daemon)''] in the [http://wiki.lustre.org/manual/LustreManual20_HTML/index.html ''Lustre Operations Manual''].


== Controlling the information written to the kernel debug log ==
== Controlling the information written to the kernel debug log ==
Masks are provided in ''/proc/sys/lnet/subsystem_debug'' and ''/proc/sys/lnet/debug'' to be used with the ''systctl'' command to determine what information is to be written to the debug log. For more information and examples, see [http://wiki.lustre.org/manual/LustreManual18_HTML/LustreDebugging.html#50532482_pgfId-1291441|Section 23.2.2 ''Controlling the Kernel Debug Log''] in the [[Lustre Documentation|''Lustre Operations Manual'']].
Masks are provided in ''/proc/sys/lnet/subsystem_debug'' and ''/proc/sys/lnet/debug'' to be used with the ''systctl'' command to determine what information is to be written to the debug log. For more information and examples, see [http://wiki.lustre.org/manual/LustreManual20_HTML/LustreDebugging.html#50438274_pgfId-1295954 Section 28.2.4: ''Controlling Information Written to the Kernel Debug Log''] and [http://wiki.lustre.org/manual/LustreManual20_HTML/LustreProc.html#50438271_pgfId-1290883 Section 31.3: ''Debug''] in the [http://wiki.lustre.org/manual/LustreManual20_HTML/index.html ''Lustre Operations Manual''].


== Use of strace for Troubleshooting ==
== Using ''strace'' to trace system calls ==  
''strace'' is a system call trace utility made available by the operating system. It can be used to trace a system call, intercept all the systems calls made by a process, and record the system call name, arguments, and return values. This tool is useful when trying to troubleshoot a failed system call.
The ''strace'' utility provided with the Linux distribution enables a system call to be traced by intercepting all the system calls made by a process and recording the system call name, arguments, and return values. For more details and examples, see [http://wiki.lustre.org/manual/LustreManual20_HTML/LustreDebugging.html#50438274_pgfId-1295970 Section 28.2.5: ''Troubleshooting with strace''] in the [http://wiki.lustre.org/manual/LustreManual20_HTML/index.html ''Lustre Operations Manual''].


The ''strace'' can be invoked for a system call as shown below:
== Looking at disk content ==


$strace <''system-call''> <''args''>
In Lustre, the inodes on the metadata server contain extended attributes (EAs) that store information about file striping. EAs contain a list of all object IDs and their locations (that is, the OST that stores them). The ''lfs'' tool can be used to obtain this information for a given file via the ''getstripe'' sub-command. For more information, see see [http://wiki.lustre.org/manual/LustreManual20_HTML/LustreDebugging.html#50438274_pgfId-1295983 Section 28.2.6: ''Looking at Disk Content''] in the [http://wiki.lustre.org/manual/LustreManual20_HTML/index.html ''Lustre Operations Manual''] ].


A system call might sometimes fork child processes, we need to use the ''-f'' option in such case to trace the child processes also:
== Finding the Lustre UUID of an OST ==
To determine the Lustre UUID of an obdfilter 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), use ''debugfs'' to get the ''last_rcvd'' file.


$strace -f <''system-call''> <''args''>


We can redirect the ''strace'' output to a file that maybe examined at a later time:


$strace -o <''filename''> <''system-call''> <''args''>
== Printing debug messages to the console ==
 
To dump debug messages to the console (''/var/log/messages''), set the corresponding debug mask in the ''printk'' flag:
We can use the ''-ff'' option along with ''-o'' to cause the trace output to be saved in ''filename.pid'', where ''pid'' is the process id of the process being traced.
 
Use ''-ttt'' to timestamp all lines in the ''strace'' output, so they can be correlated to operations in the lustre kernel debug log.
 
If the debugging is done in User mode Linux, it's a good idea to save the traces on the host machine by using the command shown below; here we assume that the hostfs is mounted on  ''/r'':
 
$strace -o /r/tmp/vi.strace
 
== Looking at Disk Content ==
In Lustre, the information about objects that make a file is stored in the extended attributes of the file inode. This will contain a list of all the object ids and their locations (that is, which OST device stores them). Lustre has a tool called the '''lfs''' that can be used to obtain this information for a given file name via the '''getstripe''' subcommand. A corresponding '''lfs setstripe''' command can be used to specify the striping attributes of a new file or directory.
 
The '''lfs getstripe''' utility is written in C; it takes a Lustre filename as input and lists all the objects that form a part of this file. So, to obtain this information for the file ''/mnt/lustre/frog'' in Lustre filesystem, we would do:
 
{|
|-
  $lfs getstripe /mnt/lustre/frog
  $
    OBDs:
      0 : OSC_localhost_UUID
      1 : OSC_localhost_2_UUID
      2 : OSC_localhost_3_UUID
    obdidx        objid
      0            17
      1            4
|}
 
The ''' debugfs''' tool is provided by the e2fsprogs package; it can be used for interactive debugging of an ext3/ldiskfs filesystem. It can either be used just to check the status, or it can be used to modify some information in the filesystem, maybe to correct the filesystem state. In Lustre, all the objects that belong to a file are stored in an underlying ldiskfs filesystem on the OST's.  The filesystem uses the object id's as the file names. So, once the object id's are known, '''debugfs''' can be used to obtain the attributes of all the objects from the different OST's. A sample run for the ''/mnt/lustre/frog'' file used in the example above is shown here:
 
{|
|-
    $ debugfs -c /tmp/ost1
    debugfs: cd O
    debugfs: cd 0              /* for files in group 0 */
    debugfs: cd d<objid % 32>
    debugfs: stat <objid>      /* for getattr on object */
    debugfs: quit
## Suppose object id is 36, then follow the steps below:
    $ debugfs /tmp/ost1
    debugfs: cd O
    debugfs: cd 0
    debugfs: cd d4                /* objid % 32 */
    debugfs: stat 36              /* for getattr on obj 4*/
    debugfs: dump 36 /tmp/obj.36  /* dump contents of obj 4 */
    debugfs: quit
|}
More help on '''debugfs''' can be obtained from the '''man pages'''.
 
== Finding the lustre UUID of an OST ==
To find the Lustre UUID of an obdfilter disk (in the event, perhaps, you mix up the cables on your OST devices or the SCSI bus numbering suddenly changes and your SCSI devices get new names), use debugfs to get the last_rcvd file ''debugfs -R "dump last_rcvd /tmp/last_rcvf"''
 
== Tcpdump ==
[[Obsolete?]]
Lustre provides a modified version of tcpdump that can be used to decode the complete Lustre message packet. '''[NOTE:''' It is currently
out-of-date and unusable] The tool has more developed support
to read packets from clients to OSTs; the functionality to decode the packets between clients and MDSs is not well developed yet.
 
== Printing to /var/log/messages ==
To dump debug messages to the console set the corresponding debug mask in the printk flag:
<pre>
<pre>
sysctl -w lnet.printk=-1
sysctl -w lnet.printk=-1
</pre>
</pre>


This slows down the system dramatically.  It is also possible to selectively enable or disable this for particular flags:
This slows down the system dramatically, so it is also possible to selectively enable or disable this capability for particular flags:
<pre>
<pre>
sysctl -w lnet.printk=+vfstrace
sysctl -w lnet.printk=+vfstrace
Line 106: Line 47:
</pre>
</pre>


In newer versions of Lustre (1.4.12, 1.6.5) it is even possible to disable '''warning''', '''error''', and '''console''' messages, though it is strongly recommended to have something like ''lctl debug_daemon'' running to capture this data to a local filesystem for debugging purposes.
It is possible to disable '''warning''', '''error''', and '''console''' messages, though it is strongly recommended to have something like ''lctl debug_daemon'' running to capture this data to a local file system for debugging purposes.


== Tracing Lock Traffic ==
== Tracing lock traffic ==
We have built a special debug type category for tracing lock traffic:
Lustre has a specific debug type category for tracing lock traffic. Use:


{| border=1 cellspacing=1
<pre>
|-
lctl> filter all_types
lctl> show dlmtrace
lctl> filter all_types <br/>
lctl> show dlmtrace <br/>
lctl> debug_kernel [filename]
lctl> debug_kernel [filename]
|}
</pre>
 
[[NOTES]] Put at end - used only in extreme cases when we are helping them trace a bad problem but useful for admin to know.

Latest revision as of 08:08, 20 January 2011

(Updated: Feb 2010)

The procedures below may be useful to administrators or developers debugging a Lustre™ file system.

Understanding the Lustre debug messaging format

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 Section 28.2.1.1: Lustre Debug Messages in the Lustre Operations Manual.

Note: For a current list of subsystems and debug message types, see lnet/include/libcfs/libcfs.h in the Lustre tree.

The elements of a Lustre debug message are described in Section 28.2.1.2: Format of Lustre Debug Messages in the Lustre Operations Manual.

Using the lctl tool to view debug messages

The lctl 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 more information about the lctl tool, see Section 28.2.2: Using the lctl Tool to View Debug Messages and Section 36.3: lctl in the Lustre Operations Manual.

A sample lctl run is shown in Section 28.2.2.1: Sample lctl Run in the Lustre Operations Manual.

Using the lctl debug daemon option to dump the buffer to a file

The debug_daemon option is used by lctl to control the dumping of the debug_kernel buffer to a user-specified file. For more information about the debug daemon including a list of commands, see Section 28.2.3: Dumping the Buffer to a File (debug_daemon) in the Lustre Operations Manual.

Controlling the information written to the kernel debug log

Masks are provided in /proc/sys/lnet/subsystem_debug and /proc/sys/lnet/debug to be used with the systctl command to determine what information is to be written to the debug log. For more information and examples, see Section 28.2.4: Controlling Information Written to the Kernel Debug Log and Section 31.3: Debug in the Lustre Operations Manual.

Using strace to trace system calls

The strace utility provided with the Linux distribution enables a system call to be traced by intercepting all the system calls made by a process and recording the system call name, arguments, and return values. For more details and examples, see Section 28.2.5: Troubleshooting with strace in the Lustre Operations Manual.

Looking at disk content

In Lustre, the inodes on the metadata server contain extended attributes (EAs) that store information about file striping. EAs contain a list of all object IDs and their locations (that is, the OST that stores them). The lfs tool can be used to obtain this information for a given file via the getstripe sub-command. For more information, see see Section 28.2.6: Looking at Disk Content in the Lustre Operations Manual ].

Finding the Lustre UUID of an OST

To determine the Lustre UUID of an obdfilter 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), use debugfs to get the last_rcvd file.


Printing debug messages to the console

To dump debug messages to the console (/var/log/messages), set the corresponding debug mask in the printk flag:

sysctl -w lnet.printk=-1

This slows down the system dramatically, so it is also possible to selectively enable or disable this capability for particular flags:

sysctl -w lnet.printk=+vfstrace
sysctl -w lnet.printk=-vfstrace

It is possible to disable warning, error, and console messages, though it is strongly recommended to have something like lctl debug_daemon running to capture this data to a local file system for debugging purposes.

Tracing lock traffic

Lustre has a specific debug type category for tracing lock traffic. Use:

lctl> filter all_types
lctl> show dlmtrace
lctl> debug_kernel [filename]