Ceph » CephFS

Will come back for another pass and verify, but I assume this is the disconnected inode error.

Never mind that comment, I was just looking at the job it happened on, not the actual failure...

(gdb) f 4
#4  Client::verify_reply_trace (this=0x14c9800, r=0, request=<optimized out>, reply=<optimized out>, ptarget=0x7fff531f56d0, 
    pcreated=<optimized out>, uid=1000, gid=1000) at client/Client.cc:1192
warning: Source file is more recent than executable.
1192                           << d->dir->parent_inode->ino << "/" << d->name
(gdb) p d
$1 = (Dentry *) 0x87d0540
(gdb) p d->dir
$2 = (Dir *) 0x0
(gdb) list
1187            Dentry *od = request->old_dentry();
1188            if (od) {
1189              unlink(od, false);
1190            }
1191            ldout(cct, 10) << "make_request got traceless reply, looking up #" 
1192                           << d->dir->parent_inode->ino << "/" << d->name
1193                           << " got_ino " << got_created_ino
1194                           << " ino " << created_ino
1195                           << dendl;
1196            r = _do_lookup(d->dir->parent_inode, d->name, &target);

   -39> 2013-05-10 11:08:08.430881 7f74ebd36780  3 client.4119 ll_rename 1000000019a.head lf3 to 1000000055b.head l115
   -38> 2013-05-10 11:08:08.430885 7f74ebd36780  3 client.4119 _rename(1000000019a lf3 to 1000000055b l115 uid 1000 gid 1000)
   -37> 2013-05-10 11:08:08.430898 7f74ebd36780 10 client.4119 _lookup 1000000019a.head(ref=3 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:47.154205 caps=pAsLsXsFsx(0=pAsLsXsFsx) parents=0x150b1c0 0x4085200) lf3 = 10000000607.head(ref=2 cap_refs={} open={} mode=120777 size=3976 mtime=2013-05-10 11:07:29.937344 caps=pAsLsXsFscr(0=pAsLsXsFscr) parents=0x14dacb0 0xb579d80)
   -36> 2013-05-10 11:08:08.430919 7f74ebd36780 10 client.4119 _do_lookup on #1000000055b/l115
   -35> 2013-05-10 11:08:08.430923 7f74ebd36780 10 client.4119 choose_target_mds from caps on inode 1000000055b.head(ref=4 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:06.822166 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x17a8620 0x408b200)
   -34> 2013-05-10 11:08:08.430932 7f74ebd36780 10 client.4119 send_request rebuilding request 13041 for mds.0
   -33> 2013-05-10 11:08:08.430936 7f74ebd36780 10 client.4119 send_request client_request(unknown.0:13041 lookup #1000000055b/l115) v1 to mds.0
   -32> 2013-05-10 11:08:08.430940 7f74ebd36780  1 -- 10.214.131.6:0/1129 --> 10.214.131.2:6809/2142 -- client_request(client.4119:13041 lookup #1000000055b/l115) v1 -- ?+0 0x26f4c80 con 0x14c8c60
   -31> 2013-05-10 11:08:08.431817 7f74e617b700  1 -- 10.214.131.6:0/1129 <== mds.0 10.214.131.2:6809/2142 27267 ==== client_reply(???:13041 = -2 No such file or directory) v1 ==== 342+0+0 (3526930164 0 0) 0x6721600 con 0x14c8c60
   -30> 2013-05-10 11:08:08.431853 7f74e617b700 10 client.4119 insert_trace from 2013-05-10 11:08:08.430935 mds.0 is_target=0 is_dentry=1
   -29> 2013-05-10 11:08:08.431876 7f74e617b700 10 client.4119  features 0xffffffff
   -28> 2013-05-10 11:08:08.431880 7f74e617b700 10 client.4119 update_snap_trace len 48
   -27> 2013-05-10 11:08:08.431884 7f74e617b700 10 client.4119 update_snap_trace snaprealm(1 nref=1805 c=0 seq=1 parent=0 my_snaps=[] cached_snapc=1=[]) seq 1 <= 1 and same parent, SKIPPING
   -26> 2013-05-10 11:08:08.431891 7f74e617b700 10 client.4119  hrm  is_target=0 is_dentry=1
   -25> 2013-05-10 11:08:08.431899 7f74e617b700 10 client.4119 update_inode_file_bits 1000000055b.head(ref=4 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:06.822166 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x17a8620 0x408b200) pAsLsXsFs mtime 2013-05-10 11:07:06.822166
   -24> 2013-05-10 11:08:08.431925 7f74e617b700 10 client.4119 add_update_cap issued pAsLsXsFs -> pAsLsXsFs from mds.0 on 1000000055b.head(ref=4 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:06.822166 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x17a8620 0x408b200)
   -23> 2013-05-10 11:08:08.431947 7f74e617b700 10 client.4119  marking I_COMPLETE on empty dir 1000000055b.head(ref=4 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:06.822166 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x17a8620 0x408b200)
   -22> 2013-05-10 11:08:08.431963 7f74e617b700 10 client.4119  dir is open on empty dir 1000000055b with 1 entries, tearing down
   -21> 2013-05-10 11:08:08.431970 7f74e617b700 10 client.4119 put_inode on 1000000055b.head(ref=4 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:06.822166 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x17a8620 0x408b200)
   -20> 2013-05-10 11:08:08.432072 7f74ebd36780 10 client.4119 _do_lookup res is -2
   -19> 2013-05-10 11:08:08.432081 7f74ebd36780 10 client.4119 _lookup 1000000055b.head(ref=3 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:06.822166 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x17a8620 0x408b200) l115 = -2
   -18> 2013-05-10 11:08:08.432099 7f74ebd36780 10 client.4119 choose_target_mds from caps on inode 1000000055b.head(ref=4 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:06.822166 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x17a8620 0x408b200)
   -17> 2013-05-10 11:08:08.432111 7f74ebd36780 10 client.4119 send_request rebuilding request 13042 for mds.0
   -16> 2013-05-10 11:08:08.432117 7f74ebd36780 10 client.4119 send_request client_request(unknown.0:13042 rename #1000000055b/l115 #1000000019a/lf3) v1 to mds.0
   -15> 2013-05-10 11:08:08.432121 7f74ebd36780  1 -- 10.214.131.6:0/1129 --> 10.214.131.2:6809/2142 -- client_request(client.4119:13042 rename #1000000055b/l115 #1000000019a/lf3) v1 -- ?+0 0x163d500 con 0x14c8c60
   -14> 2013-05-10 11:08:08.436479 7f74e617b700  1 -- 10.214.131.6:0/1129 <== mds.0 10.214.131.2:6809/2142 27268 ==== client_caps(revoke ino 1000000055b 1373 seq 8 caps=pAsLsXs dirty=- wanted=- follows 0 size 0/0 ts 1 mtime 2013-05-10 11:07:06.822166) v2 ==== 180+0+0 (2525723597 0 0) 0x14db680 con 0x14c8c60
   -13> 2013-05-10 11:08:08.436522 7f74e617b700 10 client.4119  mds.0 seq now 11088
   -12> 2013-05-10 11:08:08.436529 7f74e617b700  5 client.4119 handle_cap_grant on in 1000000055b mds.0 seq 8 caps now pAsLsXs was pAsLsXsFs
   -11> 2013-05-10 11:08:08.436539 7f74e617b700 10 client.4119 update_inode_file_bits 1000000055b.head(ref=3 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:06.822166 caps=pAsLsXsFs(0=pAsLsXsFs) COMPLETE parents=0x17a8620 0x408b200) pAsLsXsFs mtime 2013-05-10 11:07:06.822166
   -10> 2013-05-10 11:08:08.436561 7f74e617b700 10 client.4119   revocation of Fs
    -9> 2013-05-10 11:08:08.436565 7f74e617b700 10 client.4119 check_caps on 1000000055b.head(ref=3 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:06.822166 caps=pAsLsXs(0=pAsLsXs) COMPLETE parents=0x17a8620 0x408b200) wanted - used - is_delayed=1
    -8> 2013-05-10 11:08:08.436582 7f74e617b700 10 client.4119  cap mds.0 issued pAsLsXs implemented pAsLsXsFs revoking Fs
    -7> 2013-05-10 11:08:08.436591 7f74e617b700 10 client.4119 completed revocation of Fs
    -6> 2013-05-10 11:08:08.436594 7f74e617b700 10 client.4119 send_cap 1000000055b.head(ref=3 cap_refs={} open={} mode=40777 size=0 mtime=2013-05-10 11:07:06.822166 caps=pAsLsXs(0=pAsLsXs) COMPLETE parents=0x17a8620 0x408b200) mds.0 seq 8 used - want - flush - retain pAsLsXs held pAsLsXsFs revoking Fs dropping -
    -5> 2013-05-10 11:08:08.436620 7f74e617b700  1 -- 10.214.131.6:0/1129 --> 10.214.131.2:6809/2142 -- client_caps(update ino 1000000055b 1373 seq 8 caps=pAsLsXs dirty=- wanted=- follows 0 size 0/0 ts 1 mtime 2013-05-10 11:07:06.822166) v2 -- ?+0 0xe5659c0 con 0x14c8c60
    -4> 2013-05-10 11:08:08.441635 7f74e617b700  1 -- 10.214.131.6:0/1129 <== mds.0 10.214.131.2:6809/2142 27269 ==== client_reply(???:13042 = 0 Success unsafe) v1 ==== 27+0+0 (4152072573 0 0) 0x1db28c0 con 0x14c8c60
    -3> 2013-05-10 11:08:08.441671 7f74e617b700 10 client.4119 insert_trace from 2013-05-10 11:08:08.432117 mds.0 is_target=0 is_dentry=0
    -2> 2013-05-10 11:08:08.441694 7f74e617b700 10 client.4119 insert_trace -- no trace
    -1> 2013-05-10 11:08:08.441785 7f74ebd36780 10 client.4119 put_inode on 10000000607.head(ref=3 cap_refs={} open={} mode=120777 size=3976 mtime=2013-05-10 11:07:29.937344 caps=pAsXsFscr(0=pAsXsFscr) 0xb579d80)
     0> 2013-05-10 11:08:08.447540 7f74ebd36780 -1 *** Caught signal (Segmentation fault) **
 in thread 7f74ebd36780

it looks like the insert_trace() on the lookup unlinked the dentry..

500 passes of the job on commit:1f65594c23309b527d74afe648c888c69a3c2acd wip-5021

btw wip-5021 still hasn't merged because it failed the smbtorture test. i'll rebase on master and retest to see where we are at.

hit this again,

warning: Can't read pathname for load map: Input/output error.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `ceph-fuse -f --name client.0 /home/ubuntu/cephtest/108820/mnt.0'.
Program terminated with signal 11, Segmentation fault.
#0  0x00007f46471e7b7b in raise (sig=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/pt-raise.c:42
42      ../nptl/sysdeps/unix/sysv/linux/pt-raise.c: No such file or directory.
(gdb) bt
#0  0x00007f46471e7b7b in raise (sig=<optimized out>) at ../nptl/sysdeps/unix/sysv/linux/pt-raise.c:42
#1  0x00000000007a065e in reraise_fatal (signum=11) at global/signal_handler.cc:59
#2  handle_fatal_signal (signum=11) at global/signal_handler.cc:105
#3  <signal handler called>
#4  Client::verify_reply_trace (this=0x21d9800, r=0, request=<optimized out>, reply=<optimized out>, ptarget=0x7fff2e2420d0, pcreated=<optimized out>, uid=1000, gid=1000) at client/Client.cc:1199
#5  0x000000000055064a in Client::make_request (this=0x21d9800, request=0xe07e600, uid=1000, gid=1000, ptarget=0x7fff2e2420d0, pcreated=0x0, use_mds=-1, pdirbl=0x0) at client/Client.cc:1349
#6  0x00000000005654b5 in Client::_rename (this=0x21d9800, fromdir=0x95a7b00, fromname=0x21fc030 "f5a", todir=0x9483480, toname=0x21fc034 "f72", uid=1000, gid=1000) at client/Client.cc:7414
#7  0x0000000000565905 in Client::ll_rename (this=0x21d9800, parent=..., name=0x21fc030 "f5a", newparent=..., newname=0x21fc034 "f72", uid=1000, gid=1000) at client/Client.cc:7442
#8  0x00000000005277ab in fuse_ll_rename (req=0x90f4500, parent=1099511628160, name=0x21fc030 "f5a", newparent=<optimized out>, newname=0x21fc034 "f72") at client/fuse_ll.cc:302
#9  0x00007f4647405d65 in fuse_session_loop () from /lib/libfuse.so.2
#10 0x000000000052462c in main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>) at ceph_fuse.cc:165
(gdb) f 4
#4  Client::verify_reply_trace (this=0x21d9800, r=0, request=<optimized out>, reply=<optimized out>, ptarget=0x7fff2e2420d0, pcreated=<optimized out>, uid=1000, gid=1000) at client/Client.cc:1199
1199    client/Client.cc: No such file or directory.
(gdb) p d
$1 = (Dentry *) 0x4e02b60
(gdb) p d->dir
$2 = (Dir *) 0x0
(gdb) q

ubuntu@teuthology:/var/lib/teuthworker/archive/sage-2013-08-15_22:21:52-fs-wip-fallocate-testing-basic-plana/108820$ cat orig.config.yaml 
kernel:
  kdb: true
  sha1: 68d04c9a036bea12d76fdd51e926aef771e8e041
machine_type: plana
nuke-on-error: true
os_type: ubuntu
overrides:
  admin_socket:
    branch: wip-fallocate
  ceph:
    conf:
      client:
        debug client: 10
      mds:
        debug mds: 20
        debug ms: 1
        mds inject traceless reply probability: 0.5
      mon:
        debug mon: 20
        debug ms: 1
        debug paxos: 20
      osd:
        osd op thread timeout: 60
    fs: btrfs
    log-whitelist:
    - slow request
    - wrongly marked me down
    sha1: 7512c2982af890e444e81237fd05c41d3390f9fe
  ceph-deploy:
    branch:
      dev: wip-fallocate
    conf:
      client:
        log file: /var/log/ceph/ceph-$name.$pid.log
      mon:
        debug mon: 1
        debug ms: 20
        debug paxos: 20
  install:
    ceph:
      sha1: 7512c2982af890e444e81237fd05c41d3390f9fe
  s3tests:
    branch: master
  workunit:
    sha1: 7512c2982af890e444e81237fd05c41d3390f9fe
roles:
- - mon.a
  - mon.c
  - osd.0
  - osd.1
  - osd.2
- - mon.b
  - mds.a
  - osd.3
  - osd.4
  - osd.5
- - client.0
tasks:
- chef: null
- clock.check: null
- install: null
- ceph: null
- ceph-fuse: null
- workunit:
    clients:
      all:
      - suites/fsstress.sh
teuthology_branch: master

What's the status of wip-5021?