How to disable OzoneManager RocksDB logging?

[vasflam]

Hello, I can’t find a way to disable OzoneManager RocksDB logging. I have a test cluster in Kubernetes with one OM node and a 50GB disk for metadata. When uploading a 100GB test file into the cluster, after 10-15 minutes, the OM node fills the entire disk with log files and hangs.

The folder that uses space is om.db. RocksDB generate about 1GB of logs per minute.

$ ls -alh | grep log
-rw-r--r--.  1 hadoop hadoop 130M Jun 26 07:54 002755.log
-rw-r--r--.  1 hadoop hadoop 131M Jun 26 07:54 002757.log
-rw-r--r--.  1 hadoop hadoop 132M Jun 26 07:54 002760.log
-rw-r--r--.  1 hadoop hadoop 128M Jun 26 07:54 002762.log
-rw-r--r--.  1 hadoop hadoop 129M Jun 26 07:54 002764.log
-rw-r--r--.  1 hadoop hadoop 131M Jun 26 07:54 002766.log
-rw-r--r--.  1 hadoop hadoop 132M Jun 26 07:54 002769.log
-rw-r--r--.  1 hadoop hadoop 133M Jun 26 07:54 002771.log

I also tried to define options from RocksDBConfiguration.java in ozone-site.xml, but with no success.

<property><name>hadoop.hdds.db.rocksdb.logging.level</name><value>ERROR</value></property>
<property><name>hadoop.hdds.db.rocksdb.logging.enabled</name><value>false</value></property>

[errose28]

Hi @vasflam I think there is some confusion about these files. RocksDB's application logs are written to files called LOG. The files you have listed here are write ahead log (WAL) files. They are where new entries are appended before being flushed and compacted to sst files. You can verify this by opening 002755.log in a text editor, and you should see that the contents are binary.

Now it is definitely odd that the WAL is filling up at this rate and not getting flushed. Usually this aspect of the system is managed by RocksDB and the defaults just work. I don't have an exact number but I believe a 50gb RocksDB instance should suffice for at least a few million keys, if not more. Of course that requires WAL flush and compaction to be happening to reduce the storage size.

Can you share some more information:

• What Ozone version are you using?
• Have you done any customization to RocksDB configuration or version outside of what is present upstream?
• What workload are you running?
• Do you see anything suspicious in the RocksDB application log (the LOG file)?

[vasflam]

Heh, I saw the binary format, but I didn’t realize it was WAL. Very strange behavior - it’s only one file uploading at a time (later, I will try to simulate uploading multiple very large files). That’s not all; WAL logs are then moved to the archive folder, and I saw there were more than 300 files.

At this time, I can’t see any suspicious entries in the LOG files. I will look at them closer.

Information about cluster

Version:

1.4.0(Hot Springs)

Source code repository https://github.com/apache/ozone.git -r e4b6007c8e9f79d1432cf6f128d6f83e733f8e9b
Compiled by ozone on 2024-01-10T15:32Z
Compiled with protoc 2.5.0, 3.19.6 and 3.7.1
From source with checksum 7a23d1236f847a694b4dceaf676eabe
With Apache Ratis: 3.0.1 from e6f2554610941d8ca18aee6df1d5c0e78275a003
Compiled on platform linux-x86_64

Using HDDS 1.4.0
Source code repository https://github.com/apache/ozone.git -r e4b6007c8e9f79d1432cf6f128d6f83e733f8e9b
Compiled by ozone on 2024-01-10T15:30Z
Compiled with protoc 2.5.0, 3.19.6 and 3.7.1
From source with checksum b5a3e516458af8ee43a6d555f60a0c5
Compiled on platform linux-x86_64

Configuration:

apiVersion: v1
kind: ConfigMap
metadata:
  name: config
