Uploaded image for project: 'Couchbase Server'
  1. Couchbase Server
  2. MB-21406

[CBAS] Errors in blue and red service logs during graceful shutdown and startup

    XMLWordPrintable

Details

    • Bug
    • Resolution: Fixed
    • Major
    • CBAS DP
    • CBAS DP
    • analytics
    • None
    • Untriaged
    • Unknown

    Description

      CBAS Build : 283 (RC1)
      During graceful startup and shutdown of CBAS service, errors are logged in red-service.log and blue-service.log. The logging level for these msgs should be INFO

      blue-service.log

      --------------------------
      Tue Oct 18 21:03:12 IST 2016
      --------------------------
      2016-10-18T21:03:13.206+05:30 INFO CBAS.service.NCService [main] Waiting for connection from CC on null:9091
      2016-10-18T21:03:13.876+05:30 INFO CBAS.service.NCService [main] Setting JAVA_OPTS to -Xmx1536m
      2016-10-18T21:03:13.876+05:30 INFO CBAS.service.NCService [main] Launching NCDriver process
      2016-10-18T21:03:14.552+05:30 ERRO CBAS.nc.NCDriver [main] Setting uncaught exception handler org.apache.hyracks.api.lifecycle.LifeCycleComponentManager@525f1e4e
      2016-10-18T21:03:14.554+05:30 INFO CBAS.nc.NodeControllerService [main] Starting NodeControllerService
      2016-10-18T21:03:14.560+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [main] Starting Asterix node controller: blue
      2016-10-18T21:03:14.923+05:30 INFO CBAS.logging.LogManager [main] log file Id: 16, offset: 0
      2016-10-18T21:03:14.924+05:30 INFO CBAS.logging.LogManager [main] LogManager starts logging in LSN: 4294967296
      2016-10-18T21:03:14.947+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [main] System is in a state: HEALTHY
      2016-10-18T21:03:15.075+05:30 INFO CBAS.nc.NodeControllerService [main] Started NodeControllerService
      2016-10-18T21:03:15.092+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [main] Starting lifecycle components
      2016-10-18T21:03:15.092+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [main] Coredump directory for NC is: data/blue/coredump
      2016-10-18T21:03:15.092+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [main] LifecycleComponentManager configured org.apache.hyracks.api.lifecycle.LifeCycleComponentManager@525f1e4e
      2016-10-18T21:03:15.092+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [main] Configured:org.apache.hyracks.api.lifecycle.LifeCycleComponentManager@525f1e4e
      2016-10-18T21:03:15.093+05:30 INFO CBAS.recovery.RecoveryManager [main] Starting sharp checkpoint ... 
      2016-10-18T21:03:15.094+05:30 INFO CBAS.logging.LogManager [main] Terminating LogFlusher thread ...
      2016-10-18T21:03:15.094+05:30 INFO CBAS.logging.LogManager [main] LogFlusher thread is terminated.
      2016-10-18T21:03:15.095+05:30 INFO CBAS.logging.LogManager [main] created a log file: data/blue/txnlog/asterix_transaction_log_17
      2016-10-18T21:03:15.095+05:30 INFO CBAS.logging.LogManager [main] log file Id: 17, offset: 0
      2016-10-18T21:03:15.095+05:30 INFO CBAS.logging.LogManager [main] LogManager starts logging in LSN: 4563402752
      2016-10-18T21:03:15.096+05:30 INFO CBAS.recovery.RecoveryManager [main] Completed sharp checkpoint.
      2016-10-18T21:06:54.905+05:30 INFO CBAS.task.ShutdownTask [Executor-7:blue] JVM Exiting.. Bye!
      2016-10-18T21:06:54.906+05:30 INFO CBAS.nc.NodeControllerService [NC blue Shutdown] Stopping NodeControllerService
      2016-10-18T21:06:54.906+05:30 ERRO CBAS.dataset.ResultStateSweeper [Executor-5:blue] Result cleaner thread interrupted, shutting down.
      2016-10-18T21:06:54.907+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [NC blue Shutdown] Stopping Asterix node controller: blue
      2016-10-18T21:06:54.908+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC blue Shutdown] Attempting to stop org.apache.hyracks.api.lifecycle.LifeCycleComponentManager@525f1e4e
      2016-10-18T21:06:54.908+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC blue Shutdown] Stopping Asterix instance
      2016-10-18T21:06:54.908+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC blue Shutdown] Stopping component instanceorg.apache.asterix.transaction.management.service.locking.ConcurrentLockManager dump state false dump path null
      2016-10-18T21:06:54.909+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC blue Shutdown] Stopping component instanceorg.apache.asterix.transaction.management.service.transaction.TransactionManager dump state false dump path null
      2016-10-18T21:06:54.909+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC blue Shutdown] Stopping component instanceorg.apache.asterix.common.context.DatasetLifecycleManager dump state false dump path null
      2016-10-18T21:06:54.909+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC blue Shutdown] Stopping component instanceorg.apache.asterix.transaction.management.service.recovery.RecoveryManager dump state false dump path null
      2016-10-18T21:06:54.909+05:30 INFO CBAS.recovery.RecoveryManager [NC blue Shutdown] Starting sharp checkpoint ... 
      2016-10-18T21:06:54.911+05:30 INFO CBAS.logging.LogManager [NC blue Shutdown] Terminating LogFlusher thread ...
      2016-10-18T21:06:54.912+05:30 INFO CBAS.logging.LogManager [NC blue Shutdown] LogFlusher thread is terminated.
      2016-10-18T21:06:54.913+05:30 INFO CBAS.logging.LogManager [NC blue Shutdown] created a log file: data/blue/txnlog/asterix_transaction_log_18
      2016-10-18T21:06:54.913+05:30 INFO CBAS.logging.LogManager [NC blue Shutdown] log file Id: 18, offset: 0
      2016-10-18T21:06:54.914+05:30 INFO CBAS.logging.LogManager [NC blue Shutdown] LogManager starts logging in LSN: 4831838208
      2016-10-18T21:06:54.914+05:30 INFO CBAS.recovery.RecoveryManager [NC blue Shutdown] Completed sharp checkpoint.
      2016-10-18T21:06:54.914+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC blue Shutdown] Stopping component instanceorg.apache.asterix.transaction.management.service.logging.LogManager dump state false dump path null
      2016-10-18T21:06:54.914+05:30 INFO CBAS.logging.LogManager [NC blue Shutdown] Terminating LogFlusher thread ...
      2016-10-18T21:06:54.914+05:30 INFO CBAS.logging.LogManager [NC blue Shutdown] LogFlusher thread is terminated.
      2016-10-18T21:06:54.914+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC blue Shutdown] Stopping component instanceorg.apache.hyracks.storage.common.buffercache.BufferCache dump state false dump path null
      2016-10-18T21:06:54.917+05:30 INFO CBAS.nc.NodeControllerService [NC blue Shutdown] Stopped NodeControllerService
      2016-10-18T21:06:54.918+05:30 INFO CBAS.nc.NodeControllerService [Thread-5] Shutdown hook in progress
      2016-10-18T21:06:55.313+05:30 INFO CBAS.service.NCService [main] NCDriver exited with return value 99
      2016-10-18T21:06:55.314+05:30 INFO CBAS.service.NCService [main] Terminating NCService based on return value from NCDriver
      2016-10-18T21:06:55.314+05:30 INFO CBAS.service.NCService [main] JVM Exiting.. Bye!
      
      

      red-service.log

      --------------------------
      Tue Oct 18 21:03:12 IST 2016
      --------------------------
      2016-10-18T21:03:13.227+05:30 INFO CBAS.service.NCService [main] Waiting for connection from CC on null:9090
      2016-10-18T21:03:13.883+05:30 INFO CBAS.service.NCService [main] Setting JAVA_OPTS to -Xmx1536m
      2016-10-18T21:03:13.884+05:30 INFO CBAS.service.NCService [main] Launching NCDriver process
      2016-10-18T21:03:14.575+05:30 ERRO CBAS.nc.NCDriver [main] Setting uncaught exception handler org.apache.hyracks.api.lifecycle.LifeCycleComponentManager@525f1e4e
      2016-10-18T21:03:14.576+05:30 INFO CBAS.nc.NodeControllerService [main] Starting NodeControllerService
      2016-10-18T21:03:14.582+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [main] Starting Asterix node controller: red
      2016-10-18T21:03:14.928+05:30 INFO CBAS.logging.LogManager [main] log file Id: 16, offset: 0
      2016-10-18T21:03:14.928+05:30 INFO CBAS.logging.LogManager [main] LogManager starts logging in LSN: 4294967296
      2016-10-18T21:03:14.952+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [main] System is in a state: HEALTHY
      2016-10-18T21:03:15.075+05:30 INFO CBAS.nc.NodeControllerService [main] Started NodeControllerService
      2016-10-18T21:03:15.107+05:30 INFO CBAS.nc.AsterixNCAppRuntimeContext [main] Bootstrapping metadata
      2016-10-18T21:03:15.176+05:30 INFO CBAS.bootstrap.MetadataBootstrap [main] Finished enlistment of metadata B-trees in old universe
      2016-10-18T21:03:15.217+05:30 INFO CBAS.locking.ConcurrentLockManager [main] { lock : 1, instantLock : 0, tryLock : 0, instantTryLock : 0, unlock : 1, releaseLocks : 1 }
      2016-10-18T21:03:15.217+05:30 INFO CBAS.bootstrap.MetadataBootstrap [main] Starting DDL recovery ...
      2016-10-18T21:03:15.225+05:30 INFO CBAS.bootstrap.MetadataBootstrap [main] Completed DDL recovery.
      2016-10-18T21:03:15.227+05:30 INFO CBAS.nc.AsterixNCAppRuntimeContext [main] Metadata node bound
      2016-10-18T21:03:15.229+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [main] Starting lifecycle components
      2016-10-18T21:03:15.229+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [main] Coredump directory for NC is: data/red/coredump
      2016-10-18T21:03:15.229+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [main] LifecycleComponentManager configured org.apache.hyracks.api.lifecycle.LifeCycleComponentManager@525f1e4e
      2016-10-18T21:03:15.229+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [main] Configured:org.apache.hyracks.api.lifecycle.LifeCycleComponentManager@525f1e4e
      2016-10-18T21:03:15.230+05:30 INFO CBAS.recovery.RecoveryManager [main] Starting sharp checkpoint ... 
      2016-10-18T21:03:15.235+05:30 INFO CBAS.logging.LogManager [main] Terminating LogFlusher thread ...
      2016-10-18T21:03:15.235+05:30 INFO CBAS.logging.LogManager [main] LogFlusher thread is terminated.
      2016-10-18T21:03:15.236+05:30 INFO CBAS.logging.LogManager [main] created a log file: data/red/txnlog/asterix_transaction_log_17
      2016-10-18T21:03:15.236+05:30 INFO CBAS.logging.LogManager [main] log file Id: 17, offset: 0
      2016-10-18T21:03:15.236+05:30 INFO CBAS.logging.LogManager [main] LogManager starts logging in LSN: 4563402752
      2016-10-18T21:03:15.236+05:30 INFO CBAS.recovery.RecoveryManager [main] Completed sharp checkpoint.
      2016-10-18T21:06:54.903+05:30 INFO CBAS.task.ShutdownTask [Executor-7:red] JVM Exiting.. Bye!
      2016-10-18T21:06:54.904+05:30 INFO CBAS.nc.NodeControllerService [NC red Shutdown] Stopping NodeControllerService
      2016-10-18T21:06:54.904+05:30 ERRO CBAS.dataset.ResultStateSweeper [Executor-5:red] Result cleaner thread interrupted, shutting down.
      2016-10-18T21:06:54.905+05:30 INFO CBAS.bootstrap.NCApplicationEntryPoint [NC red Shutdown] Stopping Asterix node controller: red
      2016-10-18T21:06:54.906+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC red Shutdown] Attempting to stop org.apache.hyracks.api.lifecycle.LifeCycleComponentManager@525f1e4e
      2016-10-18T21:06:54.906+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC red Shutdown] Stopping Asterix instance
      2016-10-18T21:06:54.906+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC red Shutdown] Stopping component instanceorg.apache.asterix.transaction.management.service.locking.ConcurrentLockManager dump state false dump path null
      2016-10-18T21:06:54.906+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC red Shutdown] Stopping component instanceorg.apache.asterix.transaction.management.service.transaction.TransactionManager dump state false dump path null
      2016-10-18T21:06:54.906+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC red Shutdown] Stopping component instanceorg.apache.asterix.common.context.DatasetLifecycleManager dump state false dump path null
      2016-10-18T21:06:54.912+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC red Shutdown] Stopping component instanceorg.apache.asterix.transaction.management.service.recovery.RecoveryManager dump state false dump path null
      2016-10-18T21:06:54.912+05:30 INFO CBAS.recovery.RecoveryManager [NC red Shutdown] Starting sharp checkpoint ... 
      2016-10-18T21:06:54.913+05:30 INFO CBAS.logging.LogManager [NC red Shutdown] Terminating LogFlusher thread ...
      2016-10-18T21:06:54.913+05:30 INFO CBAS.logging.LogManager [NC red Shutdown] LogFlusher thread is terminated.
      2016-10-18T21:06:54.915+05:30 INFO CBAS.logging.LogManager [NC red Shutdown] created a log file: data/red/txnlog/asterix_transaction_log_18
      2016-10-18T21:06:54.915+05:30 INFO CBAS.logging.LogManager [NC red Shutdown] log file Id: 18, offset: 0
      2016-10-18T21:06:54.915+05:30 INFO CBAS.logging.LogManager [NC red Shutdown] LogManager starts logging in LSN: 4831838208
      2016-10-18T21:06:54.915+05:30 INFO CBAS.recovery.RecoveryManager [NC red Shutdown] Completed sharp checkpoint.
      2016-10-18T21:06:54.915+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC red Shutdown] Stopping component instanceorg.apache.asterix.transaction.management.service.logging.LogManager dump state false dump path null
      2016-10-18T21:06:54.916+05:30 INFO CBAS.logging.LogManager [NC red Shutdown] Terminating LogFlusher thread ...
      2016-10-18T21:06:54.916+05:30 INFO CBAS.logging.LogManager [NC red Shutdown] LogFlusher thread is terminated.
      2016-10-18T21:06:54.916+05:30 ERRO CBAS.lifecycle.LifeCycleComponentManager [NC red Shutdown] Stopping component instanceorg.apache.hyracks.storage.common.buffercache.BufferCache dump state false dump path null
      2016-10-18T21:06:54.929+05:30 INFO CBAS.nc.NodeControllerService [NC red Shutdown] Stopped NodeControllerService
      2016-10-18T21:06:54.930+05:30 INFO CBAS.nc.NodeControllerService [Thread-5] Shutdown hook in progress
      2016-10-18T21:06:55.327+05:30 INFO CBAS.service.NCService [main] NCDriver exited with return value 99
      2016-10-18T21:06:55.328+05:30 INFO CBAS.service.NCService [main] Terminating NCService based on return value from NCDriver
      2016-10-18T21:06:55.328+05:30 INFO CBAS.service.NCService [main] JVM Exiting.. Bye!
      
      

      Attachments

        No reviews matched the request. Check your Options in the drop-down menu of this sections header.

        Activity

          People

            mihir.kamdar Mihir Kamdar (Inactive)
            mihir.kamdar Mihir Kamdar (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty