Uploaded image for project: 'Apache Cassandra'
  1. Apache Cassandra
  2. CASSANDRA-1789

Clean up (and make sane) key/row cache loading logspam

    XMLWordPrintableJSON

Details

    • Improvement
    • Status: Resolved
    • Low
    • Resolution: Fixed
    • 0.6.9, 0.7.0 rc 2
    • None
    • None
    • Default settings, init log.

    Description

      //Start
      INFO 19:18:03,362 Heap size: 1935147008/1994063872
      INFO 19:18:03,366 JNA not found. Native methods will be disabled.
      INFO 19:18:03,376 Loading settings from file:/home/hermes/work/c/cass7/conf/cassandra.yaml
      INFO 19:18:03,533 DiskAccessMode 'auto' determined to be mmap, indexAccessMode is mmap
      INFO 19:18:03,612 Creating new commitlog segment /var/lib/cassandra/commitlog/CommitLog-1291079883612.log

      //Keycache loading
      INFO 19:18:03,659 read 0 from saved key cache
      INFO 19:18:03,663 read 0 from saved key cache
      INFO 19:18:03,664 read 0 from saved key cache
      INFO 19:18:03,666 read 0 from saved key cache
      INFO 19:18:03,668 read 0 from saved key cache

      //Rowcache loading
      INFO 19:18:03,671 loading row cache for LocationInfo of system
      INFO 19:18:03,671 completed loading (0 ms; 0 keys) row cache for LocationInfo of system
      INFO 19:18:03,672 loading row cache for HintsColumnFamily of system
      INFO 19:18:03,672 completed loading (0 ms; 0 keys) row cache for HintsColumnFamily of system
      INFO 19:18:03,673 loading row cache for Migrations of system
      INFO 19:18:03,673 completed loading (0 ms; 0 keys) row cache for Migrations of system
      INFO 19:18:03,676 loading row cache for Schema of system
      INFO 19:18:03,676 completed loading (0 ms; 0 keys) row cache for Schema of system
      INFO 19:18:03,676 loading row cache for IndexInfo of system
      INFO 19:18:03,677 completed loading (0 ms; 0 keys) row cache for IndexInfo of system

      //The rest
      INFO 19:18:03,730 Couldn't detect any schema definitions in local storage.
      INFO 19:18:03,731 Found table data in data directories. Consider using JMX to call org.apache.cassandra.service.StorageService.loadSchemaFromYaml().
      INFO 19:18:03,735 No commitlog files found; skipping replay
      INFO 19:18:03,783 Upgrading to 0.7. Purging hints if there are any. Old hints will be snapshotted.
      INFO 19:18:03,786 Cassandra version: 0.7.0-rc1-SNAPSHOT
      INFO 19:18:03,786 Thrift API version: 19.4.0
      INFO 19:18:03,795 Loading persisted ring state
      INFO 19:18:03,796 Starting up server gossip
      INFO 19:18:03,803 switching in a fresh Memtable for LocationInfo at CommitLogContext(file='/var/lib/cassandra/commitlog/CommitLog-1291079883612.log', position=700)
      INFO 19:18:03,804 Enqueuing flush of Memtable-LocationInfo@1249086728(227 bytes, 4 operations)
      INFO 19:18:03,805 Writing Memtable-LocationInfo@1249086728(227 bytes, 4 operations)
      INFO 19:18:03,992 Completed flushing /var/lib/cassandra/data/system/LocationInfo-e-1-Data.db (473 bytes)
      WARN 19:18:04,058 Generated random token 109302658160365096146210744235544448283. Random tokens will result in an unbalanced ring; see http://wiki.apache.org/cassandra/Operations
      INFO 19:18:04,059 switching in a fresh Memtable for LocationInfo at CommitLogContext(file='/var/lib/cassandra/commitlog/CommitLog-1291079883612.log', position=996)
      INFO 19:18:04,060 Enqueuing flush of Memtable-LocationInfo@1940835386(53 bytes, 2 operations)
      INFO 19:18:04,060 Writing Memtable-LocationInfo@1940835386(53 bytes, 2 operations)
      INFO 19:18:04,258 Completed flushing /var/lib/cassandra/data/system/LocationInfo-e-2-Data.db (301 bytes)
      INFO 19:18:04,269 Will not load MX4J, mx4j-tools.jar is not in the classpath
      INFO 19:18:04,301 Binding thrift service to localhost/127.0.0.1:9160
      INFO 19:18:04,304 Using TFramedTransport with a max frame size of 15728640 bytes.
      INFO 19:18:04,307 Listening for thrift clients...

      The logging here is annoying (and a bit schizophrenic).
      Either the keycache loading logging should include as much info as the rowcache loading (time duration, CF/KS names) or it should be a much smaller snippet for both.
      The best fix would probably be the line:
      INFO XX:XX:XX,XXX completed loading (time; keys) row/key cache for CF in KS.
      ...which would be a log line per CF per saved key/row cache (with more logging on error).

      I don't know if logging that "0 rows (key or row cache) successfully loaded" is worth it either, but I could be swayed by an argument for this.

      Attachments

        1. 1789-trunk.txt
          4 kB
          Matthew F. Dennis

        Activity

          People

            mdennis Matthew F. Dennis
            jhermes Jon Hermes
            Matthew F. Dennis
            Jonathan Ellis
            Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: