- ceph-users - lists.ceph.io

Re: Luminous 12.2.12 - filestore OSDs take an hour to boot
by Eric Smith 10 Jul '20

10 Jul '20

For what it's worth - all of our objects are generating LONG named object files like so... \uABCD\ucontent.\srecording\swzdchd\u\utnda-trg-1008007-wzdchd-216203706303281120-230932949-1593482400-159348660000000001\swzdchd\u\utpc2-tp1-1008007-wzdchd-216203706303281120-230932949-1593482400-159348660000000001\u\uwzdchd3._0bfd7c716b839cb7b3ad_0_long Does this matter? AFAICT it sees this as a long file name and has to lookup the object name in the xattrs ? Is that bad? -----Original Message----- From: Eric Smith <Eric.Smith(a)vecima.com> Sent: Friday, July 10, 2020 6:59 AM To: ceph-users(a)ceph.io Subject: [ceph-users] Luminous 12.2.12 - filestore OSDs take an hour to boot I have a cluster running Luminous 12.2.12 with Filestore and it takes my OSDs somewhere around an hour to start (They do start successfully - eventually). I have the following log entries that seem to show the OSD process attempting to descend into the PG directory on disk and create an object list of some sort: 2020-07-09 18:29:28.017207 7f3b680afd80 20 osd.1 137390 clearing temps in 8.14ads3_head pgid 8.14ads3 2020-07-09 18:29:28.017211 7f3b680afd80 20 filestore(/var/lib/ceph/osd/ceph-1) collection_list(5012): pool is 8 shard is 3 pgid 8.14ads3 2020-07-09 18:29:28.017213 7f3b680afd80 10 filestore(/var/lib/ceph/osd/ceph-1) collection_list(5020): first checking temp pool 2020-07-09 18:29:28.017215 7f3b680afd80 20 filestore(/var/lib/ceph/osd/ceph-1) collection_list(5012): pool is -10 shard is 3 pgid 8.14ads3 2020-07-09 18:29:28.017221 7f3b680afd80 20 _collection_list_partial start:GHMIN end:GHMAX-64 ls.size 0 2020-07-09 18:29:28.017263 7f3b680afd80 20 filestore(/var/lib/ceph/osd/ceph-1) objects: [] 2020-07-09 18:29:28.017268 7f3b680afd80 10 filestore(/var/lib/ceph/osd/ceph-1) collection_list(5028): fall through to non-temp collection, start 3#-1:00000000::::0# 2020-07-09 18:29:28.017272 7f3b680afd80 20 _collection_list_partial start:3#-1:00000000::::0# end:GHMAX-64 ls.size 0 2020-07-09 18:29:28.038124 7f3b680afd80 20 list_by_hash_bitwise prefix D 2020-07-09 18:29:28.058679 7f3b680afd80 20 list_by_hash_bitwise prefix DA 2020-07-09 18:29:28.069432 7f3b680afd80 20 list_by_hash_bitwise prefix DA4 2020-07-09 18:29:29.789598 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(4010): woke after 5.000074 2020-07-09 18:29:29.789634 7f3b51a87700 10 journal commit_start max_applied_seq 53085082, open_ops 0 2020-07-09 18:29:29.789639 7f3b51a87700 10 journal commit_start blocked, all open_ops have completed 2020-07-09 18:29:29.789641 7f3b51a87700 10 journal commit_start nothing to do 2020-07-09 18:29:29.789663 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(3994): waiting for max_interval 5.000000 2020-07-09 18:29:34.789815 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(4010): woke after 5.000109 2020-07-09 18:29:34.789898 7f3b51a87700 10 journal commit_start max_applied_seq 53085082, open_ops 0 2020-07-09 18:29:34.789902 7f3b51a87700 10 journal commit_start blocked, all open_ops have completed 2020-07-09 18:29:34.789906 7f3b51a87700 10 journal commit_start nothing to do 2020-07-09 18:29:34.789939 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(3994): waiting for max_interval 5.000000 2020-07-09 18:29:38.651689 7f3b680afd80 20 list_by_hash_bitwise prefix DA41 2020-07-09 18:29:39.790069 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(4010): woke after 5.000128 2020-07-09 18:29:39.790090 7f3b51a87700 10 journal commit_start max_applied_seq 53085082, open_ops 0 2020-07-09 18:29:39.790092 7f3b51a87700 10 journal commit_start blocked, all open_ops have completed 2020-07-09 18:29:39.790093 7f3b51a87700 10 journal commit_start nothing to do 2020-07-09 18:29:39.790102 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(3994): waiting for max_interval 5.000000 2020-07-09 18:29:44.790200 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(4010): woke after 5.000095 2020-07-09 18:29:44.790256 7f3b51a87700 10 journal commit_start max_applied_seq 53085082, open_ops 0 2020-07-09 18:29:44.790265 7f3b51a87700 10 journal commit_start blocked, all open_ops have completed 2020-07-09 18:29:44.790268 7f3b51a87700 10 journal commit_start nothing to do 2020-07-09 18:29:44.790286 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(3994): waiting for max_interval 5.000000 2020-07-09 18:29:49.790353 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(4010): woke after 5.000066 2020-07-09 18:29:49.790374 7f3b51a87700 10 journal commit_start max_applied_seq 53085082, open_ops 0 2020-07-09 18:29:49.790376 7f3b51a87700 10 journal commit_start blocked, all open_ops have completed 2020-07-09 18:29:49.790378 7f3b51a87700 10 journal commit_start nothing to do 2020-07-09 18:29:49.790387 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(3994): waiting for max_interval 5.000000 2020-07-09 18:29:50.564479 7f3b680afd80 20 list_by_hash_bitwise prefix DA410000 2020-07-09 18:29:50.564501 7f3b680afd80 20 list_by_hash_bitwise prefix DA410000 ob 3#8:b5280000::::head# 2020-07-09 18:29:50.564508 7f3b680afd80 20 list_by_hash_bitwise prefix DA41002A Any idea what's going on here? I can run a find of every file on the filesystem in under 12 minutes so I'm not sure what's taking so long. _______________________________________________ ceph-users mailing list -- ceph-users(a)ceph.io To unsubscribe send an email to ceph-users-leave(a)ceph.io