data:
  # For ozone console client usage
  CORE-SITE.XML_hadoop.security.authentication: kerberos

  OZONE-SITE.XML_hdds.datanode.container.schema.v3.enabled: "true"
  OZONE-SITE.XML_dfs.datanode.use.datanode.hostname: "true"
  OZONE-SITE.XML_ozone.metadata.dirs: /data/metadata
  OZONE-SITE.XML_ozone.security.enabled: "true"
  OZONE-SITE.XML_hadoop.security.authentication: kerberos
  OZONE-SITE.XML_ozone.security.http.kerberos.enabled: "true"
  OZONE-SITE.XML_ozone.http.filter.initializers: org.apache.hadoop.security.AuthenticationFilterInitializer
  OZONE-SITE.XML_ozone.acl.enabled: "true"
  OZONE-SITE.XML_ozone.acl.authorizer.class: org.apache.hadoop.ozone.security.acl.OzoneNativeAuthorizer
  OZONE-SITE.XML_ozone.administrators: hadoop
  OZONE-SITE.XML_ozone.administrators.groups: hadoop
  OZONE-SITE.XML_ozone.om.volume.listall.allowed: "false"

  OZONE-SITE.XML_ozone.om.address: om-0.om
  OZONE-SITE.XML_ozone.om.http.auth.type: kerberos
  OZONE-SITE.XML_ozone.om.kerberos.principal: OM/ozone-01@MYREALM
  OZONE-SITE.XML_ozone.om.http.auth.kerberos.principal: HTTP/ozone-01@MYREALM

  OZONE-SITE.XML_hdds.scm.http.auth.type: kerberos
  OZONE-SITE.XML_hdds.scm.kerberos.principal: SCM/ozone-01@MYREALM
  OZONE-SITE.XML_hdds.scm.http.auth.kerberos.principal: HTTP/ozone-01@MYREALM
  OZONE-SITE.XML_ozone.scm.datanode.id.dir: /data
  OZONE-SITE.XML_ozone.scm.service.ids: scmservice
  OZONE-SITE.XML_ozone.scm.address.scmservice.scm0: scm-0.scm
  OZONE-SITE.XML_ozone.scm.address.scmservice.scm1: scm-1.scm
  OZONE-SITE.XML_ozone.scm.address.scmservice.scm2: scm-2.scm
  OZONE-SITE.XML_ozone.scm.nodes.scmservice: scm0,scm1,scm2
  OZONE-SITE.XML_ozone.scm.primordial.node.id: scm0
  OZONE-SITE.XML_ozone.server.default.replication: RS-3-2-1024k
  OZONE-SITE.XML_ozone.server.default.replication.type: EC

  OZONE-SITE.XML_dfs.datanode.kerberos.principal: dn/ozone-01@MYREALM
  OZONE-SITE.XML_dfs.datanode.kerberos.keytab.file: /etc/security/keytabs/dn.keytab
  OZONE-SITE.XML_hdds.datanode.http.auth.kerberos.principal: HTTP/ozone-01@MYREALM
  OZONE-SITE.XML_hdds.datanode.http.auth.kerberos.keytab: /etc/security/keytabs/HTTP.keytab
  OZONE-SITE.XML_hdds.datanode.metadata.rocksdb.cache.size: 128MB
  OZONE-SITE.XML_hdds.datanode.dir: |
    /mnt/disk01
    /mnt/disk02
    /mnt/disk03
    /mnt/disk04
    /mnt/disk05

  OZONE-SITE.XML_ozone.s3g.http.auth.type: kerberos
  OZONE-SITE.XML_ozone.s3g.secret.http.auth.type: kerberos
  OZONE-SITE.XML_ozone.s3g.kerberos.principal: s3g/ozone-01@MYREALM
  OZONE-SITE.XML_ozone.s3g.http.auth.kerberos.principal: HTTP/ozone-01@MYREALM

  OZONE-SITE.XML_ozone.recon.http.auth.type: kerberos
  OZONE-SITE.XML_ozone.recon.http.auth.kerberos.principal: HTTP/ozone-01@MYREALM
  LOG4J.PROPERTIES_log4j.rootLogger: INFO, stdout
  LOG4J.PROPERTIES_log4j.appender.stdout: org.apache.log4j.ConsoleAppender
  LOG4J.PROPERTIES_log4j.appender.stdout.layout: org.apache.log4j.PatternLayout
  LOG4J.PROPERTIES_log4j.appender.stdout.layout.ConversionPattern: '%d{yyyy-MM-dd
    HH:mm:ss} %-5p %c{1}:%L - %m%n'

There is no real workload at this time. I tested uploading large files and got stuck at the start.
The cluster was built with the help of Apache Ozone Kubernetes example, and no additions were made to RocksDB.

There are 1 OM node, 3 SCM nodes, 5 datanodes and 5 s3g nodes in the cluster, without recon node.
The test file was attempted to be uploaded through the s3g service using the aws s3 command:

