[LU-1407] Wrong error messages on MDS and Client during a POSIX-validated meta-data operations/situation

• Status: Resolved
• Project: Lustre
• Affects Version/s: Lustre 2.0.0, Lustre 2.1.0
• Fix Version/s: Lustre 2.4.0
• Type: Improvement
• Priority: Minor
• Reporter: Alexandre Louvet
• Assignee: Yang Sheng
• Resolution: Fixed

Environment

Occurs in both Lustre 2.0 and 2.1 with very small differences in messages.

Description

Here is the reproducer/scenario and error messages on the Client side :
=======================================================================
[root@lascaux3438 ~] # dmesg | grep Lustre | tail -10
Lustre: DEBUG MARKER: Fri Apr 27 16:10:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:15:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:20:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:25:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:30:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:35:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:40:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:45:02 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:50:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:55:01 2012
[root@lascaux3438 ~] # cd /ptmp
[root@lascaux3438 ptmp] # mkdir foo
[root@lascaux3438 ptmp] # cd foo
[root@lascaux3438 foo] # df .
Filesystem 1K-blocks Used Available Use% Mounted on
lascaux110-ib0@o2ib10,lascaux110-ib1@o2ib11:lascaux111-ib0@o2ib10,lascaux111-ib1@o2ib11:/ptmp2
1693133933568 200910090740 1475222769688 12% /ptmp
[root@lascaux3438 foo] #
[root@lascaux3438 foo] # stat .
File: `.'
Size: 4096 Blocks: 8 IO Block: 4096 directory
Device: ca6be868h/3396069480d Inode: 144115281692763756 Links: 2
Access: (0755/drwxr-xr-x) Uid: ( 0/ root) Gid: ( 0/ root)
Access: 2012-04-27 16:58:23.000000000 +0200
Modify: 2012-04-27 16:58:23.000000000 +0200
Change: 2012-04-27 16:58:23.000000000 +0200
[root@lascaux3438 foo] # dmesg | grep Lustre | tail -10
Lustre: DEBUG MARKER: Fri Apr 27 16:10:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:15:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:20:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:25:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:30:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:35:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:40:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:45:02 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:50:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:55:01 2012
[root@lascaux3438 foo] # rm -rf /ptmp/foo
[root@lascaux3438 foo] # stat .
stat: cannot stat `.': No such file or directory
[root@lascaux3438 foo] # dmesg | grep Lustre | tail -10
Lustre: DEBUG MARKER: Fri Apr 27 16:40:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:45:02 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:50:01 2012
Lustre: DEBUG MARKER: Fri Apr 27 16:55:01 2012
LustreError: 11-0: an error occurred while communicating with JO.BOB.WL.IL@o2ib11. The mds_getattr operation failed with -2
LustreError: Skipped 605 previous similar messages
LustreError: 61537:0:(file.c:2111:ll_inode_revalidate_fini()) failure -2 inode 144115281692763756
LustreError: 11-0: an error occurred while communicating with JO.BOB.WL.IL@o2ib11. The mds_getattr operation failed with -2
LustreError: 61544:0:(file.c:2111:ll_inode_revalidate_fini()) failure -2 inode 144115281692763756
LustreError: Skipped 1 previous similar message
[root@lascaux3438 foo] #
=======================================================================

when the error msgs on the Server side are multiple "(ldlm_lib.c:2123:target_send_reply_msg()) @@@ processing error (-2) ..." ones.

These error msgs should be avoided for log cleanup/clarification and at least be changed of message category to be only enabled at a high level of debugging.

Comments

[Bruno Faccini (Inactive)]

Oops, forgot to indicate that the "mkdir/cd/rmdir" sequence is valid and often used in T100 site/customer jobs.

[Peter Jones]

Yangsheng

Could you please look into this one?

Thanks

Peter

[Yang Sheng]

Hi, Bruno, Do you think this messages shouldn't be print out or just don't too noisy.

[Yang Sheng]

Patch submit to: http://review.whamcloud.com/3076

[Yang Sheng]

Patch landed. Close bug.