1 0

A MON doesn't start after Octopus update
by Hervé Ballans 10 Jul '20

10 Jul '20

Hi, We encounter a strange issue on one of our Ceph cluster. Cluster has been running with no concerns since many years. But recently, after an upgrade from Octopus 15.2.1 to 15.2.4, all is OK but one of the 3 MON refuses to start ! Journalctl shows some problems regarding the RocksDBStore and a problem of Bad table magic number. On the other nodes, MONs start correctly, and all other services too, MDS, MGR and OSD (just we have 2 OSDs stopped due to hardware disk problem). Some OSD are nearfull but I don't think there is a link with the MON issue ?.. Could someone help me on this issue please ? Thnks in advance, Hervé Here are few logs : # ceph versions { "mon": { "ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable)": 3 }, "mgr": { "ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable)": 3 }, "osd": { "ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable)": 131 }, "mds": { "ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable)": 3 }, "overall": { "ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable)": 140 } } # ceph -s cluster: id: 00ff6861-f95c-4740-a570-da6ad6a261cd health: HEALTH_WARN 1/3 mons down, quorum inf-ceph-mds,cluster-r730-k80-1 8 backfillfull osd(s) 18 nearfull osd(s) Low space hindering backfill (add storage if this doesn't resolve itself): 21 pgs backfill_toofull Degraded data redundancy: 5570/50534523 objects degraded (0.011%), 2 pgs degraded, 2 pgs undersized 2 pool(s) backfillfull 1 pool(s) nearfull 25 daemons have recently crashed services: mon: 3 daemons, quorum inf-ceph-mds,cluster-r730-k80-1 (age 44h), out of quorum: cluster-r820-1 mgr: cluster-r730-k80-1(active, since 44h), standbys: inf-ceph-mds, cluster-r820-1 mds: cephfs_cluster:2 {0=cluster-r730-k80-1=up:active,1=inf-ceph-mds=up:active} 1 up:standby osd: 133 osds: 131 up (since 42h), 131 in (since 42h); 21 remapped pgs task status: scrub status: mds.cluster-r730-k80-1: idle mds.inf-ceph-mds: idle data: pools: 3 pools, 4129 pgs objects: 16.84M objects, 47 TiB usage: 143 TiB used, 33 TiB / 176 TiB avail pgs: 5570/50534523 objects degraded (0.011%) 75039/50534523 objects misplaced (0.148%) 4104 active+clean 19 active+remapped+backfill_toofull 3 active+clean+scrubbing+deep 2 active+undersized+degraded+remapped+backfill_toofull 1 active+clean+scrubbing io: client: 19 MiB/s rd, 26 MiB/s wr, 5 op/s rd, 11 op/s wr # systemctl status ceph-mon(a)cluster-r820-1.service ● ceph-mon(a)cluster-r820-1.service - Ceph cluster monitor daemon Loaded: loaded (/lib/systemd/system/ceph-mon@.service; enabled; vendor preset: enabled) Active: failed (Result: signal) since Fri 2020-07-10 11:44:33 CEST; 24min ago Process: 201002 ExecStart=/usr/bin/ceph-mon -f --cluster ${CLUSTER} --id cluster-r820-1 --setuser ceph --setgroup ceph (code=killed, signal=ABRT) Main PID: 201002 (code=killed, signal=ABRT) Jul 10 11:44:33 cluster-r820-1 systemd[1]: ceph-mon(a)cluster-r820-1.service: Service RestartSec=10s expired, scheduling restart. Jul 10 11:44:33 cluster-r820-1 systemd[1]: ceph-mon(a)cluster-r820-1.service: Scheduled restart job, restart counter is at 5. Jul 10 11:44:33 cluster-r820-1 systemd[1]: Stopped Ceph cluster monitor daemon. Jul 10 11:44:33 cluster-r820-1 systemd[1]: ceph-mon(a)cluster-r820-1.service: Start request repeated too quickly. Jul 10 11:44:33 cluster-r820-1 systemd[1]: ceph-mon(a)cluster-r820-1.service: Failed with result 'signal'. Jul 10 11:44:33 cluster-r820-1 systemd[1]: Failed to start Ceph cluster monitor daemon. # journalctl --follow Jul 10 11:43:38 cluster-r820-1 systemd[1]: Started Ceph cluster monitor daemon. Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: /build/ceph-15.2.4/src/kv/RocksDBStore.cc: In function 'virtual int RocksDBStore::get(const string&, const string&, ceph::bufferlist*)' thread 7fe5331a65c0 time 2020-07-10T11:43:39.192838+0200 Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: /build/ceph-15.2.4/src/kv/RocksDBStore.cc: 1152: ceph_abort_msg("Bad table magic number: expected 9863518390377041911, found 5836668660487291005 in /var/lib/ceph/mon/ceph-cluster-r820-1/store.db/716151.sst") Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable) Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 1: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0xe1) [0x7fe534aea7c6] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 2: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, ceph::buffer::v15_2_0::list*)+0x3ce) [0x559f6081b2ae] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 3: (main()+0x108d) [0x559f605a85fd] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 4: (__libc_start_main()+0xeb) [0x7fe5336ba09b] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 5: (_start()+0x2a) [0x559f605b93da] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: *** Caught signal (Aborted) ** Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: in thread 7fe5331a65c0 thread_name:ceph-mon Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 2020-07-10T11:43:39.192+0200 7fe5331a65c0 -1 /build/ceph-15.2.4/src/kv/RocksDBStore.cc: In function 'virtual int RocksDBStore::get(const string&, const string&, ceph::bufferlist*)' thread 7fe5331a65c0 time 2020-07-10T11:43:39.192838+0200 Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: /build/ceph-15.2.4/src/kv/RocksDBStore.cc: 1152: ceph_abort_msg("Bad table magic number: expected 9863518390377041911, found 5836668660487291005 in /var/lib/ceph/mon/ceph-cluster-r820-1/store.db/716151.sst") Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable) Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 1: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0xe1) [0x7fe534aea7c6] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 2: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, ceph::buffer::v15_2_0::list*)+0x3ce) [0x559f6081b2ae] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 3: (main()+0x108d) [0x559f605a85fd] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 4: (__libc_start_main()+0xeb) [0x7fe5336ba09b] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 5: (_start()+0x2a) [0x559f605b93da] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable) Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 1: (()+0x12730) [0x7fe533bea730] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 2: (gsignal()+0x10b) [0x7fe5336cd7bb] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 3: (abort()+0x121) [0x7fe5336b8535] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 4: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0x1b2) [0x7fe534aea897] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 5: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, ceph::buffer::v15_2_0::list*)+0x3ce) [0x559f6081b2ae] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 6: (main()+0x108d) [0x559f605a85fd] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 7: (__libc_start_main()+0xeb) [0x7fe5336ba09b] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 8: (_start()+0x2a) [0x559f605b93da] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 2020-07-10T11:43:39.196+0200 7fe5331a65c0 -1 *** Caught signal (Aborted) ** Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: in thread 7fe5331a65c0 thread_name:ceph-mon Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable) Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 1: (()+0x12730) [0x7fe533bea730] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 2: (gsignal()+0x10b) [0x7fe5336cd7bb] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 3: (abort()+0x121) [0x7fe5336b8535] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 4: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0x1b2) [0x7fe534aea897] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 5: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, ceph::buffer::v15_2_0::list*)+0x3ce) [0x559f6081b2ae] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 6: (main()+0x108d) [0x559f605a85fd] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 7: (__libc_start_main()+0xeb) [0x7fe5336ba09b] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 8: (_start()+0x2a) [0x559f605b93da] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: -1> 2020-07-10T11:43:39.192+0200 7fe5331a65c0 -1 /build/ceph-15.2.4/src/kv/RocksDBStore.cc: In function 'virtual int RocksDBStore::get(const string&, const string&, ceph::bufferlist*)' thread 7fe5331a65c0 time 2020-07-10T11:43:39.192838+0200 Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: /build/ceph-15.2.4/src/kv/RocksDBStore.cc: 1152: ceph_abort_msg("Bad table magic number: expected 9863518390377041911, found 5836668660487291005 in /var/lib/ceph/mon/ceph-cluster-r820-1/store.db/716151.sst") Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable) Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 1: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0xe1) [0x7fe534aea7c6] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 2: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, ceph::buffer::v15_2_0::list*)+0x3ce) [0x559f6081b2ae] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 3: (main()+0x108d) [0x559f605a85fd] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 4: (__libc_start_main()+0xeb) [0x7fe5336ba09b] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 5: (_start()+0x2a) [0x559f605b93da] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 0> 2020-07-10T11:43:39.196+0200 7fe5331a65c0 -1 *** Caught signal (Aborted) ** Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: in thread 7fe5331a65c0 thread_name:ceph-mon Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable) Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 1: (()+0x12730) [0x7fe533bea730] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 2: (gsignal()+0x10b) [0x7fe5336cd7bb] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 3: (abort()+0x121) [0x7fe5336b8535] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 4: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0x1b2) [0x7fe534aea897] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 5: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, ceph::buffer::v15_2_0::list*)+0x3ce) [0x559f6081b2ae] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 6: (main()+0x108d) [0x559f605a85fd] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 7: (__libc_start_main()+0xeb) [0x7fe5336ba09b] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 8: (_start()+0x2a) [0x559f605b93da] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: -1> 2020-07-10T11:43:39.192+0200 7fe5331a65c0 -1 /build/ceph-15.2.4/src/kv/RocksDBStore.cc: In function 'virtual int RocksDBStore::get(const string&, const string&, ceph::bufferlist*)' thread 7fe5331a65c0 time 2020-07-10T11:43:39.192838+0200 Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: /build/ceph-15.2.4/src/kv/RocksDBStore.cc: 1152: ceph_abort_msg("Bad table magic number: expected 9863518390377041911, found 5836668660487291005 in /var/lib/ceph/mon/ceph-cluster-r820-1/store.db/716151.sst") Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable) Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 1: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0xe1) [0x7fe534aea7c6] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 2: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, ceph::buffer::v15_2_0::list*)+0x3ce) [0x559f6081b2ae] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 3: (main()+0x108d) [0x559f605a85fd] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 4: (__libc_start_main()+0xeb) [0x7fe5336ba09b] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 5: (_start()+0x2a) [0x559f605b93da] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 0> 2020-07-10T11:43:39.196+0200 7fe5331a65c0 -1 *** Caught signal (Aborted) ** Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: in thread 7fe5331a65c0 thread_name:ceph-mon Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: ceph version 15.2.4 (7447c15c6ff58d7fce91843b705a268a1917325c) octopus (stable) Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 1: (()+0x12730) [0x7fe533bea730] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 2: (gsignal()+0x10b) [0x7fe5336cd7bb] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 3: (abort()+0x121) [0x7fe5336b8535] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 4: (ceph::__ceph_abort(char const*, int, char const*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&)+0x1b2) [0x7fe534aea897] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 5: (RocksDBStore::get(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, ceph::buffer::v15_2_0::list*)+0x3ce) [0x559f6081b2ae] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 6: (main()+0x108d) [0x559f605a85fd] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 7: (__libc_start_main()+0xeb) [0x7fe5336ba09b] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: 8: (_start()+0x2a) [0x559f605b93da] Jul 10 11:43:39 cluster-r820-1 ceph-mon[200827]: NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this. Jul 10 11:43:39 cluster-r820-1 systemd[1]: ceph-mon(a)cluster-r820-1.service: Main process exited, code=killed, status=6/ABRT Jul 10 11:43:39 cluster-r820-1 systemd[1]: ceph-mon(a)cluster-r820-1.service: Failed with result 'signal'. Jul 10 11:43:49 cluster-r820-1 systemd[1]: ceph-mon(a)cluster-r820-1.service: Service RestartSec=10s expired, scheduling restart. ...

