logo

Manual Pages

Table of Contents

NAME

na_sis - Log of Advanced Single Instance Storage (SIS) activities

SYNOPSIS

/etc/log/sis

DESCRIPTION

The sis log file contains a log of SIS activities for this filer. The file lives in /etc/log on the root volume.

Every Sunday at midnight, /etc/log/sis is moved to /etc/log/sis.0; /etc/log/sis.0 is moved to /etc/log/sis.1; and so on. The suffix can go up to 5, so the old /etc/log/sis.5 will be deleted. SIS activities are saved for a total of seven weeks.

Each entry of the /etc/log/sis file is a single line containing the following space-separated fields.

  timestamp path session-ID event_info

The following is a description of each field.

timestamp
Displayed in ctime() format, e.g. Fri Jul 17 20:41:09 GMT 2008. Indicates the time this event was recorded.

path
The full path to a SIS volume as shown below 
  /vol/volume_name

session-ID
The session ID is as shown below: 
  [sid: 1220249325]

event_info
The event which is being logged. Some events may have extra information in parentheses. The current event types are:

Sis Restart
When a SIS operation resumes from a checkpoint. The event is augmented within parenthesis with the stage from which it is restarting.( Restarting from [ - | gathering | sorting | saving_pass1 | saving_pass2 checking |
checking_pass1 | checking_pass2 ] )

Begin ( operation information)

When a SIS operation is first kicked off, there can be multiple reasons which trigger it. The event is augmented with the following additional information in parenthesis.

schedule : If the SIS operation is kicked off as per the configured or default schedule.

sis start scan : Corresponds to "sis start -s", when we are instructed to scan the entire file system for duplicated blocks.

sis check : If we are specifically instructed to perform fingerprint database checking.

sis start snapvault : If the snapvault initiated the SIS operation.

sis start : When the SIS operation is kicked off to perform deduplication based on the changelogs.

Undo
Corresponds to "sis undo" command.

Stage ( amount_processed )
An event is logged at the end of each stage along with the amount of processing that was done in that stage. The different stages can be Sort, Dedup Pass1, Dedup Pass2 and Verify. Note the Verify event is logged at the start of sis check operation. The events for each are shown below :
  Thu Sep 01 10:31:05 GMT 2008 /vol/dense_vol [sid: 12] Sort (2560 fp entries)

  Thu Sep 22 10:33:03 GMT 2008 /vol/dense_vol [sid: 12] Dedup Pass1 (0 dup entries)

  Thu Oct 13 10:35:00 GMT 2008 /vol/dense_vol [sid: 12] Dedup Pass2 (2559 dup entries)

  Thu Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 12] Verify

End ( processed_size KB )
When a long-running SIS operation (either Begin or Undo) completes successfully. The size of data processed is included in the event.

Error ( Error_message )
If a SIS operation aborts or fails to start, the cause of the error is indicated.

Config ( schedule_string )
When a "sis config" command successfully set or modified the SIS schedule on a volume. The new schedule string is logged with the event.

Enable
When the SIS is enabled on a volume.

Disable
When the SIS is disabled on a volume.

Stats ( statistics string)
When each changelog is processed ,statistics are logged with this event.

Info ( operation information)
Some of the operations that are logged within parenthesis in the Info event are :

sis start : This corresponds to the event when user issues the sis operation based on changelogs.

sis check : When a sis check operation starts to perform fingerprint database checking.

sis start scan : This information is logged when a "sis start -s" command is issued.

sis start schedule : When a sis operation starts based on its schedule.

operation pending : The maximum number of sis operations running is 8. If a sis operation is issued or scheduled when this upper limit is already reached, it gets queued as a pending operation and prints this message in Info event.

starting pending operation : A sis operation is queued when 8 sis operations are already running. This message is logged when later on system becomes free and the pending operation starts its execution at the time of schedule start.

EXAMPLE

On the successful completion of such a sis start -s operation, the log file should have the following entries: 

  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 11] Info (sis start scan)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 11] Begin (sis start scan)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 11] Sort (0 fp entries)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 11] Dedup Pass1 (0 dup entries)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 11] Dedup Pass2 (0 dup entries)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 11] Stats (blks gathered 0,finger
  prints sorted 0,dups found 0,new dups found 0,blks deduped 0,finger prints checked 0,finger
  prints deleted 0)
  Tue Jul 12 02:02:05 GMT /vol/dense_vol [sid: 11]  End (0 KB)

