[LU-2979] sanity 133a: proc counter for mkdir on mds1 was not incremented

• Type: Bug
• Resolution: Won't Fix
• Priority: Blocker
• Fix Version/s: Lustre 2.4.0
• Affects Version/s: Lustre 2.4.0
• Labels: LB
• Severity: 3
• Assignee: Di Wang
• Reporter: Maloo

Description

This issue was created by maloo for Li Wei <[e-mail]>

This issue relates to the following test suite run: https://maloo.whamcloud.com/test_sets/9b412d48-8dbe-11e2-bb99-52540035b04c.

The sub-test test_133a failed with the following error:

The counter for mkdir on mds1 was not incremented

Info required for matching: sanity 133a

== sanity test 133a: Verifying MDT stats ========================================== 09:55:50 (1363366550)
CMD: client-20-ib /usr/sbin/lctl list_param mdt.*.rename_stats
mdt.lustre-MDT0000.rename_stats
CMD: client-20-ib /usr/sbin/lctl set_param mdt.*.md_stats=clear
mdt.lustre-MDT0000.md_stats=clear
CMD: client-21-ib /usr/sbin/lctl set_param obdfilter.*.stats=clear
obdfilter.lustre-OST0000.stats=clear
obdfilter.lustre-OST0001.stats=clear
obdfilter.lustre-OST0002.stats=clear
obdfilter.lustre-OST0003.stats=clear
obdfilter.lustre-OST0004.stats=clear
obdfilter.lustre-OST0005.stats=clear
obdfilter.lustre-OST0006.stats=clear
CMD: client-20-ib /usr/sbin/lctl get_param mdt.lustre-MDT0000.md_stats

 sanity test_133a: @@@@@@ FAIL: The counter for mkdir on mds1 was not incremented 
  Trace dump:
  = /usr/lib64/lustre/tests/test-framework.sh:3973:error_noexit()
  = /usr/lib64/lustre/tests/test-framework.sh:3996:error()
  = /usr/lib64/lustre/tests/sanity.sh:8033:check_stats()
  = /usr/lib64/lustre/tests/sanity.sh:8056:test_133a()
  = /usr/lib64/lustre/tests/test-framework.sh:4251:run_one()
  = /usr/lib64/lustre/tests/test-framework.sh:4284:run_one_logged()
  = /usr/lib64/lustre/tests/test-framework.sh:4139:run_test()
  = /usr/lib64/lustre/tests/sanity.sh:8083:main()
Dumping lctl log to /logdir/test_logs/2013-03-15/lustre-reviews-el6-x86_64--review--1_2_1__14053__-70011914322200-085246/sanity.test_133a.*.1363366552.log
CMD: client-20-ib,client-21-ib,client-22-ib,client-23-ib.lab.whamcloud.com /usr/sbin/lctl dk > /logdir/test_logs/2013-03-15/lustre-reviews-el6-x86_64--review--1_2_1__14053__-70011914322200-085246/sanity.test_133a.debug_log.\$(hostname -s).1363366552.log;
         dmesg > /logdir/test_logs/2013-03-15/lustre-reviews-el6-x86_64--review--1_2_1__14053__-70011914322200-085246/sanity.test_133a.dmesg.\$(hostname -s).1363366552.log

Issue Links

• is duplicated by: LU-3296 fs/lustre/mdt/*/md_stats not showing any stats after remount
• is related to: LU-2902 sanity test_156: NOT IN CACHE: before: , after:
• is related to: LU-1282 Lustre 2.1 client memory usage at mount is excessive

Comments

[James A Simmons]

Old blocker for unsupported version

[Andreas Dilger]

http://review.whamcloud.com/6136 is still not landed

[Sarah Liu]

verified with the latest tag-2.4.50RC1, client is running tag-2.4.50RC1 and server is running 2.3.0

[Jodi Levi (Inactive)]

Patch landed to master

[John Hammond]

Please see http://review.whamcloud.com/6328.

[Di Wang]

Ah, quite possible, I spent so much time to investigate the problem on collecting, but did not notice listing. Thank you.

[John Hammond]

I believe this is a bug related to on demand allocation of per-cpu stats. If nothing has yet happened on cpu 0 then no stats will have been allocated for cpu 0, and hence lprocfs_stats_counter_get(stats, 0, index) will return NULL. This NULL will in turn be returned from lprocfs_stats_seq_start() and will be interpreted by the seq_file code as an early EOF.

static inline struct lprocfs_counter *
lprocfs_stats_counter_get(struct lprocfs_stats *stats, unsigned int cpuid,
                          int index)
{
        struct lprocfs_counter *cntr;

        cntr = &stats->ls_percpu[cpuid]->lp_cntr[index];

        if ((stats->ls_flags & LPROCFS_STATS_FLAG_IRQ_SAFE) != 0)
                cntr = (void *)cntr + index * sizeof(__s64);

        return cntr;
}

static void *lprocfs_stats_seq_start(struct seq_file *p, loff_t *pos)
{
        struct lprocfs_stats *stats = p->private;
        /* return 1st cpu location */
        return (*pos >= stats->ls_num) ? NULL :
                lprocfs_stats_counter_get(stats, 0, *pos);
}

[Robert Read]

IMHO, not having properly functioning performance counters is pretty major problem.

[Di Wang]

http://review.whamcloud.com/6136 Add some debug information for the failure to help me understand the problem.

[Sarah Liu]

another instance seen in interop between 2.3.0 client and 2.4 server:
https://maloo.whamcloud.com/test_sets/491428e6-8fed-11e2-9b28-52540035b04c