2 2

Luminous 12.2.12 - filestore OSDs take an hour to boot
by Eric Smith 10 Jul '20

10 Jul '20

I have a cluster running Luminous 12.2.12 with Filestore and it takes my OSDs somewhere around an hour to start (They do start successfully - eventually). I have the following log entries that seem to show the OSD process attempting to descend into the PG directory on disk and create an object list of some sort: 2020-07-09 18:29:28.017207 7f3b680afd80 20 osd.1 137390 clearing temps in 8.14ads3_head pgid 8.14ads3 2020-07-09 18:29:28.017211 7f3b680afd80 20 filestore(/var/lib/ceph/osd/ceph-1) collection_list(5012): pool is 8 shard is 3 pgid 8.14ads3 2020-07-09 18:29:28.017213 7f3b680afd80 10 filestore(/var/lib/ceph/osd/ceph-1) collection_list(5020): first checking temp pool 2020-07-09 18:29:28.017215 7f3b680afd80 20 filestore(/var/lib/ceph/osd/ceph-1) collection_list(5012): pool is -10 shard is 3 pgid 8.14ads3 2020-07-09 18:29:28.017221 7f3b680afd80 20 _collection_list_partial start:GHMIN end:GHMAX-64 ls.size 0 2020-07-09 18:29:28.017263 7f3b680afd80 20 filestore(/var/lib/ceph/osd/ceph-1) objects: [] 2020-07-09 18:29:28.017268 7f3b680afd80 10 filestore(/var/lib/ceph/osd/ceph-1) collection_list(5028): fall through to non-temp collection, start 3#-1:00000000::::0# 2020-07-09 18:29:28.017272 7f3b680afd80 20 _collection_list_partial start:3#-1:00000000::::0# end:GHMAX-64 ls.size 0 2020-07-09 18:29:28.038124 7f3b680afd80 20 list_by_hash_bitwise prefix D 2020-07-09 18:29:28.058679 7f3b680afd80 20 list_by_hash_bitwise prefix DA 2020-07-09 18:29:28.069432 7f3b680afd80 20 list_by_hash_bitwise prefix DA4 2020-07-09 18:29:29.789598 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(4010): woke after 5.000074 2020-07-09 18:29:29.789634 7f3b51a87700 10 journal commit_start max_applied_seq 53085082, open_ops 0 2020-07-09 18:29:29.789639 7f3b51a87700 10 journal commit_start blocked, all open_ops have completed 2020-07-09 18:29:29.789641 7f3b51a87700 10 journal commit_start nothing to do 2020-07-09 18:29:29.789663 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(3994): waiting for max_interval 5.000000 2020-07-09 18:29:34.789815 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(4010): woke after 5.000109 2020-07-09 18:29:34.789898 7f3b51a87700 10 journal commit_start max_applied_seq 53085082, open_ops 0 2020-07-09 18:29:34.789902 7f3b51a87700 10 journal commit_start blocked, all open_ops have completed 2020-07-09 18:29:34.789906 7f3b51a87700 10 journal commit_start nothing to do 2020-07-09 18:29:34.789939 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(3994): waiting for max_interval 5.000000 2020-07-09 18:29:38.651689 7f3b680afd80 20 list_by_hash_bitwise prefix DA41 2020-07-09 18:29:39.790069 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(4010): woke after 5.000128 2020-07-09 18:29:39.790090 7f3b51a87700 10 journal commit_start max_applied_seq 53085082, open_ops 0 2020-07-09 18:29:39.790092 7f3b51a87700 10 journal commit_start blocked, all open_ops have completed 2020-07-09 18:29:39.790093 7f3b51a87700 10 journal commit_start nothing to do 2020-07-09 18:29:39.790102 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(3994): waiting for max_interval 5.000000 2020-07-09 18:29:44.790200 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(4010): woke after 5.000095 2020-07-09 18:29:44.790256 7f3b51a87700 10 journal commit_start max_applied_seq 53085082, open_ops 0 2020-07-09 18:29:44.790265 7f3b51a87700 10 journal commit_start blocked, all open_ops have completed 2020-07-09 18:29:44.790268 7f3b51a87700 10 journal commit_start nothing to do 2020-07-09 18:29:44.790286 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(3994): waiting for max_interval 5.000000 2020-07-09 18:29:49.790353 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(4010): woke after 5.000066 2020-07-09 18:29:49.790374 7f3b51a87700 10 journal commit_start max_applied_seq 53085082, open_ops 0 2020-07-09 18:29:49.790376 7f3b51a87700 10 journal commit_start blocked, all open_ops have completed 2020-07-09 18:29:49.790378 7f3b51a87700 10 journal commit_start nothing to do 2020-07-09 18:29:49.790387 7f3b51a87700 20 filestore(/var/lib/ceph/osd/ceph-1) sync_entry(3994): waiting for max_interval 5.000000 2020-07-09 18:29:50.564479 7f3b680afd80 20 list_by_hash_bitwise prefix DA410000 2020-07-09 18:29:50.564501 7f3b680afd80 20 list_by_hash_bitwise prefix DA410000 ob 3#8:b5280000::::head# 2020-07-09 18:29:50.564508 7f3b680afd80 20 list_by_hash_bitwise prefix DA41002A Any idea what's going on here? I can run a find of every file on the filesystem in under 12 minutes so I'm not sure what's taking so long.

