"start time" is actually the end time?

[rogerhub]

So, the diskspd tool prints out a start time:

System information:

        computer name: foo-bar
        start time: 2025/07/29 01:23:45 UTC

However, my reading of this code suggests that this start time actually reflects the time when the benchmark ends?

https://github.com/microsoft/diskspd/blob/75d21324029af32f4b659e461c61c109608538a4/IORequestGenerator/IORequestGenerator.cpp#L2100C1-L2125C2

bool IORequestGenerator::GenerateRequests(Profile& profile, IResultParser& resultParser, PRINTF pPrintOut, PRINTF pPrintError, PRINTF pPrintVerbose, struct Synchronization *pSynch)
{
    g_pfnPrintOut = pPrintOut;
    g_pfnPrintError = pPrintError;
    g_pfnPrintVerbose = pPrintVerbose;

    bool fOk = _PrecreateFiles(profile);
    if (fOk)
    {
        const vector<TimeSpan>& vTimeSpans = profile.GetTimeSpans();
        vector<Results> vResults(vTimeSpans.size());
        for (size_t i = 0; fOk && (i < vTimeSpans.size()); i++)
        {
            printfv(profile.GetVerbose(), "Generating requests for timespan %u.\n", i + 1);
            fOk = _GenerateRequestsForTimeSpan(profile, vTimeSpans[i], vResults[i], pSynch);
        }

        // TODO: show results only for timespans that succeeded
        SystemInformation system;
        EtwResultParser::ParseResults(vResults);
        string sResults = resultParser.ParseResults(profile, system, vResults);
        print("%s", sResults.c_str());
    }

    return fOk;
}

That's because the start time is recorded in the SystemInformation constructor, but all of the benchmarking happens in _GenerateRequestsForTimeSpan.

It is misleading because the start time is now incorrect. It is delayed by however long the benchmark took to run.

Am I understanding this correctly? Is the start time incorrect?

@DanPear

[dl2n]

You understand this correctly; the error is longstanding and has been on my backlog for some time. I'll get this fixed in the next push. In the meantime I think you can simply shift instantiation of 'system' to the top of the block and it would be closer to OK. A more detail oriented approach could notice that now that we know this is not actually "start", and there are multiple times of interest that could be useful if/when trying to zero in on timelines, stalls, and the like. For one, note _PrecreateFiles. I believe I wanted to sort this out at least one more step before a final version and possibliy/likely factor it out of the System class entirely.

…

________________________________ From: Roger Chen ***@***.***> Sent: Tuesday, July 29, 2025 10:48 PM To: microsoft/diskspd ***@***.***> Cc: Subscribed ***@***.***> Subject: [microsoft/diskspd] "start time" is actually the end time? (Issue #225) So, the diskspd tool prints out a start time: System information: computer name: foo-bar start time: 2025/07/29 01:23:45 UTC However, my reading of this code suggests that this start time actually reflects the time when the benchmark ends? https://github.com/microsoft/diskspd/blob/75d21324029af32f4b659e461c61c109608538a4/IORequestGenerator/IORequestGenerator.cpp#L2100C1-L2125C2 bool IORequestGenerator::GenerateRequests(Profile& profile, IResultParser& resultParser, PRINTF pPrintOut, PRINTF pPrintError, PRINTF pPrintVerbose, struct Synchronization *pSynch) { g_pfnPrintOut = pPrintOut; g_pfnPrintError = pPrintError; g_pfnPrintVerbose = pPrintVerbose; bool fOk = _PrecreateFiles(profile); if (fOk) { const vector<TimeSpan>& vTimeSpans = profile.GetTimeSpans(); vector<Results> vResults(vTimeSpans.size()); for (size_t i = 0; fOk && (i < vTimeSpans.size()); i++) { printfv(profile.GetVerbose(), "Generating requests for timespan %u.\n", i + 1); fOk = _GenerateRequestsForTimeSpan(profile, vTimeSpans[i], vResults[i], pSynch); } // TODO: show results only for timespans that succeeded SystemInformation system; EtwResultParser::ParseResults(vResults); string sResults = resultParser.ParseResults(profile, system, vResults); print("%s", sResults.c_str()); } return fOk; } That's because the start time is recorded in the SystemInformation constructor, but all of the benchmarking happens in _GenerateRequestsForTimeSpan. It is misleading because the start time is now incorrect. It is delayed by however long the benchmark took to run. Screenshot.2025-07-29.at.10.42.59.PM.jpg (view on web)<https://github.com/user-attachments/assets/f1335813-d088-4c34-abbe-8443f5aef87d> Am I understanding this correctly? Is the start time incorrect? @DanPear<https://github.com/DanPear> — Reply to this email directly, view it on GitHub<#225> or unsubscribe<https://github.com/notifications/unsubscribe-auth/ACCWSKNNT7D4H5W7PA5ULST3LBMCZBFKMF2HI4TJMJ2XIZLTSOBKK5TBNR2WLJDUOJ2WLJDOMFWWLO3UNBZGKYLEL5YGC4TUNFRWS4DBNZ2F6YLDORUXM2LUPGBKK5TBNR2WLJLJONZXKZNENZQW2ZNLORUHEZLBMRPXI6LQMWBKK5TBNR2WLJDUOJ2WLJDOMFWWLLTXMF2GG2C7MFRXI2LWNF2HTLDTOVRGUZLDORPXI6LQMWSUS43TOVS2M5DPOBUWG44SQKSHI6LQMWVHEZLQN5ZWS5DPOJ42K5TBNR2WLKBSGM4TKNRUGI4IFJDUPFYGLJLJONZXKZNFOZQWY5LFVIZTENZVG42DQNJXGSTXI4TJM5TWK4VGMNZGKYLUMU>. You are receiving this email because you are subscribed to this thread. Triage notifications on the go with GitHub Mobile for iOS<https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675> or Android<https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub>.