Project

General

Profile

Bug #38679

mds: behind on trimming and "[dentry] was purgeable but no longer is!"

Added by Patrick Donnelly 4 months ago. Updated 3 months ago.

Status:
Pending Backport
Priority:
High
Assignee:
Category:
-
Target version:
Start date:
Due date:
% 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:

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


Related issues

Copied to fs - Backport #39221: luminous: mds: behind on trimming and "[dentry] was purgeable but no longer is!" In Progress
Copied to fs - Backport #39222: nautilus: mds: behind on trimming and "[dentry] was purgeable but no longer is!" Resolved
Copied to fs - Backport #39223: mimic: mds: behind on trimming and "[dentry] was purgeable but no longer is!" New

History

#1 Updated by Zheng Yan 3 months 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

#2 Updated by Zheng Yan 3 months 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;
        }

#3 Updated by Zheng Yan 3 months ago

  • Pull request ID set to 27051

#4 Updated by Zheng Yan 3 months ago

  • Status changed from New to Need Review

#5 Updated by Patrick Donnelly 3 months ago

  • Status changed from Need Review to Pending Backport

#6 Updated by Nathan Cutler 3 months ago

  • Copied to Backport #39221: luminous: mds: behind on trimming and "[dentry] was purgeable but no longer is!" added

#7 Updated by Nathan Cutler 3 months ago

  • Copied to Backport #39222: nautilus: mds: behind on trimming and "[dentry] was purgeable but no longer is!" added

#8 Updated by Nathan Cutler 3 months ago

  • Copied to Backport #39223: mimic: mds: behind on trimming and "[dentry] was purgeable but no longer is!" added

Also available in: Atom PDF