1 0

Lost Journals for XFS OSDs
by Mike Dawson 10 Jul '20

10 Jul '20

Tonight an old Ceph cluster we run suffered a hardware failure that resulted in the loss of Ceph journal SSDs on 7 nodes out of 36. Overview of this old setup: - Super-old Ceph Dumpling v0.67 - 3x replication for RBD w/ 3 failure domains in replication hierarchy - OSDs on XFS on spinning disks with Journals on SSD In total we lost 7 SSDs hosting Journals for 21 OSDs (3 each). The lost nodes span all three failure domains which makes me nervous that there are likely missing Placement Groups in the pool. Due to how Ceph shards data across the Placement Groups, I'm concerned I may have lost all the RBD volumes in this pool. The obvious solution is to attempt to bring the OSDs back online (for at least one failure domain) to ensure there is at least one complete copy of the data then rebuild everything else. The issue is I lost the journals when the SSDs died. I don't see much published about recovering OSDs in the event of a lost journal except: https://ceph.io/geen-categorie/ceph-recover-osds-after-ssd-journal-failure/ And that doesn't mention if the data is valid afterwards. I think I recall Inktank used to deal with this situation and may have had a potential solution. At this point, I'll take any constructive advice. Thanks you in advance, Mike

1 0

Re: RBD thin provisioning and time to format a volume
by Void Star Nill 09 Jul '20

09 Jul '20

On Thu, Jul 9, 2020 at 10:33 AM Marc Roos <M.Roos(a)f1-outsourcing.eu> wrote: > > What about ntfs? You have there a not quick option. Maybe it writes to > the whole disk some random pattern. Why do you ask? > I am writing an API layer to plug into our platform, so I want to know if the format times can be deterministic or unbounded. From what I saw with ext3, ext4 and xfs volumes, the format time is actually not dependent on the size of the volume, so I just wanted to confirm if we can assume that, or if I am missing something. Thanks, Shridhar > > > -----Original Message----- > Cc: ceph-users > Subject: [ceph-users] Re: RBD thin provisioning and time to format a > volume > > Thanks Jason. > > Do you mean to say some filesystems will initialize the entire disk > during format? Does that mean we will see the entire size of the volume > getting allocated during formatting? > Or do you mean to say, some filesystem formatting just takes longer than > others, as it does more initialization? > > I am just trying to understand if there are cases where Ceph will > allocate all the blocks for a filesystem during formation operations, OR > if they continue to be thin provisioned (allocate as you go based on > real data). So far I have tried with ext3, ext4 and xfs and none of them > dont allocate all the blocks during format. > > -Shridhar > > > On Thu, 9 Jul 2020 at 06:58, Jason Dillaman <jdillama(a)redhat.com> wrote: > > > On Thu, Jul 9, 2020 at 12:02 AM Void Star Nill > > <void.star.nill(a)gmail.com> > > wrote: > > > > > > > > > > > > On Wed, Jul 8, 2020 at 4:56 PM Jason Dillaman <jdillama(a)redhat.com> > > wrote: > > >> > > >> On Wed, Jul 8, 2020 at 3:28 PM Void Star Nill > > >> <void.star.nill(a)gmail.com> > > wrote: > > >> > > > >> > Hello, > > >> > > > >> > My understanding is that the time to format an RBD volume is not > > dependent > > >> > on its size as the RBD volumes are thin provisioned. Is this > correct? > > >> > > > >> > For example, formatting a 1G volume should take almost the same > > >> > time > > as > > >> > formatting a 1TB volume - although accounting for differences in > > latencies > > >> > due to load on the Ceph cluster. Is that a fair assumption? > > >> > > >> Yes, that is a fair comparison when creating the RBD image. > > >> However, a format operation might initialize and discard extents on > > > >> the disk, so a larger disk will take longer to format. > > > > > > > > > Thanks for the response Jason. Could you please explain a bit more > > > on > > the the format operation? > > > > I'm not sure what else there is to explain. When you create a file > > system on top of any block device, it needs to initialize the block > > device. Depending on the file system, it might take more time for > > larger block devices because it's doing more work. > > > > > Is there a relative time that we can determine based on the volume > size? > > > > > > Thanks > > > Shridhar > > > > > > > > >> > > >> > > >> > Thanks, > > >> > Shridhar > > >> > _______________________________________________ > > >> > ceph-users mailing list -- ceph-users(a)ceph.io To unsubscribe send > > > >> > an email to ceph-users-leave(a)ceph.io > > >> > > > >> > > >> > > >> -- > > >> Jason > > >> > > > > > > -- > > Jason > > > > > _______________________________________________ > ceph-users mailing list -- ceph-users(a)ceph.io To unsubscribe send an > email to ceph-users-leave(a)ceph.io > > >

