function varargout = analyseParforResults(profResults)
%analyseParforResults - perform analysis of PARFOR loops

% Copyright 2017 The MathWorks, Inc.

% First, look through the language constructs to find the PARFOR loops
lcl =  profResults.LanguageConstructLog;
pfStartRows = lcl(lcl.Types == 'PARFOR' & lcl.When == 'STARTED', :);
pfEndRows   = lcl(lcl.Types == 'PARFOR' & lcl.When == 'COMPLETED', :);

assert(isequal(pfStartRows.Id, pfEndRows.Id), ...
       'Mismatched PARFOR Ids!');

out = cell(1, height(pfStartRows));

for pfIdx = 1:height(pfStartRows)
    pfId = pfStartRows{pfIdx, 'Id'};
    fprintf('Analysing parfor loop %d...\n', pfId);
    range = [pfStartRows.Times(pfIdx), pfEndRows.Times(pfIdx)];
    out{pfIdx} = iAnalyseRange(profResults, pfId, range);
end

if nargout > 0
    varargout = {out};
else
    cellfun(@iDisplayReport, out);
end

end

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
function iDisplayReport(out)
fprintf('---\n');
fprintf('Execution report for PARFOR loop : %d\n', out.ParforID);
fprintf('Loop execution timespan          : %s\n', join(string(out.TimeRange), ' -> '));
fprintf('Loop duration                    : %g s\n', out.Duration);
fprintf('Num workers                      : %g\n', out.NumWorkers);
fprintf('Total work time                  : %g s\n', out.TotalWorkTime);
fprintf('Parallel overhead                : %g s\n', out.OverheadSeconds);
fprintf('Parallel efficiency              : %g %%\n', out.ParallelEfficiency * 100);
fprintf('Total num intervals              : %g\n', out.Data.NumIntervals(out.Data.LabIndex == -1));
fprintf('Broadcast data sent separately   : %s\n', string(out.IsBroadcastSentSeparately));
fprintf('Details                          : \n%s\n', evalc('disp(out.Data)'));
end

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
function out = iAnalyseRange(results, pfId, range)

% First, perform the overall analysis
out.ParforID  = pfId; 
out.TimeRange = range;
out.Duration  = seconds(range(2) - range(1));

tr = timerange(range(1), range(2));
mlLog = results.MatlabLog(tr, :);
msgLog = results.MessageLog(tr, :);
dispLog = results.DispatchLog(tr, :);

out.NumWorkers = numel(unique(mlLog.LabIndex(mlLog.LabIndex > 0)));
labsInUse = sort(unique(mlLog.LabIndex));
nlabs = numel(labsInUse);
numVar = NaN(nlabs, 1);
durVar = seconds(NaN(nlabs, 1));
durVar.Format = 'mm:ss.SSS';
out.Data = table(labsInUse, numVar, numVar, ...
                 durVar, durVar, ...
                 durVar, durVar, durVar, durVar, ...
                 numVar, ...
                 'VariableNames', {'LabIndex', ...
                    'BytesSent', 'BytesReceived', ...
                    'Serialization', 'Deserialization', ...
                    'InitialIdleTime', 'IntermediateIdleTime', 'BusyTime', 'FinalIdleTime', ...
                    'NumIntervals'});
for idx = 1:numel(labsInUse)
    lab = labsInUse(idx);
    out.Data{idx, 'BytesSent'} = iMessageBytes(msgLog, lab, 'SEND');
    out.Data{idx, 'BytesReceived'} = iMessageBytes(msgLog, lab, 'RECEIVE');
    out.Data{idx, 'Serialization'} = iSerTime(mlLog, lab, 'SERIALIZATION');
    out.Data{idx, 'Deserialization'} = iSerTime(mlLog, lab, 'DESERIALIZATION');
    out.Data{idx, {'InitialIdleTime', 'IntermediateIdleTime', 'BusyTime', 'FinalIdleTime'}} = ...
        iIdleBusyTimes(mlLog, lab, range);
    if lab == -1
        out.Data{idx, 'NumIntervals'} = iNumReceived(dispLog, lab, 'ParforIntervalResultMessage');
    else
        out.Data{idx, 'NumIntervals'} = iNumReceived(dispLog, lab, 'ParforIntervalMessage');
    end
end