dd if=/dev/urandom bs=1M count=102400 | aws s3 cp - s3://test/100gb.bin --expected-size=107374182400 --endpoint-url http://s3g.ozone-01:9878

[errose28]

Looks like you are uploading a 100gb file using aws s3 cp. This will automatically be converted to a multi-part upload per the S3 docs. Internally Ozone will allocate one block for each part of the upload, and IIRC the default part size used is quite small, like a single digit number of MBs. Can you try the test with a larger part size, like 256MB which aligns with Ozone's default block size? Also, you can try the test using using an Ozone client directly using ozone sh or ozone fs (or HDFS which also uses ofs like ozone fs).

This is actually a known issue, but I can't seem to find a Jira corresponding to it. Here's a technical breakdown of what's happening if you are interested:

Internally, Each multi-part upload is a single key in RocksDB, whose value is a list of part metadata. Each time a new part is uploaded, Ozone will append the metadata of the new part to the list of parts mapped to the key in RocksDB. Since RocksDB is an LSM database, this append is modification is written as a new entry to the WAL file. The previous entry will likely still be in the WAL as well since parts are being uploaded in quick succession. The contents of the WAL will look like this:

key: part1 <- OLDEST ENTRY
key: part1 part 2
key: part1 part 2 part3
key: part1 part 2 part3 part4 ... <- NEWEST ENTRY

This means that the WAL size is actually O(n^2) with respect to the number of parts in the key, since each part addition generates a new WAL entry with all the parts before it.

With Ozone's default block size this is not a problem, even for small files like 100MB, because they fit in a single block. But when block size is decreased two orders of magnitude to the single digits, this problem arises. If we use a 5MB block size, for example, that 100MB file is now generating 20 WAL entries, each of increasing size, where as previously it would only generate 1 WAL entry.

[ivandika3]

This is actually a known issue, but I can't seem to find a Jira corresponding to it.

FYI, the Jira should be this https://issues.apache.org/jira/browse/HDDS-8238

[whbing]

@vasflam

I also tried to define options from RocksDBConfiguration.java in ozone-site.xml, but with no success.

Hi , rocksdb conf can be set in etc/hadoop/om.db.ini / etc/hadoop/scm.db.ini file.
Some doc see: https://github.com/apache/ozone/pull/4503/files, or examples : https://github.com/facebook/rocksdb/blob/main/examples/rocksdb_option_file_example.ini
You can try it.

[vasflam]

Thank you all! I learned more from these three messages than from a couple of days of searching on Google! Next week, I will try all the suggested solutions and share them if there are any interesting results.

[vasflam]

After extensive study, I came to the following conclusion: the root of the problem is that the s3g service cannot control the minimum/maximum multipart upload partition size. A user, either unintentionally or maliciously, can set the partition size to as little as 1 byte (as @errose28 pointed out, a block the size of each upload part is created, and a RocksDB entry is added), which can result in filling up all the space allocated for metadata and disabling the OM service. Here is an example code in Java - OzoneOmSpam.java

The only solution is to disable WAL log archiving and set a maximum limit on the WAL size.
As @whbing suggested, add the following to the /etc/hadoop/ob.db.ini file:

[DBOptions]
max_total_wal_size=1024MB
WAL_ttl_seconds=0
WAL_size_limit_MB=0
[CFOptions "default"]

The section [CFOptions “default”] is mandatory. If it is omitted, the RocksDB configuration will not be applied, and no entries will be recorded in the log files (I spent some hours on this).

Links to the descriptions in RocksDB options.h:

• max_total_wal_size
• WAL_ttl_seconds & WAL_size_limit_MB

[adoroszlai]

@vasflam Minimum part size for multipart uploads is 5MB, except for the last part. Unfortunately this is only validated upon CompleteMultipartUpload, since that's when we know which one is the last part. We could check in UploadPart whether the previous part, which can no longer be the last one, conforms to the size restriction. I don't know whether that behavior would be compatible with Amazon, but it may be worth adding this check anyway.

[errose28]

That sounds like a good idea to prevent extreme cases like 1 byte part size. A 100GB file with 5MB parts will still likely have issues without increasing the part size closer to Ozone's default block size though.

[adoroszlai]

Created HDDS-11109.