1 0

post - bluestore default vs tuned performance comparison
by Frank Ritchie 09 Jul '20

09 Jul '20

Hi, For this post: https://ceph.io/community/bluestore-default-vs-tuned-performance-comparison/ I don't see a way to contact the authors so I thought I would try here. Does anyone know how the rocksdb tuning parameters of: " bluestore_rocksdb_options = compression=kNoCompression,max_write_buffer_number=32,min_write_buffer_number_to_merge=2,recycle_log_file_num=32,compaction_style=kCompactionStyleLevel,write_buffer_size=67108864,target_file_size_base=67108864,max_background_compactions=31,level0_file_num_compaction_trigger=8,level0_slowdown_writes_trigger=32,level0_stop_writes_trigger=64,max_bytes_for_level_base=536870912,compaction_threads=32,max_bytes_for_level_multiplier=8,flusher_threads=8,compaction_readahead_size=2MB " were chosen? Some of the settings seem to not be in line with the rocksdb tuning guide: https://github.com/facebook/rocksdb/wiki/RocksDB-Tuning-Guide thx Frank

2 1

RBD thin provisioning and time to format a volume
by Void Star Nill 09 Jul '20

09 Jul '20

Hello, My understanding is that the time to format an RBD volume is not dependent on its size as the RBD volumes are thin provisioned. Is this correct? For example, formatting a 1G volume should take almost the same time as formatting a 1TB volume - although accounting for differences in latencies due to load on the Ceph cluster. Is that a fair assumption? Thanks, Shridhar

