-- 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
AsciiUSING [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.