You are currently reviewing an older revision of this page.

KB-XXXX How to understand checkpointing in service_manager.log

Purpose

Illustrate and explain the process of a single engine checkpointing, and how the associated output appears in the <APPIAN_HOME>/logs/service_manager.log.

Context

The Appian Engines use a process called "checkpointing" to persist data stored in the in-memory engines to disk. This is triggered either manually or automatically.

Instructions

Note: The remainder of the document will use the following notation:

  • <engine id>: This is the name of the engine associated with the checkpoint. E.g. groups, execution00.
    <path to temporary>: This is the temporary folder where files related to an in-progress checkpoint are stored. This is typically <APPIAN_HOME>/services/data/temporary. However, this can be changed in <APPIAN_HOME>/services/conf/service_manager.conf. Changing this file is not supported unless advised to by Appian Support.
  • <path to archived>: This is the archived folder where historical kdbs are stored.This is typically <APPIAN_HOME>/services/data/archived. However, this can be changed in <APPIAN_HOME>/services/conf/service_manager.conf. Changing this file is not supported unless advised to by Appian Support. This directly can be cleaned and maintained using the cleanupArchives script.
  • <path to engine gateway>: This is the directory that stores the live kdb that an engine will boot from if it is shutdown. This file should never be modified unless advised to by Appian Support. The exact path varies from engine to engine. E.g. <APPIAN_HOME>/server/process/exec/00/gw1 is associated with the execution00 engine gateway.

Phase1:

When a checkpoint is first requested or triggered, it is placed into a queue within the Service Manager component. Checkpoints occur serially, in the order that they are placed into the queue. In the logs, this looks like:

YYYY-MM-DD HH:MM:SS.mmm [KomodoEventBus-XXXX] INFO  com.appian.komodo.engine.status.CheckpointingStateProvider - Checkpoint <checkpoint id> requested for: <engine id>

Service Manager will also log output indicating the type of checkpoint that was requested, e.g. automatic or user triggered.

Automatic:

YYYY-MM-DD HH:MM:SS.mmm [CheckpointManager-<engine id>-X] INFO  com.appian.komodo.engine.checkpoint.CheckpointManager - HandlingCheckpointRequestedEventAutoCheckpointRequestedEvent{createdInstant=YYYY-MM-DDTHH:MM:SS.mmmZ,engineId=<engine id>>,
 requestId=<checkpoint id>,engineShuttingDown=false, checkpointContext=null}
YYYY-MM-DD HH:MM:SS.mmm [CheckpointManager-<engine id>-X] INFO com.appian.komodo.engine.checkpoint.CheckpointManager - QueueingCheckpointRequestedEventAutoCheckpointRequestedEvent{createdInstant=YYYY-MM-DDTHH:MM:SS.mmmZ,engineId=<engine id>, requestId
=<checkpoint id>,engineShuttingDown=false,checkpointContext=CheckpointContext{checkpointId=<checkpoint id>,minTxId=XXXX, kdbFileIndex=XXX,retentionMetadata=serviceManager.transaction.<engine id>-X@XXXX,initiatingHost=<host>, executionHost=<host>}}

User Requested (using the checkpoint script):

YYYY-MM-DD HH:MM:SS.mmm [CheckpointManager-<engine id-X] INFO com.appian.komodo.engine.checkpoint.CheckpointManager - HandlingCheckpointRequestedEventUserCheckpointRequestedEvent{createdInstant=YYYY-MM-DDTHH:MM:SS.mmmZ,engineId=<engine id>, requestId=<checkpoint id>,engineShuttingDown=false, checkpointContext=null}
YYYY-MM-DD HH:MM:SS.mmm [CheckpointManager-<engine id-X] INFO com.appian.komodo.engine.checkpoint.CheckpointManager - QueueingCheckpointRequestedEventUserCheckpointRequestedEvent{createdInstant=YYYY-MM-DDTHH:MM:SS.mmmZ,engineId=<engine id>, requestId=<checkpoint id>,engineShuttingDown=false,checkpointContext=CheckpointContext{checkpointId=<checkpoint id>,minTxId=XXXX, kdbFileIndex=X,retentionMetadata=serviceManager.transaction.<engine id>-X@X,initiatingHost=<host>, executionHost=<host>}}

As can be seen, in both of the above outputs, the CheckpointRequestedEvent is handled by putting it on the checkpointing queue, to be processed.

Phase 2:

Service Manager will dequeue a checkpoint request in order to process it. This is associated with:

YYYY-MM-DD HH:MM:SS.mmm [KomodoEventBus-XXXX] INFO com.appian.komodo.engine.status.CheckpointingStateProvider -Checkpoint <checkpoint id> dequeued for: <engineid>
YYYY-MM-DD HH:MM:SS.mmm [KomodoEventBus-XXXX] INFO com.appian.komodo.engine.checkpoint.CheckpointWatcher - Waiting for checkpoint <checkpoint id> for <engine id>
YYYY-MM-DD HH:MM:SS.mmm [KomodoEventBus-XXXX] INFO com.appian.komodo.engine.status.CheckpointingStateProvider - Checkpoint <checkpoint id> started for <engine id>

After this output, Service Manager will be actively checkpointing the specific engine that the request was associated with. While an engine is being checkpointed, a temporary *.writing kdb is created in the temporary folder associated with the engine undergoing a checkpoint.

Phase 3:

Service Manager will complete the checkpoint operation and perform some operations on the file system:

  • The *.writing kdb from Phase 2 will be renamed to *.written.
  • The *.written kdb will be moved into the <APPIAN_HOME>/server/**/gw1 folder associated with the engine that underwent a checkpoint. This is the new live kdb.

These appear in the logs as:

YYYY-MM-DD HH:MM:SS.mmm [checkpoint-watcher-<engine id>-XXX-X] INFO com.appian.komodo.engine.checkpoint.LocalCheckpointWatcherTask - Notified of Kimage created for checkpoint <checkpoint id> file<path to temporary>/temporary/<engine id>/<engineid>-<checkpoint id>.written at YYYY-MM-DD HH:MM:SS.mmmZ
YYYY-MM-DD HH:MM:SS.mmm[checkpoint-watcher-<engine id>-XXX-X] INFO com.appian.komodo.engine.checkpoint.SingleGatewayCheckpointCopier - Moving KCheckpoint to next live: <path to temporary>/temporary/<engine id>/<engine id>-<checkpoint id>.written to/<APPIAN_HOME>/server/<path to engine gateway>/gw1/<kdb name>.kdb
YYYY-MM-DD HH:MM:SS.mmm [checkpoint-watcher-<engineid>-XXX-X] INFO com.appian.komodo.engine.checkpoint.LocalCheckpointWatcherTask - Finishedcheckpoint <checkpoint id> for <engine id>
YYYY-MM-DD HH:MM:SS.mmm [KomodoEventBus-XXXX] INFO com.appian.komodo.engine.status.CheckpointingStateProvider - Checkpoint<checkpoint id> completed for <engine id>
YYYY-MM-DD HH:MM:SS.mmm [CheckpointManager-<engine id>-X] INFO com.appian.komodo.engine.checkpoint.CheckpointManager - Checkpoint <checkpoint id> execution complete

Phase 4:

Once the checkpoint is complete Service Manager will perform cleanup of the prior "live" kdb, and will also instruct the Kafka component to mark any transactions that were persisted to disk in the checkpoint as ready for cleanup. In the logs, this is associated with:

YYYY-MM-DD HH:MM:SS.mmm[checkpointArchiver-XXX-X]INFO com.appian.komodo.engine.checkpoint.SingleGatewayCheckpointCopier -Archiving kdb image from <APPIAN_HOME>/server/<path to engine gateway>/gw1/*.kdb to <path to archived>/archived/<engineid>/*.kdb
...
YYYY-MM-DD HH:MM:SS.mmm [KomodoEventBus-XXXX]INFO  com.appian.komodo.log.KafkaLogCleaner - Updating committed offset for serviceManager.transaction.<engine id>-X from XXXX to XXXX
YYYY-MM-DD HH:MM:SS.mmm [KomodoEventBus-XXXX] INFO com.appian.komodo.log.KafkaLogCleaner - Marking all transaction log entries for <engine id> that are an earlier offset than XXXX for deletion.

Affected Versions

This article applies to Appian 17.3 and later. The output was captured on Appian 19.4 and may be slightly different on older / newer versions of Appian.

Last Reviewed: January 2020