3 5

Bucket index logs (bilogs) not being trimmed automatically (multisite, ceph nautilus 14.2.9)
by david.piper＠metaswitch.com 09 Jul '20

09 Jul '20

Hi all, We're seeing a problem in our multisite Ceph deployment, where bilogs aren't being trimmed for several buckets. This is causing bilogs to accumulate over time, leading to large OMAP object warnings for the indexes on these buckets. In every case, Ceph reports that the bucket is in sync and the data is consistent across both sites, so we're perplexed as to why the logs aren't being trimmed. It's not affecting all of our buckets, we're not sure what's 'different' in the affected cases causing them to accumulate. We're seeing this in both unsharded and sharded buckets. Some buckets with heavy activity (lots of object updates) have accumulated millions of bilogs, but this does not affect all of our very active buckets. I've tried running 'radosgw-admin bilog autotrim' against an affected bucket, and it doesn't appear to do anything. I've used 'radosgw-admin bilog trim' with a suitable 'end-marker' to trim all of the bilogs, but the implications of doing this aren't clear to me, and the logs continue to accumulate afterwards. We're running Ceph Nautilus 14.2.9 and running the services in containers, we have 3 hosts on each site with 1 OSD on each host. We're adjusting a fairly minimal set of config and I don't think it includes anything that would affect bilog trimming. Checking the running config on the mon service, I think these defaulted parameters are relevant: "rgw_sync_log_trim_concurrent_buckets": "4", "rgw_sync_log_trim_interval": "1200", "rgw_sync_log_trim_max_buckets": "16", "rgw_sync_log_trim_min_cold_buckets": "4", I can't find any documentation on these parameters but we have more than 16 buckets, so is it possible that some buckets are just never being selected for trimming? Any other ideas as to what might be causing this, or anything else we could try to help diagnose or fix this? Thanks in advance! I've included an example below for one such affected bucket, showing its current state. Zone details (as per 'radosgw-admin zonegroup get') are at the bottom. $ radosgw-admin bucket sync status --bucket=edin2z6-sharedconfig realm b7f31089-0879-4fa2-9cbc-cfdf5f866a35 (geored_realm) zonegroup 5d74eb0e-5d99-481f-ae33-43483f6cebc0 (geored_zg) zone c48f33ad-6d79-4b9f-a22f-78589f67526e (siteA) bucket edin2z6-sharedconfig[033709fc-924a-4582-b00d-97c90e9e61b6.3634407.1] source zone 0a3c29b7-1a2c-432d-979b-d324a05cc831 (siteApubsub) full sync: 0/1 shards incremental sync: 0/1 shards bucket is caught up with source source zone 9f5fba56-4a32-46a6-8695-89253be81614 (siteB) full sync: 0/1 shards incremental sync: 1/1 shards bucket is caught up with source source zone c72b3aa8-a051-4665-9421-909510702412 (siteBpubsub) full sync: 0/1 shards incremental sync: 0/1 shards bucket is caught up with source $ radosgw-admin bilog list --bucket edin2z6-sharedconfig --max-entries 600000000 | grep op_id | wc -l 1299392 $ rados -p siteA.rgw.buckets.index listomapkeys .dir.033709fc-924a-4582-b00d-97c90e9e61b6.3634407.1 | wc -l 1299083 $ radosgw-admin bucket stats --bucket=edin2z6-sharedconfig { "bucket": "edin2z6-sharedconfig", "num_shards": 0, "tenant": "", "zonegroup": "5d74eb0e-5d99-481f-ae33-43483f6cebc0", "placement_rule": "default-placement", "explicit_placement": { "data_pool": "", "data_extra_pool": "", "index_pool": "" }, "id": "033709fc-924a-4582-b00d-97c90e9e61b6.3634407.1", "marker": "033709fc-924a-4582-b00d-97c90e9e61b6.3634407.1", "index_type": "Normal", "owner": "edin2z6", "ver": "0#1622676", "master_ver": "0#0", "mtime": "2020-01-14 14:30:18.606142Z", "max_marker": "0#00001622675.2115836.5", "usage": { "rgw.main": { "size": 15209, "size_actual": 40960, "size_utilized": 15209, "size_kb": 15, "size_kb_actual": 40, "size_kb_utilized": 15, "num_objects": 7 } }, "bucket_quota": { "enabled": false, "check_on_raw": false, "max_size": -1, "max_size_kb": 0, "max_objects": -1 } } $ radosgw-admin bucket limit check ... { "bucket": "edin2z6-sharedconfig", "tenant": "", "num_objects": 7, "num_shards": 0, "objects_per_shard": 7, "fill_status": "OK" }, ... $ radosgw-admin zonegroup get ++ sudo docker ps --filter name=ceph-rgw-.*rgw -q ++ sudo docker exec d2c999b1f3f8 radosgw-admin { "id": "5d74eb0e-5d99-481f-ae33-43483f6cebc0", "name": "geored_zg", "api_name": "geored_zg", "is_master": "true", "endpoints": [ "https://10.254.2.93:7480" ], "hostnames": [], "hostnames_s3website": [], "master_zone": "c48f33ad-6d79-4b9f-a22f-78589f67526e", "zones": [ { "id": "0a3c29b7-1a2c-432d-979b-d324a05cc831", "name": "siteApubsub", "endpoints": [ "https://10.254.2.93:7481", "https://10.254.2.94:7481", "https://10.254.2.95:7481" ], "log_meta": "false", "log_data": "true", "bucket_index_max_shards": 0, "read_only": "false", "tier_type": "pubsub", "sync_from_all": "false", "sync_from": [ "siteA" ], "redirect_zone": "" }, { "id": "9f5fba56-4a32-46a6-8695-89253be81614", "name": "siteB", "endpoints": [ "https://10.254.2.224:7480", "https://10.254.2.225:7480", "https://10.254.2.226:7480" ], "log_meta": "false", "log_data": "true", "bucket_index_max_shards": 0, "read_only": "false", "tier_type": "", "sync_from_all": "true", "sync_from": [], "redirect_zone": "" }, { "id": "c48f33ad-6d79-4b9f-a22f-78589f67526e", "name": "siteA", "endpoints": [ "https://10.254.2.93:7480", "https://10.254.2.94:7480", "https://10.254.2.95:7480" ], "log_meta": "false", "log_data": "true", "bucket_index_max_shards": 0, "read_only": "false", "tier_type": "", "sync_from_all": "true", "sync_from": [], "redirect_zone": "" }, { "id": "c72b3aa8-a051-4665-9421-909510702412", "name": "siteBpubsub", "endpoints": [ "https://10.254.2.224:7481", "https://10.254.2.225:7481", "https://10.254.2.226:7481" ], "log_meta": "false", "log_data": "true", "bucket_index_max_shards": 0, "read_only": "false", "tier_type": "pubsub", "sync_from_all": "false", "sync_from": [ "siteB" ], "redirect_zone": "" } ], "placement_targets": [ { "name": "default-placement", "tags": [], "storage_classes": [ "STANDARD" ] } ], "default_placement": "default-placement", "realm_id": "b7f31089-0879-4fa2-9cbc-cfdf5f866a35" }