out.ClientSerializationTime = seconds(sum(out.Data{1, {'Serialization', 'Deserialization'}}, 'omitnan'));
out.TotalWorkTime = seconds(sum(out.Data.BusyTime, 'omitnan'));
out.WorkerSerializationTime = seconds(sum(reshape(...
    out.Data{2:end, {'Serialization', 'Deserialization'}}, [], 1), 'omitnan'));
out.BodyWorkTime = out.TotalWorkTime - out.WorkerSerializationTime;
out.ParallelEfficiency = (out.BodyWorkTime ./ out.NumWorkers) ./ out.Duration;
out.OverheadSeconds = out.Duration - (out.TotalWorkTime ./ out.NumWorkers);
out.MinInitialIdleTime = min(out.Data.InitialIdleTime, [], 1, 'omitnan');
out.MaxFinalIdleTime = max(out.Data.FinalIdleTime, [], 1, 'omitnan');
out.TotalIntermediateIdleTime = sum(out.Data.IntermediateIdleTime, 'omitnan');

out.IsBroadcastSentSeparately = iNumReceived(dispLog, -1, 'ParforBroadcastResultMessage') > 0;
[out.BroadcastBytes, out.SliceBytes] = iBcastSliceBytes(mlLog);
end

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
% Dig through the MATLAB log and work out how many bytes were sent as broadcast
% and sliced data. Does this by assuming that the first serialization at the
% client is the broadcast data, and that subsequent serializations are all
% sliced data.
function [bcast, sliced] = iBcastSliceBytes(mlLog)

% In the mlLog timetable, for rows of type SERIALIZATION at the point they are
% COMPLETED, the 'Function' variable actually contains a char-vector
% representation of the number of bytes serialized.
bytesPerSerializeAtClient = str2double(...
    mlLog{mlLog.LabIndex == -1 & ...
          mlLog.Types == 'SERIALIZATION' & ...
          mlLog.When == 'COMPLETED', 'Function'});

if ~isempty(bytesPerSerializeAtClient)
    bcast = bytesPerSerializeAtClient(1);
    sliced = sum(bytesPerSerializeAtClient(2:end));
else
    bcast = NaN;
    sliced = NaN;
end
end

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
function n = iNumReceived(dispLog, lab, msgType)
rows = dispLog(dispLog.LabIndex == lab & ...
               strcmp(dispLog.DispatchClassName, msgType) & ...
               dispLog.When == 'STARTED', :);
n = height(rows);
end

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%    
function idleTimes = iIdleBusyTimes(mlLog, lab, range)
% How long from start of log until first remoteParallelFunction call?

rows = mlLog(mlLog.LabIndex == lab & mlLog.Types == 'FEVAL', :);

firstStart = find(rows.When == 'STARTED', 1, 'first');
lastEnd    = find(rows.When == 'COMPLETED', 1, 'last');

if isempty(firstStart) || isempty(lastEnd) || lastEnd < firstStart
    idleTimes = seconds(NaN(1, 4));
else
    rows = rows(firstStart:lastEnd, :);
    t1 = rows.Times(1) - range(1);
    if height(rows) >= 4
        times = diff(rows.Times);
        t2 = sum(times(2:2:end));
        t3 = sum(times(1:2:end));
    else
        t2 = seconds(NaN);
        t3 = seconds(0);
    end
    t4 = range(2) - rows.Times(end);
    idleTimes = [t1, t2, t3, t4];
end

end


%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
function t = iSerTime(mlLog, lab, serOrDeser)
rows = mlLog(mlLog.LabIndex == lab & mlLog.Types == serOrDeser, :);

% Pick from first 'STARTED' to last 'COMPLETED'
firstStart = find(rows.When == 'STARTED', 1, 'first');
lastEnd    = find(rows.When == 'COMPLETED', 1, 'last');

if isempty(firstStart) || isempty(lastEnd) || lastEnd < firstStart
    t = 0;
else
    durations = diff(rows.Times(firstStart:lastEnd));
    t = sum(durations(1:2:end));
end
end

%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
function b = iMessageBytes(tt, labIndex, sendOrReceive)
b = sum(tt.Bytes(tt.LabIndex == labIndex & ...
                 tt.Types    == sendOrReceive & ...
                 tt.When     == 'COMPLETED'));
end