On the successful completion of a sis start operation, the log file should have the following entries: 

  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 9] Info (sis start)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 9] Begin (sis start)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 9] Sort (0 fp entries)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 9] Dedup Pass1 (0 dup entries)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 9] Dedup Pass2 (0 dup entries)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 9] Stats (blks gathered 0,finger
  prints sorted 0,dups found 0,new dups found 0,blks deduped 0,finger prints checked
  0,finger prints deleted 0)
  Tue Jul 12 02:02:05 GMT 2008 /vol/dense_vol [sid: 9] End (0 KB)

A SIS operation initiated by schedule and based on change log is the most common case. In this case a pending operation has started its execution. On the successful completion of such an operation, the log file should have the following entries: 

  Tue Jul 12 02:01:03 GMT 2008 /vol/dense_vol [sid: 0] Info (starting pending operation)
  Tue Jul 12 02:01:03 GMT 2008 /vol/dense_vol [sid: 0] Begin (schedule)
  Tue Jul 12 02:01:04 GMT 2008 /vol/dense_vol [sid: 0] Sort (128000 fp entries)
  Tue Jul 12 02:01:04 GMT 2008 /vol/dense_vol [sid: 0] Dedup Pass1 (0 dup entries)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 0] Dedup Pass2 (127999 dup entries)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 0] Stats (blks gathered 0,finger prints sorted 0,dups found
  0,new dups found 127999,blks deduped 127541,finger prints checked 0,finger prints deleted 0)
  Tue Jul 12 02:02:22 GMT 2008 /vol/dense_vol [sid: 0] End (2356080 KB)

The log file will have following entries if sis start operation starts from a checkpoint corresponding to saving_pass2 stage :
  Thu Sep 18 03:32:23 GMT 2008 /vol/dense_vol [sid: 15] Sis Restart (Restarting from saving_pass2 stage )
  Thu Sep 18 03:32:23 GMT 2008 /vol/dense_vol [sid: 15] Begin (sis start)
  Thu Sep 18 03:32:23 GMT 2008 /vol/dense_vol [sid: 15] Dedup Pass2 (130559 dup entries)
  Thu Sep 18 03:32:30 GMT 2008 /vol/dense_vol [sid: 15] Stats (blks gathered 0,finger prints sorted 0,dups found 0,new dups found 130559,blks deduped 130091,finger prints checked 0,finger prints deleted 0)
  Thu Sep 18 03:32:30 GMT 2008 /vol/dense_vol [sid: 15] End (522240 KB)

On the successful completion of such a sis check operation, the log file should have the following entries: (sis check) 

  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 14] Info (sis check)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 14] Begin (sis check)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 14] Verify
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 14] Merge(0 stale entries)
  Tue Jul 12 02:01:05 GMT 2008 /vol/dense_vol [sid: 14] Stats (blks gathered 0,finger
  prints sorted 0,dups found 0,new dups found 0,blks deduped 0,finger prints
  checked 0,finger prints deleted 0)
  Tue Jul 12 02:02:05 GMT 2008 /vol/dense_vol [sid: 14] End (0 KB)

If a SIS operation aborts, the Error event will replace the End event. 

  Fri Jul 15 00:40:31 GMT 2008 /vol/dense_vol [sid: 18] Begin(schedule)
  Fri Jul 15 18:58:26 GMT 2008 /vol/dense_vol [sid: 18] Error (Volume is full)

The Undo is the only other long-running event, similar to the Begin event, is terminated by either End or Error. 

  Fri Jul 15 18:58:26 GMT 2008 /vol/dense_vol [sid: 19] Undo
  Fri Jul 15 18:58:26 GMT 2008 /vol/dense_vol [sid: 19] End (34670 KB)

The Enable, Disable and Config events are only logged when they complete successfully. 

  Fri Jul 15 18:58:26 GMT 2008 /vol/dense_vol [sid: 20] Enable
  Fri Jul 15 18:58:26 GMT 2008 /vol/dense_vol [sid: 20] Disable
  Fri Jul 15 18:58:26 GMT 2008 /vol/dense_vol [sid: 20] Config ([email protected])

FILES

/etc/log/sis
SIS log file for current week.

/etc/log/sis.[0-5] SIS log files for previous weeks.

SEE ALSO

  na_sis(1)

Table of Contents