Bogus Entries in RGW Usage Log / Large omap object in rgw.log pool
Hi All, Running an object storage cluster, originally deployed with Nautilus 14.2.1 and now running 14.2.4. Last week I was alerted to a new warning from my object storage cluster: [root@ceph1 ~]# ceph health detail HEALTH_WARN 1 large omap objects LARGE_OMAP_OBJECTS 1 large omap objects 1 large objects found in pool 'default.rgw.log' Search the cluster log for 'Large omap object found' for more details. I looked into this and found the object and pool in question (default.rgw.log): [root@ceph1 /var/log/ceph]# grep -R -i 'Large omap object found' . ./ceph.log:2019-10-24 12:21:26.984802 osd.194 (osd.194) 715 : cluster [WRN] Large omap object found. Object: 5:0fbdcb32:usage::usage.17:head Key count: 702330 Size (bytes): 92881228 [root@ceph1 ~]# ceph --format=json pg ls-by-pool default.rgw.log | jq '.[]' | egrep '(pgid|num_large_omap_objects)' | grep -v '"num_large_omap_objects": 0,' | grep -B1 num_large_omap_objects "pgid": "5.70", "num_large_omap_objects": 1, While I was investigating, I noticed an enormous amount of entries in the RGW usage log: [root@ceph ~]# radosgw-admin usage show | grep -c bucket 223326 There are entries for over 223k buckets! This was pretty scary to see, considering we only have maybe 500 legitimate buckets in this fairly new cluster. Almost all of the entries in the usage log are bogus entries from anonymous users. It looks like someone/something was scanning, looking for vulnerabilities, etc. Here are a few example entries, notice none of the operations were successful: <-----SNIP-----> { "bucket": "pk1914.php", "time": "2019-07-26 21:00:00.000000Z", "epoch": 1564174800, "owner": "anonymous", "categories": [ { "category": "post_obj", "bytes_sent": 586, "bytes_received": 0, "ops": 2, "successful_ops": 0 } ] }, { "bucket": "plus", "time": "2019-07-26 21:00:00.000000Z", "epoch": 1564174800, "owner": "anonymous", "categories": [ { "category": "post_obj", "bytes_sent": 6314, "bytes_received": 0, "ops": 22, "successful_ops": 0 } ] }, { "bucket": "pma.php", "time": "2019-07-26 21:00:00.000000Z", "epoch": 1564174800, "owner": "anonymous", "categories": [ { "category": "post_obj", "bytes_sent": 580, "bytes_received": 0, "ops": 2, "successful_ops": 0 } ] <-----SNIP-----> I suspect that the large omap warning from Ceph is related to the 223k+ entries in the RGW usage log. I have two questions: 1) How can I remove these bogus bucket entries from the RGW usage log? When I issue $(radosgw-admin usage trim), it only resets the stats to 0, but does not actually remove the bogus bucket entries. 2) Is it possible to prevent Ceph from logging usage statistics for buckets that do not exist? Some more output if it's useful:## ceph --format=json pg ls-by-pool default.rgw.log | jq '.[]' <-----SNIP-----> { "pgid": "5.70", "version": "4712'5226850", "reported_seq": "5636679", "reported_epoch": "4712", "state": "active+clean", "last_fresh": "2019-10-24 14:40:59.287019", "last_change": "2019-10-24 12:21:26.984997", "last_active": "2019-10-24 14:40:59.287019", "last_peered": "2019-10-24 14:40:59.287019", "last_clean": "2019-10-24 14:40:59.287019", "last_became_active": "2019-10-18 16:02:06.007865", "last_became_peered": "2019-10-18 16:02:06.007865", "last_unstale": "2019-10-24 14:40:59.287019", "last_undegraded": "2019-10-24 14:40:59.287019", "last_fullsized": "2019-10-24 14:40:59.287019", "mapping_epoch": 4672, "log_start": "4712'5223781", "ondisk_log_start": "4712'5223781", "created": 1105, "last_epoch_clean": 4673, "parent": "0.0", "parent_split_bits": 0, "last_scrub": "4712'5223077", "last_scrub_stamp": "2019-10-24 12:21:26.984947", "last_deep_scrub": "4712'5223077", "last_deep_scrub_stamp": "2019-10-24 12:21:26.984947", "last_clean_scrub_stamp": "2019-10-24 12:21:26.984947", "log_size": 3069, "ondisk_log_size": 3069, "stats_invalid": false, "dirty_stats_invalid": false, "omap_stats_invalid": false, "hitset_stats_invalid": false, "hitset_bytes_stats_invalid": false, "pin_stats_invalid": false, "manifest_stats_invalid": false, "snaptrimq_len": 0, "stat_sum": { "num_bytes": 0, "num_objects": 2, "num_object_clones": 0, "num_object_copies": 6, "num_objects_missing_on_primary": 0, "num_objects_missing": 0, "num_objects_degraded": 0, "num_objects_misplaced": 0, "num_objects_unfound": 0, "num_objects_dirty": 2, "num_whiteouts": 0, "num_read": 6140544, "num_read_kb": 6769195, "num_write": 10664318, "num_write_kb": 9859326, "num_scrub_errors": 0, "num_shallow_scrub_errors": 0, "num_deep_scrub_errors": 0, "num_objects_recovered": 8, "num_bytes_recovered": 0, "num_keys_recovered": 2666590, "num_objects_omap": 1, "num_objects_hit_set_archive": 0, "num_bytes_hit_set_archive": 0, "num_flush": 0, "num_flush_kb": 0, "num_evict": 0, "num_evict_kb": 0, "num_promote": 0, "num_flush_mode_high": 0, "num_flush_mode_low": 0, "num_evict_mode_some": 0, "num_evict_mode_full": 0, "num_objects_pinned": 0, "num_legacy_snapsets": 0, "num_large_omap_objects": 1, "num_objects_manifest": 0, "num_omap_bytes": 92881228, "num_omap_keys": 702330, "num_objects_repaired": 0 }, "up": [ 194, 79, 51 ], "acting": [ 194, 79, 51 ], "avail_no_missing": [], "object_location_counts": [], "blocked_by": [], "up_primary": 194, "acting_primary": 194, "purged_snaps": [] }, I appreciate any assistance. Thank you. - Dave Monschein
Hi David, On 28/10/2019 20:44, David Monschein wrote:
Hi All,
Running an object storage cluster, originally deployed with Nautilus 14.2.1 and now running 14.2.4.
Last week I was alerted to a new warning from my object storage cluster:
[root@ceph1 ~]# ceph health detail HEALTH_WARN 1 large omap objects LARGE_OMAP_OBJECTS 1 large omap objects 1 large objects found in pool 'default.rgw.log' Search the cluster log for 'Large omap object found' for more details.
I looked into this and found the object and pool in question (default.rgw.log):
[root@ceph1 /var/log/ceph]# grep -R -i 'Large omap object found' . ./ceph.log:2019-10-24 12:21:26.984802 osd.194 (osd.194) 715 : cluster [WRN] Large omap object found. Object: 5:0fbdcb32:usage::usage.17:head Key count: 702330 Size (bytes): 92881228
[root@ceph1 ~]# ceph --format=json pg ls-by-pool default.rgw.log | jq '.[]' | egrep '(pgid|num_large_omap_objects)' | grep -v '"num_large_omap_objects": 0,' | grep -B1 num_large_omap_objects "pgid": "5.70", "num_large_omap_objects": 1, While I was investigating, I noticed an enormous amount of entries in the RGW usage log:
[root@ceph ~]# radosgw-admin usage show | grep -c bucket 223326 [...]
I recently ran into a similar issue: https://lists.ceph.io/hyperkitty/list/ceph-users@ceph.io/thread/AQNGVY7VJ3K6... You have 702,330 keys on that omap object, so you would have been bitten by the default for osd_deep_scrub_large_omap_object_key_threshold having been revised down from 2,000,000 to 200,000 in 14.2.3: https://github.com/ceph/ceph/commit/d8180c57ac9083f414a23fd393497b2784377735 https://tracker.ceph.com/issues/40583 That's why you didn't see this warning before your recent upgrade.
There are entries for over 223k buckets! This was pretty scary to see, considering we only have maybe 500 legitimate buckets in this fairly new cluster. Almost all of the entries in the usage log are bogus entries from anonymous users. It looks like someone/something was scanning, looking for vulnerabilities, etc. Here are a few example entries, notice none of the operations were successful:
Caveat: whether or not you really *want* to trim the usage log is up to you to decide. If you are suspecting you are dealing with a security breach, you should definitely export and preserve the usage log before you trim it, or else delay trimming until you have properly investigated your problem. *If* you decide you no longer need those usage log entries, you can use "radosgw-admin usage trim" with appropriate --start-date, --end-date, and/or --uid options, to clean them up: https://docs.ceph.com/docs/nautilus/radosgw/admin/#trim-usage Please let me know if that information is helpful. Thank you! Cheers, Florian
Florian, Thank you for your detailed reply. I was right in thinking that the 223k+ usage log entries were causing my large omap object warning. You've also confirmed my suspicions that osd_deep_scrub_large_omap_object_key_threshold was changed between Ceph versions. I ended up trimming all of the usage logs before 2019-10-01. First I exported the log -- it was 140MB! radosgw-admin usage trim --start-date=2018-10-01 --end-date=2019-10-01 Interestingly enough, trimming all logs with --start-date & --end-date only took maybe 10 seconds, but when I try to trim the usage for only a single user/bucket, it takes over 30 minutes. Either way, after trimming the log down considerably, I manually issued a deep scrub on pgid 5.70, after which the Ceph health returned to HEALTH_OK I hope this can serve as a guide for anyone else who runs into this problem :) Thanks again, Dave On Tue, Oct 29, 2019 at 3:22 AM Florian Haas <florian@citynetwork.eu> wrote:
Hi David,
Hi All,
Running an object storage cluster, originally deployed with Nautilus 14.2.1 and now running 14.2.4.
Last week I was alerted to a new warning from my object storage cluster:
[root@ceph1 ~]# ceph health detail HEALTH_WARN 1 large omap objects LARGE_OMAP_OBJECTS 1 large omap objects 1 large objects found in pool 'default.rgw.log' Search the cluster log for 'Large omap object found' for more
On 28/10/2019 20:44, David Monschein wrote: details.
I looked into this and found the object and pool in question (default.rgw.log):
[root@ceph1 /var/log/ceph]# grep -R -i 'Large omap object found' . ./ceph.log:2019-10-24 12:21:26.984802 osd.194 (osd.194) 715 : cluster [WRN] Large omap object found. Object: 5:0fbdcb32:usage::usage.17:head Key count: 702330 Size (bytes): 92881228
[root@ceph1 ~]# ceph --format=json pg ls-by-pool default.rgw.log | jq
'.[]' | egrep '(pgid|num_large_omap_objects)' | grep -v '"num_large_omap_objects": 0,' | grep -B1 num_large_omap_objects
"pgid": "5.70", "num_large_omap_objects": 1, While I was investigating, I noticed an enormous amount of entries in the RGW usage log:
[root@ceph ~]# radosgw-admin usage show | grep -c bucket 223326 [...]
I recently ran into a similar issue:
https://lists.ceph.io/hyperkitty/list/ceph-users@ceph.io/thread/AQNGVY7VJ3K6...
You have 702,330 keys on that omap object, so you would have been bitten by the default for osd_deep_scrub_large_omap_object_key_threshold having been revised down from 2,000,000 to 200,000 in 14.2.3:
https://github.com/ceph/ceph/commit/d8180c57ac9083f414a23fd393497b2784377735 https://tracker.ceph.com/issues/40583
That's why you didn't see this warning before your recent upgrade.
There are entries for over 223k buckets! This was pretty scary to see, considering we only have maybe 500 legitimate buckets in this fairly new cluster. Almost all of the entries in the usage log are bogus entries from anonymous users. It looks like someone/something was scanning, looking for vulnerabilities, etc. Here are a few example entries, notice none of the operations were successful:
Caveat: whether or not you really *want* to trim the usage log is up to you to decide. If you are suspecting you are dealing with a security breach, you should definitely export and preserve the usage log before you trim it, or else delay trimming until you have properly investigated your problem.
*If* you decide you no longer need those usage log entries, you can use "radosgw-admin usage trim" with appropriate --start-date, --end-date, and/or --uid options, to clean them up:
https://docs.ceph.com/docs/nautilus/radosgw/admin/#trim-usage
Please let me know if that information is helpful. Thank you!
Cheers, Florian
participants (2)
-
David Monschein
-
Florian Haas