1 0

default.rgw.data.root pool
by Seena Fallah 09 Jul '20

09 Jul '20

Hi all. Is there any docs related to default.rgw.data.root pool? I have this pool and there are no objects in default.rgw.meta pool. Thanks for your help.

1 0

Ceph df Vs Dashboard pool usage mismatch
by Richard Kearsley 09 Jul '20

09 Jul '20

Hi My ceph dashboard reports 64% usage for rgw.buckets.data: [image: cephdashboard.png] But "ceph df" command shows 56.81% used: RAW STORAGE: CLASS SIZE AVAIL USED RAW USED %RAW USED hdd 611 TiB 282 TiB 328 TiB 329 TiB 53.81 TOTAL 611 TiB 282 TiB 328 TiB 329 TiB 53.81 POOLS: POOL ID STORED OBJECTS USED %USED MAX AVAIL .rgw.root 1 12 KiB 25 7.5 MiB 0 50 TiB rgw.control 5 0 B 15 0 B 0 50 TiB rgw.meta 6 13 KiB 51 14 MiB 0 50 TiB rgw.log 7 7.5 MiB 783 69 MiB 0 50 TiB rgw.buckets.index 8 57 MiB 16 57 MiB 0 50 TiB buckets.non-ec 10 0 B 0 0 B 0 50 TiB rgw.buckets.data 11 217 TiB 57.48M 328 TiB 56.81 187 TiB Does ceph df have the correct one? 🤔 ceph version 14.2.8 (2d095e947a02261ce61424021bb43bd3022d35cb) nautilus (stable) Thanks Richard

3 2