-- Transport Mechanism Mail Server: disk log --

-- [Indigo]<Grapevine>MS>Log.mesa --

-- Andrew Birrell   September 14, 1982 2:03 pm --
-- Redell          20-May-81 17:13:35 --
-- M. D. Schroeder   June 7, 1982  7:07 PM --

DIRECTORY
  Ascii	USING [CR, SP],
  LogDefs USING [],
  LogWatchDefs USING [],
  Process USING [DisableTimeout, SecondsToTicks, SetTimeout],
  Storage USING [String],
  String USING [
    AppendChar, AppendDecimal, AppendString, AppendSubString, EqualSubString,
    SubString, SubStringDescriptor],
  Time USING [Append, Current, Unpack],
  VMDefs USING [
    AbandonFile, CantOpen, CantReadBackingStore, CantWriteBackingStore,
    CloseFile, Error, FileHandle, FileSystem, Login, Logout, LookAheadCount,
    MarkStart, OpenFile, Page, PageAddress, PageByteIndex, pageByteSize,
    PageNumber, Position, ReadPage, Release, SetFileLength, UnableToLogin,
    UsePage, Wait];

Log: MONITOR
  IMPORTS Process, Storage, String, Time, VMDefs
  EXPORTS LogDefs, LogWatchDefs =

  BEGIN OPEN Ascii, String, Time, VMDefs;

  halfPagesInLogFile: CARDINAL = 60;
  pagesInLogFile: CARDINAL = halfPagesInLogFile*2;
  endMarker: CHARACTER = '_;
  dayLength: CARDINAL = 10;  -- format is "dd-mmm-yy "
  timeLength: CARDINAL = 8;  --format is "hh:mm:ss"

  spillLimit: CARDINAL = 40;  -- cycle length for spilling log files
  logSequence: [0..spillLimit);  -- number for backing up this log file cycle

  logFileHandle: FileHandle;
  current: Position;
  pageArray:
    POINTER TO PACKED ARRAY PageByteIndex OF CHARACTER _ NIL;
  firstPage: Page _ NIL;

  lastDay: STRING = [dayLength];
  lastDaySSD: SubStringDescriptor _ [lastDay, 0, dayLength];
  lastDaySS: SubString = @lastDaySSD;

  logChange: CONDITION _ [timeout: Process.SecondsToTicks[2]];


  -- procedure to write a log entry --

  WriteLogEntry: PUBLIC ENTRY PROCEDURE [s: STRING] =
    BEGIN

    dayTimeString: STRING _ [dayLength + timeLength];
    timeString: STRING _ [timeLength];
    daySSD: SubStringDescriptor _ [dayTimeString, 0, dayLength];
    daySS: SubString = @daySSD;
    timeSSD: SubStringDescriptor _ [dayTimeString, dayLength, timeLength];
    timeSS: SubString = @timeSSD;

    front: STRING = "  "L;
    crString: STRING = "
"L;

    Append[dayTimeString, Unpack[Current[]]];
    IF NOT EqualSubString[daySS, lastDaySS] THEN
      BEGIN
      lastDay.length _ 0;
      AppendSubString[lastDay, daySS];
      LogLastDay[];
      END;
    AppendSubString[timeString, timeSS];
    StartLogEntry[];
    PutStringInLog[timeString];
    PutStringInLog[front];
    PutStringInLog[s];
    PutStringInLog[crString];
    FinishLogEntry[];

    BROADCAST logChange;

    END;


  -- procedure to start a log entry

  StartLogEntry: INTERNAL PROCEDURE =
    BEGIN
    Wait[LOOPHOLE[pageArray, VMDefs.Page]];
    -- make sure previous write completed before updating page
    END;


  -- procedure to put a string into the log file

  PutStringInLog: INTERNAL PROCEDURE [ls: STRING] =
    BEGIN
    c: CHARACTER;
    Copy: PROC [offset: CARDINAL] RETURNS [done: CARDINAL] =
      BEGIN
      done _ MIN[pageByteSize - current.byte, ls.length - offset];
      FOR i: CARDINAL IN [0..done) DO
        pageArray^[current.byte + i] _
          IF (c _ ls[i + offset]) = endMarker THEN SP ELSE c;
        ENDLOOP;
      current.byte _ current.byte + done;
      END;

    firstChunkLength: CARDINAL = Copy[0];

    IF current.byte = pageByteSize  --cross a page boundary--
      AND firstPage = NIL  --not at end of second page--
      THEN
      BEGIN
      current.page _ current.page + 1;
      SELECT TRUE FROM
        (current.page >= pagesInLogFile) => {
          current.page _ 0; SpillLog[second, logSequence]};
        (current.page = halfPagesInLogFile) => SpillLog[first, logSequence];
        ENDCASE => NULL;
      firstPage _ LOOPHOLE[pageArray, VMDefs.Page];  --remember first page
      GetCurrentLogPage[];  --get second page; sets current.byte
      [] _ Copy[firstChunkLength];
      END;

    IF current.byte = pageByteSize THEN current.byte _ current.byte - 1  -- leave room for endMarker;

    END;


  -- procedure to complete a log entry

  FinishLogEntry: INTERNAL PROCEDURE =
    BEGIN
    pageArray^[current.byte] _ endMarker;  --will be overwritten by next log entry

    MarkStart[LOOPHOLE[pageArray, VMDefs.Page]];
    --writes second page first if entry crosses page boundary

    IF firstPage # NIL THEN
      BEGIN  -- wait for second page write to complete then write and release first page
      Wait[LOOPHOLE[pageArray, VMDefs.Page]];
      MarkStart[firstPage];
      Release[firstPage];
      firstPage _ NIL;
      IF current.page = 0 OR current.page = halfPagesInLogFile
      THEN LogLastDay[];  -- write day at start of each half of file
      END;
    END;


  -- procedure to write a log entry containing the last day value

  LogLastDay: INTERNAL PROCEDURE =
    BEGIN
    binaryBit: STRING = [1];
    binaryBit[0] _ 377C;
    binaryBit.length _ 1;
    lastDay[lastDay.maxlength - 1] _ CR;
    StartLogEntry[];
    PutStringInLog[binaryBit];
    PutStringInLog[lastDay];
    FinishLogEntry[];
    lastDay[lastDay.maxlength - 1] _ SP;
    END;


  -- procedure to read the current log page --

  GetCurrentLogPage: INTERNAL PROCEDURE =
    BEGIN
    pageArray _ LOOPHOLE[ReadPage[
      addr: PageAddress[file: logFileHandle, page: current.page], lookAhead: 0]];
    current.byte _ 0;
    IF current.page = 0 THEN
      BEGIN
      logSequence _ (logSequence + 1) MOD spillLimit;
      pageArray[0] _ LOOPHOLE[logSequence];
      current.byte _ 1;
      -- but don't mark it dirty yet --
      END;
    END;

  -- procedures to implement the LogWatchDefs interface --

  LogPosition: PUBLIC TYPE = VMDefs.Position;

  GetLogPosition: PUBLIC ENTRY PROCEDURE RETURNS [LogPosition] =
    {RETURN[current]};


  PutLogChars: PUBLIC PROCEDURE [p: LogPosition,
      put: PROCEDURE [CHARACTER],
      gap: PROCEDURE,
      stop: PROCEDURE RETURNS [BOOLEAN] ]
        RETURNS [LogPosition] =
    BEGIN
    e: Position;
    page: POINTER TO PACKED ARRAY PageByteIndex OF CHARACTER;
    WaitForNewChars: ENTRY PROCEDURE = INLINE
      {IF p=current THEN WAIT logChange; e _ current};
    CaughtUp: ENTRY PROCEDURE RETURNS[BOOLEAN] = INLINE
      {RETURN[p=current]};
    DO
      WaitForNewChars[];
      IF p#e THEN
        BEGIN ENABLE UNWIND => Release[LOOPHOLE[page, Page]];
        page _ LOOPHOLE[ReadPage[PageAddress[logFileHandle, p.page], 0]];
        FOR i:PageByteIndex
          IN [p.byte .. IF p.page=e.page THEN e.byte ELSE pageByteSize) DO
            put[page[i]]; ENDLOOP;
        p _ IF p.page=e.page THEN e ELSE [(p.page+1) MOD pagesInLogFile, 0];
        IF CaughtUp[] THEN gap[];
        Release[LOOPHOLE[page, Page]];
        END;
      IF stop[] THEN RETURN [p];
      ENDLOOP;
  END; -- PutLogChars --


  -- procedure to spill half of log to backing file server

  SpillRequest: TYPE = {first, second};
  spillRequest: SpillRequest;  -- which half to spill this time --
  spillSequence: [0..spillLimit);  -- which file to spill to this time --
  spillerWanted: BOOLEAN;  -- spilling request has been set up --
  spillerChange: CONDITION;  -- used in both directions --
  spillerSeconds: CARDINAL _ 5*60;  -- delay between retries after failures --
  spillerProcess: PROCESS;  -- for debugging only --
  myName: STRING _ NIL;  -- credentials for spilling --
  myPwd: STRING _ NIL;
  server: STRING _ NIL;  -- server name for spilling --
  spillName: STRING _ NIL;  -- spill file name --
  spillPrefix: CARDINAL;
  spillEnabled: BOOLEAN _ FALSE;

  KeepString: INTERNAL PROC [from: STRING, extra: CARDINAL _ 0]
    RETURNS [to: STRING] =
    BEGIN
    to _ Storage.String[from.length + extra];
    String.AppendString[to, from];
    END;

  EnableLogSpilling: PUBLIC ENTRY PROC [name, pwd, host, path: STRING] =
    BEGIN
    IF spillEnabled THEN RETURN;
    myName _ KeepString[name];
    myPwd _ KeepString[pwd];
    server _ KeepString[host];
    spillName _ KeepString[path, myName.length+5 -- "Cabernet-00!1" -- ];
    spillPrefix _ path.length;
    spillEnabled _ TRUE;
    -- Assume last spill of previous run failed, and possibly re-try --
    IF current.page < halfPagesInLogFile THEN  -- previous request was for second half of previous cycle --
      BEGIN
      spillRequest _ second;
      spillSequence _ (logSequence + spillLimit - 1) MOD spillLimit;
      END
    ELSE  -- last spill request was for first half of this cycle --
      BEGIN spillRequest _ first; spillSequence _ logSequence; END;
    spillerWanted _ FALSE; -- Spiller may retry after normal delay --
    spillerProcess _ FORK LogSpiller[];
    END;

  SpillLog: INTERNAL PROC [half: SpillRequest, cycle: [0..spillLimit)] =
    BEGIN
    IF spillEnabled THEN
      BEGIN
      -- don't wait for spiller if it isn't ready: it might take too long!
      spillRequest _ half;
      spillSequence _ cycle;
      spillerWanted _ TRUE;
      NOTIFY spillerChange;
      END;
    END;

  WaitForSpillRequest: ENTRY PROC [completed: BOOLEAN]
    RETURNS [SpillRequest, [0..spillLimit)] =
    BEGIN
    IF completed THEN Process.DisableTimeout[@spillerChange]
    ELSE
      Process.SetTimeout[@spillerChange, Process.SecondsToTicks[spillerSeconds]];
    DO
      IF NOT spillerWanted THEN WAIT spillerChange;
      IF spillerWanted  -- new request --
        OR
          (  -- possible retry after timeout --
            NOT completed
            AND
              ((spillRequest = first
                 AND current.page < halfPagesInLogFile + halfPagesInLogFile/2)
                OR
                  (spillRequest = second AND current.page < halfPagesInLogFile/2)))
        THEN EXIT;
      ENDLOOP;
    spillerWanted _ FALSE;
    RETURN[spillRequest, spillSequence]
    END;

  LogSpiller: PROC =
    BEGIN
    Behind: ENTRY PROC RETURNS[BOOLEAN] = INLINE
      { RETURN[spillerWanted] };
    completed: BOOLEAN _ FALSE;  -- assume last run failed --
    DO
      half: SpillRequest;
      currentCycle: [0..spillLimit);
      [half, currentCycle] _ WaitForSpillRequest[completed];
      BEGIN
      ENABLE
        VMDefs.UnableToLogin, VMDefs.CantOpen, VMDefs.Error,
        VMDefs.CantReadBackingStore, VMDefs.CantWriteBackingStore =>
            GOTO crash;
      DoSpill[half, currentCycle];
      completed _ TRUE;
      EXITS crash => completed _ FALSE;
      END;
      LogSpillEnded[half, spillName, completed, Behind[]];
      ENDLOOP;
    END;

  LogSpillEnded: PROC [
    half: SpillRequest, file: STRING, ok, late: BOOLEAN] =
    BEGIN
    text: STRING = [128];
    String.AppendString[text, "Log "L];
    String.AppendString[text, IF ok
                              THEN "spilled: ["L
                              ELSE "spill failed: ["L];
    String.AppendString[text, server];
    String.AppendString[text, "]"L];
    String.AppendString[text, file];
    String.AppendString[text, IF half = first
                              THEN ", first"L
                              ELSE ", second"L];
    String.AppendString[text, " half"L];
    WriteLogEntry[text];
    IF late THEN WriteLogEntry["Started next spill request late"L];
    END;


  DoSpill: --EXTERNAL-- PROC [half: SpillRequest, currentCycle: [0..spillLimit)] =
    BEGIN
    fs: VMDefs.FileSystem = VMDefs.Login[IFS, server, myName, myPwd];
    spillName.length _ spillPrefix;
    String.AppendString[spillName, myName];
    FOR i: CARDINAL DECREASING IN [spillPrefix..spillName.length) DO
      IF spillName[i] = '. THEN {spillName.length _ i; EXIT} ENDLOOP;
    String.AppendChar[spillName, '-];
    IF currentCycle < 10 THEN String.AppendChar[spillName, '0];
    String.AppendDecimal[spillName, currentCycle];
    String.AppendString[spillName, "!1"L];
    BEGIN
      ENABLE UNWIND => VMDefs.Logout[fs];
      file: VMDefs.FileHandle _ VMDefs.OpenFile[
        system: fs, name: spillName, options: oldOrNew];
      BEGIN
        ENABLE UNWIND => VMDefs.AbandonFile[file];
        base: VMDefs.PageNumber = IF half = first THEN 0 ELSE halfPagesInLogFile;
        limit: VMDefs.PageNumber = base + halfPagesInLogFile;
        VMDefs.SetFileLength[file, [page: limit, byte: 0]];
        FOR p: VMDefs.PageNumber IN [base..limit) DO
          to: VMDefs.Page = VMDefs.UsePage[[file, p]];
          from: VMDefs.Page = VMDefs.ReadPage[[logFileHandle, p], 2];
          to^ _ from^;
          VMDefs.Release[from];  -- must be released first --
          VMDefs.MarkStart[to];
--TEMP--  VMDefs.Wait[to]; -- avoid VM deadlock on connection failure --
          VMDefs.Release[to];
        ENDLOOP;
        VMDefs.CloseFile[file];
      END;
    END;
    VMDefs.Logout[fs];
    END;



  -- initialization procedure

  InitializeLog: ENTRY PROCEDURE =
    BEGIN
    AppendString[lastDay, "01-Jan-01 "L];  -- forces day to be logged on startup
    logFileHandle _ OpenFile[
      name: "GV.log"L, options: oldOrNew, cacheFraction: 0];
    SetFileLength[
      file: logFileHandle, position: Position[page: pagesInLogFile, byte: 0]];
    -- initialize "logSequence" --
    current.page _ 0;
    pageArray _ LOOPHOLE[ReadPage[
      addr: PageAddress[file: logFileHandle, page: 0], lookAhead: 0]];
    logSequence _ (LOOPHOLE[pageArray[0], CARDINAL]) MOD spillLimit;
    current.byte _ 1;
    -- search for endMarker --
    DO
      FOR i: CARDINAL IN [current.byte..pageByteSize) DO
        IF pageArray^[i] = endMarker THEN {current.byte _ i; GOTO found};
        ENDLOOP;
      Release[LOOPHOLE[pageArray, VMDefs.Page]];
      current.page _ current.page + 1;
      IF current.page = pagesInLogFile THEN
        BEGIN
        -- no endMarker found: start at 0 and increment logSequence --
        current.page _ 0;
        GetCurrentLogPage[];
        EXIT
        END;
      GetCurrentLogPage[];
      REPEAT found => NULL;
      ENDLOOP;
    END;


  -- initialization code

  InitializeLog[];

  END.

(635)\f1