Actions
Bug #38679
closedmds: behind on trimming and "[dentry] was purgeable but no longer is!"
% Done:
0%
Source:
Q/A
Tags:
Backport:
nautilus,mimic,luminous
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Component(FS):
MDS
Labels (FS):
multimds
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
2019-03-07T22:22:01.852 INFO:teuthology.orchestra.run.smithi179:> mkdir -p -- /home/ubuntu/cephtest/mnt.1/client.1/tmp && cd -- /home/ubuntu/cephtest/mnt.1/client.1/tmp && CEPH_CLI_TEST_DUP_COMMAND=1 CEPH_REF=4a8e27e6efdaad211a513d7fcdf7736bf8cebb71 TESTDIR="/home/ubuntu/cephtest" CEPH_ARGS="--cluster ceph" CEPH_ID="1" PATH=$PATH:/usr/sbin CEPH_BASE=/home/ubuntu/cephtest/clone.client.1 CEPH_ROOT=/home/ubuntu/cephtest/clone.client.1 adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage timeout 3h /home/ubuntu/cephtest/clone.client.1/qa/workunits/fs/misc/dirfrag.sh 2019-03-07T22:22:01.961 INFO:tasks.workunit.client.1.smithi179.stdout:creating folder hierarchy 2019-03-07T22:22:01.962 INFO:tasks.workunit.client.0.smithi179.stdout:creating folder hierarchy 2019-03-07T22:22:09.948 INFO:teuthology.orchestra.run.smithi167:Running: 2019-03-07T22:22:09.948 INFO:teuthology.orchestra.run.smithi167:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:22:09.952 INFO:teuthology.orchestra.run.smithi170:Running: 2019-03-07T22:22:09.952 INFO:teuthology.orchestra.run.smithi170:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:22:09.956 INFO:teuthology.orchestra.run.smithi179:Running: 2019-03-07T22:22:09.956 INFO:teuthology.orchestra.run.smithi179:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:22:40.105 INFO:teuthology.orchestra.run.smithi167:Running: 2019-03-07T22:22:40.106 INFO:teuthology.orchestra.run.smithi167:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:22:40.110 INFO:teuthology.orchestra.run.smithi170:Running: 2019-03-07T22:22:40.110 INFO:teuthology.orchestra.run.smithi170:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:22:40.114 INFO:teuthology.orchestra.run.smithi179:Running: 2019-03-07T22:22:40.115 INFO:teuthology.orchestra.run.smithi179:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:23:10.424 INFO:teuthology.orchestra.run.smithi167:Running: 2019-03-07T22:23:10.424 INFO:teuthology.orchestra.run.smithi167:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:23:10.428 INFO:teuthology.orchestra.run.smithi170:Running: 2019-03-07T22:23:10.428 INFO:teuthology.orchestra.run.smithi170:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:23:10.431 INFO:teuthology.orchestra.run.smithi179:Running: 2019-03-07T22:23:10.432 INFO:teuthology.orchestra.run.smithi179:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:23:29.459 INFO:tasks.workunit.client.0.smithi179.stdout:created hierarchy, now cleaning up 2019-03-07T22:23:45.038 INFO:teuthology.orchestra.run.smithi167:Running: 2019-03-07T22:23:45.038 INFO:teuthology.orchestra.run.smithi167:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:23:45.042 INFO:teuthology.orchestra.run.smithi170:Running: 2019-03-07T22:23:45.042 INFO:teuthology.orchestra.run.smithi170:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:23:45.047 INFO:teuthology.orchestra.run.smithi179:Running: 2019-03-07T22:23:45.047 INFO:teuthology.orchestra.run.smithi179:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:24:06.940 INFO:tasks.workunit.client.1.smithi179.stdout:created hierarchy, now cleaning up 2019-03-07T22:24:20.029 INFO:teuthology.orchestra.run.smithi167:Running: 2019-03-07T22:24:20.029 INFO:teuthology.orchestra.run.smithi167:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:24:20.055 INFO:teuthology.orchestra.run.smithi170:Running: 2019-03-07T22:24:20.055 INFO:teuthology.orchestra.run.smithi170:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:24:20.074 INFO:teuthology.orchestra.run.smithi179:Running: 2019-03-07T22:24:20.074 INFO:teuthology.orchestra.run.smithi179:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:24:57.842 INFO:teuthology.orchestra.run.smithi167:Running: 2019-03-07T22:24:57.843 INFO:teuthology.orchestra.run.smithi167:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:24:57.875 INFO:teuthology.orchestra.run.smithi170:Running: 2019-03-07T22:24:57.876 INFO:teuthology.orchestra.run.smithi170:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:24:57.880 INFO:teuthology.orchestra.run.smithi179:Running: 2019-03-07T22:24:57.880 INFO:teuthology.orchestra.run.smithi179:> sudo logrotate /etc/logrotate.d/ceph-test.conf 2019-03-07T22:24:59.192 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:24:59.198 7efd6f00b700 -1 received signal: Hangup from killall ceph-mds -1 (PID: 8637) UID: 0 2019-03-07T22:24:59.192 INFO:tasks.ceph.mds.c.smithi167.stderr:2019-03-07 22:24:59.199 7ffbe027b700 -1 received signal: Hangup from killall ceph-mds -1 (PID: 8637) UID: 0 2019-03-07T22:25:01.146 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/10000009bc2 [2,head] auth (dversion lock) v=4642 ino=0x10000009bc2 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c1c4fc0] was purgeable but no longer is! 2019-03-07T22:25:01.147 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/10000009af3 [2,head] auth (dversion lock) v=4644 ino=0x10000009af3 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5db29dc0] was purgeable but no longer is! 2019-03-07T22:25:01.147 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a640 [2,head] auth (dversion lock) v=4646 ino=0x1000000a640 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5dc79500] was purgeable but no longer is! 2019-03-07T22:25:01.147 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a45f [2,head] auth (dversion lock) v=4648 ino=0x1000000a45f state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5925ba40] was purgeable but no longer is! 2019-03-07T22:25:01.147 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a394 [2,head] auth (dversion lock) v=4650 ino=0x1000000a394 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c5b2700] was purgeable but no longer is! 2019-03-07T22:25:01.147 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a49b [2,head] auth (dversion lock) v=4652 ino=0x1000000a49b state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5df17dc0] was purgeable but no longer is! 2019-03-07T22:25:01.148 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a201 [2,head] auth (dversion lock) v=4654 ino=0x1000000a201 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5dc79880] was purgeable but no longer is! 2019-03-07T22:25:01.148 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a4e4 [2,head] auth (dversion lock) v=4656 ino=0x1000000a4e4 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5aa4dc00] was purgeable but no longer is! 2019-03-07T22:25:01.148 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a3f1 [2,head] auth (dversion lock) v=4658 ino=0x1000000a3f1 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5df16fc0] was purgeable but no longer is! 2019-03-07T22:25:01.148 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a3fe [2,head] auth (dversion lock) v=4660 ino=0x1000000a3fe state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c5b5340] was purgeable but no longer is! 2019-03-07T22:25:01.148 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a081 [2,head] auth (dversion lock) v=4662 ino=0x1000000a081 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5da16000] was purgeable but no longer is! 2019-03-07T22:25:01.148 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a14e [2,head] auth (dversion lock) v=4664 ino=0x1000000a14e state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c5b5dc0] was purgeable but no longer is! 2019-03-07T22:25:01.149 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a470 [2,head] auth (dversion lock) v=4666 ino=0x1000000a470 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c5bb180] was purgeable but no longer is! 2019-03-07T22:25:01.149 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/10000009d3b [2,head] auth (dversion lock) v=4668 ino=0x10000009d3b state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c5b5880] was purgeable but no longer is! 2019-03-07T22:25:01.149 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a528 [2,head] auth (dversion lock) v=4670 ino=0x1000000a528 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c5ba8c0] was purgeable but no longer is! 2019-03-07T22:25:01.149 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a3ba [2,head] auth (dversion lock) v=4672 ino=0x1000000a3ba state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e59fb3340] was purgeable but no longer is! 2019-03-07T22:25:01.149 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a3e5 [2,head] auth (dversion lock) v=4674 ino=0x1000000a3e5 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c5bb500] was purgeable but no longer is! 2019-03-07T22:25:01.149 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a5ea [2,head] auth (dversion lock) v=4676 ino=0x1000000a5ea state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5ccba000] was purgeable but no longer is! 2019-03-07T22:25:01.150 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a63d [2,head] auth (dversion lock) v=4678 ino=0x1000000a63d state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c5b3a40] was purgeable but no longer is! 2019-03-07T22:25:01.150 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/10000009fdf [2,head] auth (dversion lock) v=4680 ino=0x10000009fdf state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c5b2000] was purgeable but no longer is! 2019-03-07T22:25:01.151 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a586 [2,head] auth (dversion lock) v=4682 ino=0x1000000a586 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e59fb1c00] was purgeable but no longer is! 2019-03-07T22:25:01.152 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a349 [2,head] auth (dversion lock) v=4684 ino=0x1000000a349 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e58ab6fc0] was purgeable but no longer is! 2019-03-07T22:25:01.152 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a3fb [2,head] auth (dversion lock) v=4686 ino=0x1000000a3fb state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c960c40] was purgeable but no longer is! 2019-03-07T22:25:01.152 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/10000009d09 [2,head] auth (dversion lock) v=4688 ino=0x10000009d09 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e59fb2380] was purgeable but no longer is! 2019-03-07T22:25:01.152 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a0d8 [2,head] auth (dversion lock) v=4690 ino=0x1000000a0d8 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c961a40] was purgeable but no longer is! 2019-03-07T22:25:01.152 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a482 [2,head] auth (dversion lock) v=4692 ino=0x1000000a482 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5d74ea80] was purgeable but no longer is! 2019-03-07T22:25:01.152 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a533 [2,head] auth (dversion lock) v=4694 ino=0x1000000a533 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5d74f180] was purgeable but no longer is! 2019-03-07T22:25:01.153 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/10000009f65 [2,head] auth (dversion lock) v=4696 ino=0x10000009f65 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5e036e00] was purgeable but no longer is! 2019-03-07T22:25:01.153 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a49d [2,head] auth (dversion lock) v=4698 ino=0x1000000a49d state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c1c6e00] was purgeable but no longer is! 2019-03-07T22:25:01.153 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a0db [2,head] auth (dversion lock) v=4700 ino=0x1000000a0db state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5d74e700] was purgeable but no longer is! 2019-03-07T22:25:01.153 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a4a8 [2,head] auth (dversion lock) v=4702 ino=0x1000000a4a8 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5db26c40] was purgeable but no longer is! 2019-03-07T22:25:01.153 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a4c8 [2,head] auth (dversion lock) v=4704 ino=0x1000000a4c8 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5bbb08c0] was purgeable but no longer is! 2019-03-07T22:25:01.153 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a332 [2,head] auth (dversion lock) v=4706 ino=0x1000000a332 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5bbb0380] was purgeable but no longer is! 2019-03-07T22:25:01.154 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a191 [2,head] auth (dversion lock) v=4708 ino=0x1000000a191 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c1c4c40] was purgeable but no longer is! 2019-03-07T22:25:01.154 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a5ce [2,head] auth (dversion lock) v=4710 ino=0x1000000a5ce state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5e039180] was purgeable but no longer is! 2019-03-07T22:25:01.154 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a30d [2,head] auth (dversion lock) v=4712 ino=0x1000000a30d state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5e038c40] was purgeable but no longer is! 2019-03-07T22:25:01.154 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a4bf [2,head] auth (dversion lock) v=4714 ino=0x1000000a4bf state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5db29880] was purgeable but no longer is! 2019-03-07T22:25:01.154 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/10000009d24 [2,head] auth (dversion lock) v=4716 ino=0x10000009d24 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5d475c00] was purgeable but no longer is! 2019-03-07T22:25:01.154 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a38e [2,head] auth (dversion lock) v=4718 ino=0x1000000a38e state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5d6436c0] was purgeable but no longer is! 2019-03-07T22:25:01.155 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a33d [2,head] auth (dversion lock) v=4720 ino=0x1000000a33d state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5cd76c40] was purgeable but no longer is! 2019-03-07T22:25:01.155 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a30e [2,head] auth (dversion lock) v=4722 ino=0x1000000a30e state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5cd76000] was purgeable but no longer is! 2019-03-07T22:25:01.155 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/1000000a547 [2,head] auth (dversion lock) v=4724 ino=0x1000000a547 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5cd76700] was purgeable but no longer is! 2019-03-07T22:25:15.789 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:15.787 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray2/10000004524 [2,head] auth (dversion lock) v=5181 ino=0x10000004524 state=1879048192 | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c47b180] was purgeable but no longer is! 2019-03-07T22:25:20.741 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:25:20.748 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray5/1000000999f [2,head] auth (dversion lock) v=6359 ino=0x1000000999f state=1879048192 | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e57da7500] was purgeable but no longer is! 2019-03-07T22:27:12.304 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:27:12.314 7efd6e80a700 -1 mds.0.bal balancer runs too long 2019-03-07T22:27:12.304 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:27:12.314 7efd6e80a700 -1 mds.0.bal balancer runs too long 2019-03-07T22:27:26.020 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:27:26.030 7efd6e80a700 -1 mds.0.bal balancer runs too long 2019-03-07T22:27:26.021 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:27:26.030 7efd6e80a700 -1 mds.0.bal balancer runs too long 2019-03-07T22:27:33.605 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:27:33.615 7efd6e80a700 -1 mds.0.bal balancer runs too long 2019-03-07T22:27:55.639 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:27:55.650 7efd6e80a700 -1 mds.0.bal balancer runs too long 2019-03-07T22:28:23.641 INFO:tasks.ceph.mds.b.smithi167.stderr:2019-03-07 22:28:23.653 7efd6e80a700 -1 mds.0.bal balancer runs too long
From: /ceph/teuthology-archive/pdonnell-2019-03-07_15:13:09-multimds-wip-pdonnell-testing-20190307.041917-distro-basic-smithi/3679312/teuthology.log
Updated by Zheng Yan about 5 years ago
For the "was purgeable but no longer is" errors.
2019-03-07 22:25:01.126 7efd6c005700 10 mds.0.cache.ino(0x10000009bc2) auth_pin by 0x555e5ddfa700 on [inode 0x10000009bc2 [2,head] ~mds0/stray6/10000009bc2 auth v4642 ap=1 dirtyparent s=0 nl=0 n(v0 rc2019-03-07 22:24:26.391179 1=1+0) (iversion lock) | ptrwaiter=0 request=0 lock=0 caps=0 dirtyparent=1 dirty=1 authpin=1 0x555e5ddfa700] now 1 2019-03-07 22:25:01.126 7efd6c005700 20 mds.0.cache.ino(0x10000009bc2) store_backtrace: no dirtypool or no old pools 2019-03-07 22:25:01.126 7efd6c005700 1 -- [v2:172.21.15.167:6834/679747418,v1:172.21.15.167:6836/679747418] --> [v2:172.21.15.170:6816/6682,v1:172.21.15.170:6817/6682] -- osd_op(unknown.0.5:41412 3.5 3:b5d1c589:::10000009bc2.00000000:head [create,setxattr parent (99),setxattr layout (30)] snapc 0=[] ondisk+write+known_if_redirected+full_force e20) v8 -- 0x555e5fa4bb80 con 0x555e52d7a000 2019-03-07 22:25:01.153 7efd6c005700 10 mds.0.cache.strays eval_stray [dentry #0x100/stray6/10000009bc2 [2,head] auth (dversion lock) v=4642 ino=0x10000009bc2 state=1879048209|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c1c4fc0] 2019-03-07 22:25:01.153 7efd6c005700 10 mds.0.cache.strays inode is [inode 0x10000009bc2 [2,head] ~mds0/stray6/10000009bc2 auth v4642 ap=1 dirtyparent s=0 nl=0 n(v0 rc2019-03-07 22:24:26.391179 1=1+0) (iversion lock) | ptrwaiter=0 request=0 lock=0 caps=0 dirtyparent=1 dirty=1 authpin=1 0x555e5ddfa700] 2019-03-07 22:25:01.153 7efd6c005700 -1 mds.0.cache.strays Dentry [dentry #0x100/stray6/10000009bc2 [2,head] auth (dversion lock) v=4642 ino=0x10000009bc2 state=1879048193|new | request=0 lock=0 inodepin=1 dirty=1 authpin=0 0x555e5c1c4fc0] was purgeable but no longer is!
I think we can just remove the code that prints error
Updated by Zheng Yan about 5 years ago
The "behind on trimming" was caused by a frozen dirfrag. The dirfrag stayed in frozen state for a long time is because Migrator::handle_export_prep() took long time.
diff --git a/src/mds/Migrator.cc b/src/mds/Migrator.cc
index 180fb99b2d..59f721921c 100644
--- a/src/mds/Migrator.cc
+++ b/src/mds/Migrator.cc
@@ -2534,6 +2534,7 @@ void Migrator::handle_export_prep(const MExportDirPrep::const_ref &m, bool did_a
if (!bound) {
dout(7) << " opening bounding dirfrag " << leaf << " on " << *in << dendl;
cache->open_remote_dirfrag(in, leaf, cf.build());
+ // this may take long if there are lots of bounding dirfrags
return;
}
Updated by Zheng Yan about 5 years ago
- Status changed from New to Fix Under Review
Updated by Patrick Donnelly about 5 years ago
- Status changed from Fix Under Review to Pending Backport
Updated by Nathan Cutler about 5 years ago
- Copied to Backport #39221: luminous: mds: behind on trimming and "[dentry] was purgeable but no longer is!" added
Updated by Nathan Cutler about 5 years ago
- Copied to Backport #39222: nautilus: mds: behind on trimming and "[dentry] was purgeable but no longer is!" added
Updated by Nathan Cutler about 5 years ago
- Copied to Backport #39223: mimic: mds: behind on trimming and "[dentry] was purgeable but no longer is!" added
Updated by Xiaoxi Chen almost 5 years ago
It seems not a valid fix as this is not the only path to have the error.
We hit this in another way, not due to frozen and migration but due to client has caps.
2019-07-10 03:27:51.458 7fc882aac700 10 mds.9.cache.strays inode is [inode 0xa0001908553 [2,head] ~mds9/stray2/a0001908553 auth v12728687 s=7890291 nl=0 n(v0 rc2019-07-10 02:39:11.984908 b7890291 1=1+0) (iversion lock) caps={217702=pAsLsXsFscr/-@6} | ptrwaiter=0 request=0 lock=0 caps=1 dirtyparent=0 dirty=0 waiter=0 authpin=0 0x55a7342f9100]
2019-07-10 03:27:51.458 7fc882aac700 20 mds.9.cache.strays caps | leases
2019-07-10 03:27:51.458 7fc882aac700 -1 mds.9.cache.strays Dentry [dentry #0x109/stray2/a0001908553 [2,head] auth (dversion lock) v=12728687 ino=0xa0001908553 state=1342177280 | request=0 lock=0 inodepin=1 dirty=0 authpin=0 0x55a86e584f00] was purgeable but no longer is!
Updated by Xiaoxi Chen almost 5 years ago
root@cal-rno-mds-new-27:~# ceph daemon --cluster rno_ceph_cal mds.`hostname -s` dump inode 0xa0001908553
{
"path": "~mds9/stray2/a0001908553",
"ino": 10995142526291,
"rdev": 0,
"ctime": "2019-07-10 02:39:11.984908",
"btime": "2019-07-09 06:33:06.046917",
"mode": 33188,
"uid": 0,
"gid": 0,
"nlink": 0,
"dir_layout": {
"dir_hash": 0
},
"layout": {
"stripe_unit": 4194304,
"stripe_count": 1,
"object_size": 4194304,
"pool_id": 2,
"pool_ns": ""
},
"old_pools": [],
"size": 7890291,
"truncate_seq": 1,
"truncate_size": 18446744073709551615,
"truncate_from": 0,
"truncate_pending": 0,
"mtime": "2019-07-09 06:34:49.419935",
"atime": "2019-07-09 06:33:06.046917",
"time_warp_seq": 0,
"change_attr": 1,
"export_pin": -1,
"client_ranges": [],
"dirstat": {
"version": 0,
"mtime": "0.000000",
"num_files": 0,
"num_subdirs": 0
},
"rstat": {
"version": 0,
"rbytes": 7890291,
"rfiles": 1,
"rsubdirs": 0,
"rsnaps": 0,
"rctime": "2019-07-10 02:39:11.984908"
},
"accounted_rstat": {
"version": 0,
"rbytes": 7890291,
"rfiles": 1,
"rsubdirs": 0,
"rsnaps": 0,
"rctime": "2019-07-10 02:39:11.984908"
},
"version": 12728687,
"file_data_version": 0,
"xattr_version": 1,
"backtrace_version": 12728687,
"stray_prior_path": "ORIGNIAL_PATH_HIDDEN",
"symlink": "",
"old_inodes": [],
"dirfragtree": {
"splits": []
},
"is_auth": true,
"auth_state": {
"replicas": {}
},
"replica_state": {
"authority": [
9,
-2
],
"replica_nonce": 0
},
"auth_pins": 0,
"is_frozen": false,
"is_freezing": false,
"pins": {
"ptrwaiter": 0,
"request": 0,
"lock": 0,
"caps": 1,
"dirtyparent": 0,
"dirty": 0,
"waiter": 0,
"authpin": 0
},
"nref": 1,
"versionlock": {
"gather_set": [],
"is_leased": false,
"num_rdlocks": 0,
"num_wrlocks": 0,
"num_xlocks": 0,
"xlock_by": {}
},
"authlock": {},
"linklock": {},
"dirfragtreelock": {},
"filelock": {},
"xattrlock": {},
"snaplock": {},
"nestlock": {
"gather_set": [],
"is_leased": false,
"num_rdlocks": 0,
"num_wrlocks": 0,
"num_xlocks": 0,
"xlock_by": {}
},
"flocklock": {},
"policylock": {},
"states": [
"auth",
"notifyref",
"orphan"
],
"client_caps": [
{
"client_id": 217702,
"pending": "pAsLsXsFscr",
"issued": "pAsLsXsFscr",
"wanted": "-",
"last_sent": 6
}
],
"loner": -1,
"want_loner": -1,
"mds_caps_wanted": []
}
Updated by Zheng Yan almost 5 years ago
not big issue even inode becomes to have caps
Updated by Xiaoxi Chen almost 5 years ago
I think we need to try reclaim the caps in this case. I am seeing num_stray accumulated in my env due to the indoes have caps.
The clients that holding the caps are the cleanup clients --- i.e the one that trigger the unlink. What it does and only does is
find /import/ceph/callogs/ -maxdepth 3 -type f -name *.mul.gz -cmin +1200
so the fd should closed and caps can be released however it doesnt.
echo 3 > /proc/sys/vm/drop_caches on client side solve the issue, also shrink the #inodes in cache(fuse) from 1.7M down to 93k.
Updated by Xiaoxi Chen almost 5 years ago
Zheng Yan wrote:
is cephfs exported to nfs
No, it is ceph-fuse (13.2.5).
It seems like customer has ~10 nodes mounted same share, all do something like
"find /import/ceph/callogs/ -maxdepth 3 -type f -name *.mul.gz -cmin +1200 -exec rm -f {} + " but it is a hand written java application...
We did a change this afternoon that 1) reduce concurrent from 10 to 2; 2) change from fuse to kernel and is seeing positive result.
Also, reducing mds_max_caps_per_client helps. So it seems like the ll_forget in ceph-fuse is not get called from kernel to release caps for the deleted file?
Updated by Nathan Cutler over 4 years ago
- Status changed from Pending Backport to Resolved
While running with --resolve-parent, the script "backport-create-issue" noticed that all backports of this issue are in status "Resolved" or "Rejected".
Actions